diff mbox series

schemas: Add schema for firmware logs

Message ID 20230204001959.935268-1-sjg@chromium.org
State Handled Elsewhere
Delegated to: Tom Rini
Headers show
Series schemas: Add schema for firmware logs | expand

Commit Message

Simon Glass Feb. 4, 2023, 12:19 a.m. UTC
A common way to detect problems in firmware is to collect logs from
the firmware, then pass them to the OS for storage and analysis.

Logs can take the form of simple text output, or structured logs where the
filename and line number, etc. are provided. Timestamps can sometimes be
useful, too.

Ideally the log can be displayed as simple ASCII without always needing
a special program to read it.

The firmware consists of various boot phases, any of which can contribute
log information. It is assumed that these logs are not interleaved, i.e.
that the phases run one after the other.

The final boot phase (before the OS) is responsible for collecting the
logs, e.g. from a Transfer List, and placing them in the devicetree.

This binding collects the logs as individual log@n subnodes within a
/chosen/logs node.

If firmware phases use the devicetree to pass logs between each other,
then the /chosen node should still be used. The /options node is not
supported. Subsequent phases must be sure to use the next numbered
log@n node.

If the log data is sitting in memory somewhere, it is possible to point
to it, rather than copying the data into a property. For large logs this
may be more efficient. It must end with a NUL character, so the total
space for actual log data is one byte less than the allocated size.

If something goes wrong and an incomplete log record is emitted, then the
next record may appear to be part of it, since there is no LF or ETX
character at the end of the previous record.

The intent with this binding is to provide a Linux driver which can
provide access to the log data after booting is complete.

Other things not considered:
- signalling overflow of a log buffer
- circular log buffers
- a single unified log buffer with inline ASCII characters to indicate the
  phase and project
- log records that contain multiple lines of text

Signed-off-by: Simon Glass <sjg@chromium.org>
---

 dtschema/schemas/chosen.yaml |   3 +
 dtschema/schemas/log.yaml    | 176 +++++++++++++++++++++++++++++++++++
 dtschema/schemas/logs.yaml   |  30 ++++++
 test/logs.dts                |  47 ++++++++++
 4 files changed, 256 insertions(+)
 create mode 100644 dtschema/schemas/log.yaml
 create mode 100644 dtschema/schemas/logs.yaml
 create mode 100644 test/logs.dts

Comments

Peter Robinson Feb. 4, 2023, 9:35 a.m. UTC | #1
Hi Simon,

Does it make sense to devise something that is compatible with the
kernel's pstore [1] mechanism?

Peter

[1] https://lwn.net/Articles/434821/

On Sat, Feb 4, 2023 at 12:20 AM Simon Glass <sjg@chromium.org> wrote:
>
> A common way to detect problems in firmware is to collect logs from
> the firmware, then pass them to the OS for storage and analysis.
>
> Logs can take the form of simple text output, or structured logs where the
> filename and line number, etc. are provided. Timestamps can sometimes be
> useful, too.
>
> Ideally the log can be displayed as simple ASCII without always needing
> a special program to read it.
>
> The firmware consists of various boot phases, any of which can contribute
> log information. It is assumed that these logs are not interleaved, i.e.
> that the phases run one after the other.
>
> The final boot phase (before the OS) is responsible for collecting the
> logs, e.g. from a Transfer List, and placing them in the devicetree.
>
> This binding collects the logs as individual log@n subnodes within a
> /chosen/logs node.
>
> If firmware phases use the devicetree to pass logs between each other,
> then the /chosen node should still be used. The /options node is not
> supported. Subsequent phases must be sure to use the next numbered
> log@n node.
>
> If the log data is sitting in memory somewhere, it is possible to point
> to it, rather than copying the data into a property. For large logs this
> may be more efficient. It must end with a NUL character, so the total
> space for actual log data is one byte less than the allocated size.
>
> If something goes wrong and an incomplete log record is emitted, then the
> next record may appear to be part of it, since there is no LF or ETX
> character at the end of the previous record.
>
> The intent with this binding is to provide a Linux driver which can
> provide access to the log data after booting is complete.
>
> Other things not considered:
> - signalling overflow of a log buffer
> - circular log buffers
> - a single unified log buffer with inline ASCII characters to indicate the
>   phase and project
> - log records that contain multiple lines of text
>
> Signed-off-by: Simon Glass <sjg@chromium.org>
> ---
>
>  dtschema/schemas/chosen.yaml |   3 +
>  dtschema/schemas/log.yaml    | 176 +++++++++++++++++++++++++++++++++++
>  dtschema/schemas/logs.yaml   |  30 ++++++
>  test/logs.dts                |  47 ++++++++++
>  4 files changed, 256 insertions(+)
>  create mode 100644 dtschema/schemas/log.yaml
>  create mode 100644 dtschema/schemas/logs.yaml
>  create mode 100644 test/logs.dts
>
> diff --git a/dtschema/schemas/chosen.yaml b/dtschema/schemas/chosen.yaml
> index 86194dd..46cc9fb 100644
> --- a/dtschema/schemas/chosen.yaml
> +++ b/dtschema/schemas/chosen.yaml
> @@ -236,6 +236,9 @@ properties:
>        system.
>
>  patternProperties:
> +  '^logs$':
> +    $ref: logs.yaml#
> +
>    "^framebuffer": true
>
>  additionalProperties: false
> diff --git a/dtschema/schemas/log.yaml b/dtschema/schemas/log.yaml
> new file mode 100644
> index 0000000..5218234
> --- /dev/null
> +++ b/dtschema/schemas/log.yaml
> @@ -0,0 +1,176 @@
> +# SPDX-License-Identifier: BSD-2-Clause
> +# Copyright 2023 Google LLC
> +%YAML 1.2
> +---
> +$id: http://devicetree.org/schemas/log.yaml#
> +$schema: http://devicetree.org/meta-schemas/core.yaml#
> +
> +title: Log-output binding
> +
> +maintainers:
> +  - Simon Glass <sjg@chromium.org>
> +
> +description:
> +  This holds a log file or console dump created by a single phase of the boot.
> +  It typically consists of plain ASCII text, but it is also possible to
> +  add metadata like files and line numbers.
> +
> +  Each log node has a hex unit address which indicates the order of progress
> +  through the boot phases. The first node must be log@0, followed by
> +  log@1, etc.
> +
> +select: false
> +
> +properties:
> +  reg:
> +    description:
> +      Defines a unique log ID for the log represented by the log node.
> +
> +  boot-phase:
> +    $ref: types.yaml#/definitions/string
> +    description: |
> +      Indicates the phase of boot which produced this log:
> +
> +        - pre-sram: Before SRAM is available
> +        - verify: Verification step, which decides which of the available images
> +          should be run next
> +        - pre-ram: Sets up SDRAM
> +        - some-ram: After SDRAM is working but before all of it is available.
> +          Some RAM is available but it is limited (e.g. it may be split into
> +          two pieces by the location of the running program) because the
> +          program code is not yet relocated out of the way.
> +        - loader: OS loader, typically the final firmware step
> +
> +    pattern: "^pre-sram|verify|pre-ram|some-ram|loader$"
> +
> +  project:
> +    $ref: types.yaml#/definitions/string
> +    description:
> +      Indicates the name of the project which produced this log
> +
> +    pattern: "^U-Boot|TF-A"
> +
> +  time-format:
> +    $ref: types.yaml#/definitions/string
> +    description: |
> +      Indicates the time format used by the log. Options are:
> +
> +        usec - a integer number of microseconds since reset was released,
> +               expressed in ASCII, e.g. "123"
> +
> +    pattern: "^usec$"
> +
> +  text-start:
> +    oneOf:
> +      - $ref: types.yaml#/definitions/uint32
> +      - $ref: types.yaml#/definitions/uint64
> +    description:
> +      These properties hold the physical start and end address of the log text
> +      if the 'text' property is not used.
> +
> +      Note that text-start is inclusive, but text-end is exclusive.
> +
> +      The text must be terminated with a NUL character.
> +
> +  text-end:
> +    oneOf:
> +      - $ref: types.yaml#/definitions/uint32
> +      - $ref: types.yaml#/definitions/uint64
> +    description:
> +      These properties hold the physical start and end address of the log text
> +      if the 'text' property is not used.
> +
> +      Note that text-start is inclusive, but text-end is exclusive.
> +
> +      The text must be terminated with a NUL character.
> +
> +  text:
> +    $ref: types.yaml#/definitions/string
> +    description: |
> +      Contains the log text, if it is not referred to by text-start / text-end.
> +
> +      The format is ASCII with US and SOT used to indicate optional fields:
> +
> +        [timestamp<US>][level[:category[:filename[:line[:function]]]]]<SOT>]message[<LF>|<ETX>]
> +
> +      where:
> +
> +        timestamp is the timestamp, according to time-format
> +
> +        level is the single-digit log level:
> +           0 - emergency (program is unstable)
> +           1 - alert (action must be taken immediately)
> +           2 - crit (critical conditions)
> +           3 - err (error that prevents something from working
> +           4 - warning (may prevent optimal operation)
> +           5 - notice (normal but significant condition, printf())
> +           6 - info (general information message)
> +           7 - debug (basic debug-level message)
> +           8 - debug content (debug message showing full message content)
> +           9 - debug I/O (debug message showing hardware I/O access)
> +
> +        category is the category name which is project-dependent
> +
> +        filename is the relative filename (__FILE__ in C)
> +
> +        line is the line number starting from 1 (__LINE__ in C)
> +
> +        function is the function name (__func__ in C)
> +
> +        message is the message string, which may not contain control
> +        characters (beyond those listed above) except for HT and LF. DEL and CR
> +        are not permitted.
> +
> +      The timestamp is present only if US is in the string.
> +
> +      The fields before <SOT> are all optional, but must be listed in order.
> +      To omit a field in the middle, use an empty string between two colons.
> +      To omit a field at the end, just leave it out along with the colon before
> +      it.
> +
> +      Typically LF is used as a line delimiter, but if a record does not
> +      end with a newline, ETX can be used. This indicates that it is a new
> +      log record but without a newline between them. Often (but not always)
> +      the 'continuation' does not include the US and SOT information.
> +
> +      A log record without a LF or ETX terminator is considered invalid, even
> +      if it is the final record.
> +
> +      Examples:
> +
> +         123<US>5:tpm:lib/tpm.c:334:tpm_init<SOT>TPM starting...<LF>
> +         23<US>Hello<LF>
> +         2:boot:lib/panic.c:84:panic<SOT>Memory training failed<LF>
> +         7:mmc:::mmc_bind<SOT>Cannot create block device<LF>
> +         Net:   eth0: host_lo, eth1: host_enp1s0<ETX>
> +
> +      ASCII characters:
> +
> +        SOT - 0x2  - indicates the start of the message. This is optional if
> +                     the record has nothing but a message
> +        ETX - 0x3  - indicates the end of a log record (without new line)
> +        LF  - 0xa  - indicates the end of a log record (and new line)
> +        US  - 0x1f - indicates the end of the timestamp (and that it is present
> +                     in the record)
> +
> +      The above format is intended to be unambiguous, while still being fairly
> +      readable it just shown on a terminal with all control characters except
> +      LF dropped. The CR character is not permitted since it is not needed to
> +      signal an end of line and it avoids worrying about what <CR><LF> actually
> +      means.
> +
> +      The text size is determined by the property size. The last byte must be
> +      a NUL character.
> +
> +required:
> +  - boot-phase
> +  - project
> +
> +anyOf:
> +  - required:
> +    - text
> +  - required:
> +    - text-start
> +    - text-end
> +
> +additionalProperties: false
> diff --git a/dtschema/schemas/logs.yaml b/dtschema/schemas/logs.yaml
> new file mode 100644
> index 0000000..76ba2b0
> --- /dev/null
> +++ b/dtschema/schemas/logs.yaml
> @@ -0,0 +1,30 @@
> +# SPDX-License-Identifier: BSD-2-Clause
> +# Copyright 2023 Google LLC
> +%YAML 1.2
> +---
> +$id: http://devicetree.org/schemas/logs.yaml#
> +$schema: http://devicetree.org/meta-schemas/core.yaml#
> +
> +title: Log information collected during firmware execution
> +
> +maintainers:
> +  - Simon Glass <sjg@chromium.org>
> +
> +description:
> +  This holds a set of logs build up during booting of the machine. The
> +  collection of logs is described in the "/logs" node.  This node in turn
> +  contains a number of subnodes representing individual log output from
> +  different boot phases.
> +
> +properties:
> +  '#address-cells':
> +    const: 1
> +
> +  '#size-cells':
> +    const: 0
> +
> +patternProperties:
> +  '^log@[0-9a-f]+$':
> +    $ref: log.yaml#
> +
> +additionalProperties: false
> diff --git a/test/logs.dts b/test/logs.dts
> new file mode 100644
> index 0000000..7d044df
> --- /dev/null
> +++ b/test/logs.dts
> @@ -0,0 +1,47 @@
> +// SPDX-License-Identifier: BSD-2-Clause
> +// Copyright 2023 Google LLC
> +
> +// Used to validate the "logs" node and its child "log" nodes
> +
> +// dtc -O dtb -o test.dtb test/bootphases.dts && tools/dt-validate -s test/schemas -m test.dtb
> +
> +
> +/dts-v1/;
> +
> +/ {
> +       model = "none";
> +       compatible = "foo";
> +
> +       #address-cells = <1>;
> +       #size-cells = <1>;
> +
> +       chosen {
> +               logs {
> +                       #address-cells = <1>;
> +                       #size-cells = <0>;
> +
> +                       log@0 {
> +                               reg = <0>;
> +                               boot-phase = "pre-ram";
> +                               project = "U-Boot";
> +                               text = "\nU-Boot SPL 2023.01 (Feb 03 2023 - 14:45:39 -0700)\nTrying to boot from sandbox_image\nTrying to boot from sandbox_file\n";
> +                       };
> +
> +                       log@1 {
> +                               reg = <1>;
> +                               boot-phase = "loader";
> +                               project = "U-Boot";
> +                               time-format = "usec";
> +                               text = "\n\n123\x1f2:boot:lib/display_options.c:43:display_options\x02U-Boot 2023.01 (Feb 03 2023 - 14:45:39 -0700)\n\nReset Status: COLD\nModel: sandbox\nDRAM:  256 MiB\n";
> +                       };
> +
> +                       log@2 {
> +                               reg = <2>;
> +                               boot-phase = "pre-ram";
> +                               project = "TF-A";
> +                               text-start = <0x103000>;
> +                               text-end = <0x107000>;
> +                       };
> +               };
> +       };
> +};
> --
> 2.39.1.519.gcb327c4b5f-goog
>
Simon Glass Feb. 4, 2023, 12:04 p.m. UTC | #2
Hi Peter,

On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com> wrote:
>
> Hi Simon,
>
> Does it make sense to devise something that is compatible with the
> kernel's pstore [1] mechanism?

Possibly...can you please be a little more specific?

Regards,
Simon

>
> Peter
>
> [1] https://lwn.net/Articles/434821/
>
> On Sat, Feb 4, 2023 at 12:20 AM Simon Glass <sjg@chromium.org> wrote:
> >
> > A common way to detect problems in firmware is to collect logs from
> > the firmware, then pass them to the OS for storage and analysis.
> >
> > Logs can take the form of simple text output, or structured logs where the
> > filename and line number, etc. are provided. Timestamps can sometimes be
> > useful, too.
> >
> > Ideally the log can be displayed as simple ASCII without always needing
> > a special program to read it.
> >
> > The firmware consists of various boot phases, any of which can contribute
> > log information. It is assumed that these logs are not interleaved, i.e.
> > that the phases run one after the other.
> >
> > The final boot phase (before the OS) is responsible for collecting the
> > logs, e.g. from a Transfer List, and placing them in the devicetree.
> >
> > This binding collects the logs as individual log@n subnodes within a
> > /chosen/logs node.
> >
> > If firmware phases use the devicetree to pass logs between each other,
> > then the /chosen node should still be used. The /options node is not
> > supported. Subsequent phases must be sure to use the next numbered
> > log@n node.
> >
> > If the log data is sitting in memory somewhere, it is possible to point
> > to it, rather than copying the data into a property. For large logs this
> > may be more efficient. It must end with a NUL character, so the total
> > space for actual log data is one byte less than the allocated size.
> >
> > If something goes wrong and an incomplete log record is emitted, then the
> > next record may appear to be part of it, since there is no LF or ETX
> > character at the end of the previous record.
> >
> > The intent with this binding is to provide a Linux driver which can
> > provide access to the log data after booting is complete.
> >
> > Other things not considered:
> > - signalling overflow of a log buffer
> > - circular log buffers
> > - a single unified log buffer with inline ASCII characters to indicate the
> >   phase and project
> > - log records that contain multiple lines of text
> >
> > Signed-off-by: Simon Glass <sjg@chromium.org>
> > ---
> >
> >  dtschema/schemas/chosen.yaml |   3 +
> >  dtschema/schemas/log.yaml    | 176 +++++++++++++++++++++++++++++++++++
> >  dtschema/schemas/logs.yaml   |  30 ++++++
> >  test/logs.dts                |  47 ++++++++++
> >  4 files changed, 256 insertions(+)
> >  create mode 100644 dtschema/schemas/log.yaml
> >  create mode 100644 dtschema/schemas/logs.yaml
> >  create mode 100644 test/logs.dts
> >
> > diff --git a/dtschema/schemas/chosen.yaml b/dtschema/schemas/chosen.yaml
> > index 86194dd..46cc9fb 100644
> > --- a/dtschema/schemas/chosen.yaml
> > +++ b/dtschema/schemas/chosen.yaml
> > @@ -236,6 +236,9 @@ properties:
> >        system.
> >
> >  patternProperties:
> > +  '^logs$':
> > +    $ref: logs.yaml#
> > +
> >    "^framebuffer": true
> >
> >  additionalProperties: false
> > diff --git a/dtschema/schemas/log.yaml b/dtschema/schemas/log.yaml
> > new file mode 100644
> > index 0000000..5218234
> > --- /dev/null
> > +++ b/dtschema/schemas/log.yaml
> > @@ -0,0 +1,176 @@
> > +# SPDX-License-Identifier: BSD-2-Clause
> > +# Copyright 2023 Google LLC
> > +%YAML 1.2
> > +---
> > +$id: http://devicetree.org/schemas/log.yaml#
> > +$schema: http://devicetree.org/meta-schemas/core.yaml#
> > +
> > +title: Log-output binding
> > +
> > +maintainers:
> > +  - Simon Glass <sjg@chromium.org>
> > +
> > +description:
> > +  This holds a log file or console dump created by a single phase of the boot.
> > +  It typically consists of plain ASCII text, but it is also possible to
> > +  add metadata like files and line numbers.
> > +
> > +  Each log node has a hex unit address which indicates the order of progress
> > +  through the boot phases. The first node must be log@0, followed by
> > +  log@1, etc.
> > +
> > +select: false
> > +
> > +properties:
> > +  reg:
> > +    description:
> > +      Defines a unique log ID for the log represented by the log node.
> > +
> > +  boot-phase:
> > +    $ref: types.yaml#/definitions/string
> > +    description: |
> > +      Indicates the phase of boot which produced this log:
> > +
> > +        - pre-sram: Before SRAM is available
> > +        - verify: Verification step, which decides which of the available images
> > +          should be run next
> > +        - pre-ram: Sets up SDRAM
> > +        - some-ram: After SDRAM is working but before all of it is available.
> > +          Some RAM is available but it is limited (e.g. it may be split into
> > +          two pieces by the location of the running program) because the
> > +          program code is not yet relocated out of the way.
> > +        - loader: OS loader, typically the final firmware step
> > +
> > +    pattern: "^pre-sram|verify|pre-ram|some-ram|loader$"
> > +
> > +  project:
> > +    $ref: types.yaml#/definitions/string
> > +    description:
> > +      Indicates the name of the project which produced this log
> > +
> > +    pattern: "^U-Boot|TF-A"
> > +
> > +  time-format:
> > +    $ref: types.yaml#/definitions/string
> > +    description: |
> > +      Indicates the time format used by the log. Options are:
> > +
> > +        usec - a integer number of microseconds since reset was released,
> > +               expressed in ASCII, e.g. "123"
> > +
> > +    pattern: "^usec$"
> > +
> > +  text-start:
> > +    oneOf:
> > +      - $ref: types.yaml#/definitions/uint32
> > +      - $ref: types.yaml#/definitions/uint64
> > +    description:
> > +      These properties hold the physical start and end address of the log text
> > +      if the 'text' property is not used.
> > +
> > +      Note that text-start is inclusive, but text-end is exclusive.
> > +
> > +      The text must be terminated with a NUL character.
> > +
> > +  text-end:
> > +    oneOf:
> > +      - $ref: types.yaml#/definitions/uint32
> > +      - $ref: types.yaml#/definitions/uint64
> > +    description:
> > +      These properties hold the physical start and end address of the log text
> > +      if the 'text' property is not used.
> > +
> > +      Note that text-start is inclusive, but text-end is exclusive.
> > +
> > +      The text must be terminated with a NUL character.
> > +
> > +  text:
> > +    $ref: types.yaml#/definitions/string
> > +    description: |
> > +      Contains the log text, if it is not referred to by text-start / text-end.
> > +
> > +      The format is ASCII with US and SOT used to indicate optional fields:
> > +
> > +        [timestamp<US>][level[:category[:filename[:line[:function]]]]]<SOT>]message[<LF>|<ETX>]
> > +
> > +      where:
> > +
> > +        timestamp is the timestamp, according to time-format
> > +
> > +        level is the single-digit log level:
> > +           0 - emergency (program is unstable)
> > +           1 - alert (action must be taken immediately)
> > +           2 - crit (critical conditions)
> > +           3 - err (error that prevents something from working
> > +           4 - warning (may prevent optimal operation)
> > +           5 - notice (normal but significant condition, printf())
> > +           6 - info (general information message)
> > +           7 - debug (basic debug-level message)
> > +           8 - debug content (debug message showing full message content)
> > +           9 - debug I/O (debug message showing hardware I/O access)
> > +
> > +        category is the category name which is project-dependent
> > +
> > +        filename is the relative filename (__FILE__ in C)
> > +
> > +        line is the line number starting from 1 (__LINE__ in C)
> > +
> > +        function is the function name (__func__ in C)
> > +
> > +        message is the message string, which may not contain control
> > +        characters (beyond those listed above) except for HT and LF. DEL and CR
> > +        are not permitted.
> > +
> > +      The timestamp is present only if US is in the string.
> > +
> > +      The fields before <SOT> are all optional, but must be listed in order.
> > +      To omit a field in the middle, use an empty string between two colons.
> > +      To omit a field at the end, just leave it out along with the colon before
> > +      it.
> > +
> > +      Typically LF is used as a line delimiter, but if a record does not
> > +      end with a newline, ETX can be used. This indicates that it is a new
> > +      log record but without a newline between them. Often (but not always)
> > +      the 'continuation' does not include the US and SOT information.
> > +
> > +      A log record without a LF or ETX terminator is considered invalid, even
> > +      if it is the final record.
> > +
> > +      Examples:
> > +
> > +         123<US>5:tpm:lib/tpm.c:334:tpm_init<SOT>TPM starting...<LF>
> > +         23<US>Hello<LF>
> > +         2:boot:lib/panic.c:84:panic<SOT>Memory training failed<LF>
> > +         7:mmc:::mmc_bind<SOT>Cannot create block device<LF>
> > +         Net:   eth0: host_lo, eth1: host_enp1s0<ETX>
> > +
> > +      ASCII characters:
> > +
> > +        SOT - 0x2  - indicates the start of the message. This is optional if
> > +                     the record has nothing but a message
> > +        ETX - 0x3  - indicates the end of a log record (without new line)
> > +        LF  - 0xa  - indicates the end of a log record (and new line)
> > +        US  - 0x1f - indicates the end of the timestamp (and that it is present
> > +                     in the record)
> > +
> > +      The above format is intended to be unambiguous, while still being fairly
> > +      readable it just shown on a terminal with all control characters except
> > +      LF dropped. The CR character is not permitted since it is not needed to
> > +      signal an end of line and it avoids worrying about what <CR><LF> actually
> > +      means.
> > +
> > +      The text size is determined by the property size. The last byte must be
> > +      a NUL character.
> > +
> > +required:
> > +  - boot-phase
> > +  - project
> > +
> > +anyOf:
> > +  - required:
> > +    - text
> > +  - required:
> > +    - text-start
> > +    - text-end
> > +
> > +additionalProperties: false
> > diff --git a/dtschema/schemas/logs.yaml b/dtschema/schemas/logs.yaml
> > new file mode 100644
> > index 0000000..76ba2b0
> > --- /dev/null
> > +++ b/dtschema/schemas/logs.yaml
> > @@ -0,0 +1,30 @@
> > +# SPDX-License-Identifier: BSD-2-Clause
> > +# Copyright 2023 Google LLC
> > +%YAML 1.2
> > +---
> > +$id: http://devicetree.org/schemas/logs.yaml#
> > +$schema: http://devicetree.org/meta-schemas/core.yaml#
> > +
> > +title: Log information collected during firmware execution
> > +
> > +maintainers:
> > +  - Simon Glass <sjg@chromium.org>
> > +
> > +description:
> > +  This holds a set of logs build up during booting of the machine. The
> > +  collection of logs is described in the "/logs" node.  This node in turn
> > +  contains a number of subnodes representing individual log output from
> > +  different boot phases.
> > +
> > +properties:
> > +  '#address-cells':
> > +    const: 1
> > +
> > +  '#size-cells':
> > +    const: 0
> > +
> > +patternProperties:
> > +  '^log@[0-9a-f]+$':
> > +    $ref: log.yaml#
> > +
> > +additionalProperties: false
> > diff --git a/test/logs.dts b/test/logs.dts
> > new file mode 100644
> > index 0000000..7d044df
> > --- /dev/null
> > +++ b/test/logs.dts
> > @@ -0,0 +1,47 @@
> > +// SPDX-License-Identifier: BSD-2-Clause
> > +// Copyright 2023 Google LLC
> > +
> > +// Used to validate the "logs" node and its child "log" nodes
> > +
> > +// dtc -O dtb -o test.dtb test/bootphases.dts && tools/dt-validate -s test/schemas -m test.dtb
> > +
> > +
> > +/dts-v1/;
> > +
> > +/ {
> > +       model = "none";
> > +       compatible = "foo";
> > +
> > +       #address-cells = <1>;
> > +       #size-cells = <1>;
> > +
> > +       chosen {
> > +               logs {
> > +                       #address-cells = <1>;
> > +                       #size-cells = <0>;
> > +
> > +                       log@0 {
> > +                               reg = <0>;
> > +                               boot-phase = "pre-ram";
> > +                               project = "U-Boot";
> > +                               text = "\nU-Boot SPL 2023.01 (Feb 03 2023 - 14:45:39 -0700)\nTrying to boot from sandbox_image\nTrying to boot from sandbox_file\n";
> > +                       };
> > +
> > +                       log@1 {
> > +                               reg = <1>;
> > +                               boot-phase = "loader";
> > +                               project = "U-Boot";
> > +                               time-format = "usec";
> > +                               text = "\n\n123\x1f2:boot:lib/display_options.c:43:display_options\x02U-Boot 2023.01 (Feb 03 2023 - 14:45:39 -0700)\n\nReset Status: COLD\nModel: sandbox\nDRAM:  256 MiB\n";
> > +                       };
> > +
> > +                       log@2 {
> > +                               reg = <2>;
> > +                               boot-phase = "pre-ram";
> > +                               project = "TF-A";
> > +                               text-start = <0x103000>;
> > +                               text-end = <0x107000>;
> > +                       };
> > +               };
> > +       };
> > +};
> > --
> > 2.39.1.519.gcb327c4b5f-goog
> >
Rob Herring (Arm) Feb. 6, 2023, 5:14 p.m. UTC | #3
On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
>
> Hi Peter,
>
> On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com> wrote:
> >
> > Hi Simon,
> >
> > Does it make sense to devise something that is compatible with the
> > kernel's pstore [1] mechanism?
>
> Possibly...can you please be a little more specific?

Peter is talking about the same thing I suggested on IRC.

pstore == ramoops

Rob
Simon Glass Feb. 6, 2023, 9:25 p.m. UTC | #4
Hi Rob,

On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
>
> On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> >
> > Hi Peter,
> >
> > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com> wrote:
> > >
> > > Hi Simon,
> > >
> > > Does it make sense to devise something that is compatible with the
> > > kernel's pstore [1] mechanism?
> >
> > Possibly...can you please be a little more specific?
>
> Peter is talking about the same thing I suggested on IRC.
>
> pstore == ramoops

Oh, I only looked at the DT binding as I thought that was what you
were talking about on irc.

For pstore, isn't the point that Linux wants to save stuff to allow
debugging or collection on reboot? What does that have to do with
console logs from firmware? That seems like a different thing. Or are
you suggesting that we add a pstore driver into U-Boot? It is quite a
lot of code, including compression, etc. It might be easier for Linux
to write the data into pstore when it starts up?

I'm really just looking for more specific ideas as to what you are suggesting.

Regards,
Simon
Rob Herring (Arm) Feb. 6, 2023, 11:32 p.m. UTC | #5
+boot-architecture

On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
>
> Hi Rob,
>
> On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> >
> > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > >
> > > Hi Peter,
> > >
> > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com> wrote:
> > > >
> > > > Hi Simon,
> > > >
> > > > Does it make sense to devise something that is compatible with the
> > > > kernel's pstore [1] mechanism?
> > >
> > > Possibly...can you please be a little more specific?
> >
> > Peter is talking about the same thing I suggested on IRC.
> >
> > pstore == ramoops
>
> Oh, I only looked at the DT binding as I thought that was what you
> were talking about on irc.

The binding is called ramoops as it's for the RAM backend for pstore.

My suggestion was either using/extending ramoops or following its
design as a reserved memory region. All you would need to extend the
ramoops binding is a new property to define the size of your data.

> For pstore, isn't the point that Linux wants to save stuff to allow
> debugging or collection on reboot? What does that have to do with
> console logs from firmware? That seems like a different thing. Or are
> you suggesting that we add a pstore driver into U-Boot? It is quite a
> lot of code, including compression, etc. It might be easier for Linux
> to write the data into pstore when it starts up?

Originally ramoops was just what you described. It has grown to
multiple backends and types of records (hence the rename to pstore).
If you just add a new subsection within the pstore region, then I
think the existing kernel infrastructure will support reading it from
userspace. Maybe new types have to be explicitly supported, IDK.

U-boot being able to read pstore wouldn't be a terrible feature to
have anyways if your boot crashes before anything else is up to get
the output. Note I'd guess the ram backend doesn't do compression as
supporting slightly corrupted ram is a feature which wouldn't work.


I think any new DT binding is premature and pstore/ramoops was just a
suggestion to consider. This needs wider consideration of how to
handle all the various (boot) firmware logs. I've added the
boot-architecture list for a bit more visibility.

Rob
Simon Glass Feb. 6, 2023, 11:56 p.m. UTC | #6
Hi Rob,

On Mon, 6 Feb 2023 at 16:32, Rob Herring <robh@kernel.org> wrote:
>
> +boot-architecture
>
> On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
> >
> > Hi Rob,
> >
> > On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> > >
> > > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > > >
> > > > Hi Peter,
> > > >
> > > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com> wrote:
> > > > >
> > > > > Hi Simon,
> > > > >
> > > > > Does it make sense to devise something that is compatible with the
> > > > > kernel's pstore [1] mechanism?
> > > >
> > > > Possibly...can you please be a little more specific?
> > >
> > > Peter is talking about the same thing I suggested on IRC.
> > >
> > > pstore == ramoops
> >
> > Oh, I only looked at the DT binding as I thought that was what you
> > were talking about on irc.
>
> The binding is called ramoops as it's for the RAM backend for pstore.
>
> My suggestion was either using/extending ramoops or following its
> design as a reserved memory region. All you would need to extend the
> ramoops binding is a new property to define the size of your data.

OK I see.

>
> > For pstore, isn't the point that Linux wants to save stuff to allow
> > debugging or collection on reboot? What does that have to do with
> > console logs from firmware? That seems like a different thing. Or are
> > you suggesting that we add a pstore driver into U-Boot? It is quite a
> > lot of code, including compression, etc. It might be easier for Linux
> > to write the data into pstore when it starts up?
>
> Originally ramoops was just what you described. It has grown to
> multiple backends and types of records (hence the rename to pstore).
> If you just add a new subsection within the pstore region, then I
> think the existing kernel infrastructure will support reading it from
> userspace. Maybe new types have to be explicitly supported, IDK.
>
> U-boot being able to read pstore wouldn't be a terrible feature to
> have anyways if your boot crashes before anything else is up to get
> the output. Note I'd guess the ram backend doesn't do compression as
> supporting slightly corrupted ram is a feature which wouldn't work.

I actually meant U-Boot writing to pstore...as that is the only way
that the console data could be provided to the kernel, as I understand
it.

Another question is how U-Boot could write thie information if the
pstore backend is not RAM?
>
>
> I think any new DT binding is premature and pstore/ramoops was just a
> suggestion to consider. This needs wider consideration of how to
> handle all the various (boot) firmware logs. I've added the
> boot-architecture list for a bit more visibility.

OK.

Regards,
SImon
Jan Lübbe Feb. 7, 2023, 11:56 a.m. UTC | #7
On Mon, 2023-02-06 at 17:32 -0600, Rob Herring wrote:
> +boot-architecture
> 
> On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
> > 
> > Hi Rob,
> > 
> > On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> > > 
> > > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > > > 
> > > > Hi Peter,
> > > > 
> > > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com>
> > > > wrote:
> > > > > 
> > > > > Hi Simon,
> > > > > 
> > > > > Does it make sense to devise something that is compatible with the
> > > > > kernel's pstore [1] mechanism?
> > > > 
> > > > Possibly...can you please be a little more specific?
> > > 
> > > Peter is talking about the same thing I suggested on IRC.
> > > 
> > > pstore == ramoops
> > 
> > Oh, I only looked at the DT binding as I thought that was what you
> > were talking about on irc.
> 
> The binding is called ramoops as it's for the RAM backend for pstore.
> 
> My suggestion was either using/extending ramoops or following its
> design as a reserved memory region. All you would need to extend the
> ramoops binding is a new property to define the size of your data.
> 
> > For pstore, isn't the point that Linux wants to save stuff to allow
> > debugging or collection on reboot? What does that have to do with
> > console logs from firmware? That seems like a different thing. Or are
> > you suggesting that we add a pstore driver into U-Boot? It is quite a
> > lot of code, including compression, etc. It might be easier for Linux
> > to write the data into pstore when it starts up?
> 
> Originally ramoops was just what you described. It has grown to
> multiple backends and types of records (hence the rename to pstore).
> If you just add a new subsection within the pstore region, then I
> think the existing kernel infrastructure will support reading it from
> userspace. Maybe new types have to be explicitly supported, IDK.
> 
> U-boot being able to read pstore wouldn't be a terrible feature to
> have anyways if your boot crashes before anything else is up to get
> the output. Note I'd guess the ram backend doesn't do compression as
> supporting slightly corrupted ram is a feature which wouldn't work.

This is basically how it works in Barebox. It can display the pstore contents
after a kernel crash and also (optionally) log to the pstore/ramooms console
log. Slight RAM corruption can be handled by using error correcting codes.

It's not perfect, of course, but still very useful.

Regards,
Jan

> I think any new DT binding is premature and pstore/ramoops was just a
> suggestion to consider. This needs wider consideration of how to
> handle all the various (boot) firmware logs. I've added the
> boot-architecture list for a bit more visibility.
Simon Glass Feb. 7, 2023, 1:38 p.m. UTC | #8
Hi Jan,

On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
>
> On Mon, 2023-02-06 at 17:32 -0600, Rob Herring wrote:
> > +boot-architecture
> >
> > On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
> > >
> > > Hi Rob,
> > >
> > > On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> > > >
> > > > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > > > >
> > > > > Hi Peter,
> > > > >
> > > > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com>
> > > > > wrote:
> > > > > >
> > > > > > Hi Simon,
> > > > > >
> > > > > > Does it make sense to devise something that is compatible with the
> > > > > > kernel's pstore [1] mechanism?
> > > > >
> > > > > Possibly...can you please be a little more specific?
> > > >
> > > > Peter is talking about the same thing I suggested on IRC.
> > > >
> > > > pstore == ramoops
> > >
> > > Oh, I only looked at the DT binding as I thought that was what you
> > > were talking about on irc.
> >
> > The binding is called ramoops as it's for the RAM backend for pstore.
> >
> > My suggestion was either using/extending ramoops or following its
> > design as a reserved memory region. All you would need to extend the
> > ramoops binding is a new property to define the size of your data.
> >
> > > For pstore, isn't the point that Linux wants to save stuff to allow
> > > debugging or collection on reboot? What does that have to do with
> > > console logs from firmware? That seems like a different thing. Or are
> > > you suggesting that we add a pstore driver into U-Boot? It is quite a
> > > lot of code, including compression, etc. It might be easier for Linux
> > > to write the data into pstore when it starts up?
> >
> > Originally ramoops was just what you described. It has grown to
> > multiple backends and types of records (hence the rename to pstore).
> > If you just add a new subsection within the pstore region, then I
> > think the existing kernel infrastructure will support reading it from
> > userspace. Maybe new types have to be explicitly supported, IDK.
> >
> > U-boot being able to read pstore wouldn't be a terrible feature to
> > have anyways if your boot crashes before anything else is up to get
> > the output. Note I'd guess the ram backend doesn't do compression as
> > supporting slightly corrupted ram is a feature which wouldn't work.
>
> This is basically how it works in Barebox. It can display the pstore contents
> after a kernel crash and also (optionally) log to the pstore/ramooms console
> log. Slight RAM corruption can be handled by using error correcting codes.
>
> It's not perfect, of course, but still very useful.

Thanks for the pointer. I had a look at this. How do you deal with
updating a filesystem that might be corrupt? Is that even a good idea,
if the purpose of it is to collect data from a kernel crash?

We are working on a firmware 'Transfer List' which is a simple data
structure to communicate through the different firmware phases. Since
U-Boot is the last one, in this case, I suppose it could do the
ramoops thing and add files for each of the firmware phases.

What about logging support? It would be nice to have a format that
understands logging level, category, filename/function, etc.

>
> Regards,
> Jan
>
> > I think any new DT binding is premature and pstore/ramoops was just a
> > suggestion to consider. This needs wider consideration of how to
> > handle all the various (boot) firmware logs. I've added the
> > boot-architecture list for a bit more visibility.

If this needs a call, I have not seen one for quite a while. It seems
to get cancelled at the last minute. I would be happy to attend one to
discuss this topic. But if people have ideas here, please weigh in.

Regards,
Simon
Jan Lübbe Feb. 7, 2023, 3:38 p.m. UTC | #9
On Tue, 2023-02-07 at 06:38 -0700, Simon Glass wrote:
> Hi Jan,
> 
> On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
> > 
> > On Mon, 2023-02-06 at 17:32 -0600, Rob Herring wrote:
> > > +boot-architecture
> > > 
> > > On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
> > > > 
> > > > Hi Rob,
> > > > 
> > > > On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> > > > > 
> > > > > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > > > > > 
> > > > > > Hi Peter,
> > > > > > 
> > > > > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com>
> > > > > > wrote:
> > > > > > > 
> > > > > > > Hi Simon,
> > > > > > > 
> > > > > > > Does it make sense to devise something that is compatible with the
> > > > > > > kernel's pstore [1] mechanism?
> > > > > > 
> > > > > > Possibly...can you please be a little more specific?
> > > > > 
> > > > > Peter is talking about the same thing I suggested on IRC.
> > > > > 
> > > > > pstore == ramoops
> > > > 
> > > > Oh, I only looked at the DT binding as I thought that was what you
> > > > were talking about on irc.
> > > 
> > > The binding is called ramoops as it's for the RAM backend for pstore.
> > > 
> > > My suggestion was either using/extending ramoops or following its
> > > design as a reserved memory region. All you would need to extend the
> > > ramoops binding is a new property to define the size of your data.
> > > 
> > > > For pstore, isn't the point that Linux wants to save stuff to allow
> > > > debugging or collection on reboot? What does that have to do with
> > > > console logs from firmware? That seems like a different thing. Or are
> > > > you suggesting that we add a pstore driver into U-Boot? It is quite a
> > > > lot of code, including compression, etc. It might be easier for Linux
> > > > to write the data into pstore when it starts up?
> > > 
> > > Originally ramoops was just what you described. It has grown to
> > > multiple backends and types of records (hence the rename to pstore).
> > > If you just add a new subsection within the pstore region, then I
> > > think the existing kernel infrastructure will support reading it from
> > > userspace. Maybe new types have to be explicitly supported, IDK.
> > > 
> > > U-boot being able to read pstore wouldn't be a terrible feature to
> > > have anyways if your boot crashes before anything else is up to get
> > > the output. Note I'd guess the ram backend doesn't do compression as
> > > supporting slightly corrupted ram is a feature which wouldn't work.
> > 
> > This is basically how it works in Barebox. It can display the pstore
> > contents
> > after a kernel crash and also (optionally) log to the pstore/ramooms console
> > log. Slight RAM corruption can be handled by using error correcting codes.
> > 
> > It's not perfect, of course, but still very useful.
> 
> Thanks for the pointer. I had a look at this. How do you deal with
> updating a filesystem that might be corrupt? Is that even a good idea,
> if the purpose of it is to collect data from a kernel crash?

This uses only the ramoops "backend" in pstore, so no filesystems are involved.
If I remember correctly, ramoops in the kernel just discards any data that is
too corrupted to process. Barebox should behave the same, as the code was ported
from the kernel.

> We are working on a firmware 'Transfer List' which is a simple data
> structure to communicate through the different firmware phases. Since
> U-Boot is the last one, in this case, I suppose it could do the
> ramoops thing and add files for each of the firmware phases.

For passing logs "forward" to the next step in the boot chain, this should work
as well and could be more explicit than the ramoops console. One benefit would
be that keeping the logs from each step separate, right?

ramoops has additional mechanisms to deal with the possible corruption caused by
the crash or reset cycle, which shouldn't be needed in to "forward" direction.

> What about logging support? It would be nice to have a format that
> understands logging level, category, filename/function, etc.

ramoops console is just unstructured text, Linux and Barebox just write
characters to it. More structure might be nice some cases, but the necessary
coordination between different projects could be a high barrier. ;)

Perhaps a simple list of text blocks would be enough, though.

> > Regards,
> > Jan
> > 
> > > I think any new DT binding is premature and pstore/ramoops was just a
> > > suggestion to consider. This needs wider consideration of how to
> > > handle all the various (boot) firmware logs. I've added the
> > > boot-architecture list for a bit more visibility.
> 
> If this needs a call, I have not seen one for quite a while. It seems
> to get cancelled at the last minute. I would be happy to attend one to
> discuss this topic. But if people have ideas here, please weigh in.

Looking at the proposed schema, I'd prefer to drop the boot-phase and project
patterns and use the lists as suggestions only. The order of /chosen/logs/log@N
should be enough to make sense of those.

Also to keep it simple, perhaps support the memory reference only, and drop the
in-DTB string?

Regards,
Jan
Simon Glass Feb. 7, 2023, 6:39 p.m. UTC | #10
Hi Jan,

On Tue, 7 Feb 2023 at 08:39, Jan Lübbe <jlu@pengutronix.de> wrote:
>
> On Tue, 2023-02-07 at 06:38 -0700, Simon Glass wrote:
> > Hi Jan,
> >
> > On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
> > >
> > > On Mon, 2023-02-06 at 17:32 -0600, Rob Herring wrote:
> > > > +boot-architecture
> > > >
> > > > On Mon, Feb 6, 2023 at 3:25 PM Simon Glass <sjg@chromium.org> wrote:
> > > > >
> > > > > Hi Rob,
> > > > >
> > > > > On Mon, 6 Feb 2023 at 10:15, Rob Herring <robh@kernel.org> wrote:
> > > > > >
> > > > > > On Sat, Feb 4, 2023 at 6:04 AM Simon Glass <sjg@chromium.org> wrote:
> > > > > > >
> > > > > > > Hi Peter,
> > > > > > >
> > > > > > > On Sat, 4 Feb 2023 at 02:36, Peter Robinson <pbrobinson@gmail.com>
> > > > > > > wrote:
> > > > > > > >
> > > > > > > > Hi Simon,
> > > > > > > >
> > > > > > > > Does it make sense to devise something that is compatible with the
> > > > > > > > kernel's pstore [1] mechanism?
> > > > > > >
> > > > > > > Possibly...can you please be a little more specific?
> > > > > >
> > > > > > Peter is talking about the same thing I suggested on IRC.
> > > > > >
> > > > > > pstore == ramoops
> > > > >
> > > > > Oh, I only looked at the DT binding as I thought that was what you
> > > > > were talking about on irc.
> > > >
> > > > The binding is called ramoops as it's for the RAM backend for pstore.
> > > >
> > > > My suggestion was either using/extending ramoops or following its
> > > > design as a reserved memory region. All you would need to extend the
> > > > ramoops binding is a new property to define the size of your data.
> > > >
> > > > > For pstore, isn't the point that Linux wants to save stuff to allow
> > > > > debugging or collection on reboot? What does that have to do with
> > > > > console logs from firmware? That seems like a different thing. Or are
> > > > > you suggesting that we add a pstore driver into U-Boot? It is quite a
> > > > > lot of code, including compression, etc. It might be easier for Linux
> > > > > to write the data into pstore when it starts up?
> > > >
> > > > Originally ramoops was just what you described. It has grown to
> > > > multiple backends and types of records (hence the rename to pstore).
> > > > If you just add a new subsection within the pstore region, then I
> > > > think the existing kernel infrastructure will support reading it from
> > > > userspace. Maybe new types have to be explicitly supported, IDK.
> > > >
> > > > U-boot being able to read pstore wouldn't be a terrible feature to
> > > > have anyways if your boot crashes before anything else is up to get
> > > > the output. Note I'd guess the ram backend doesn't do compression as
> > > > supporting slightly corrupted ram is a feature which wouldn't work.
> > >
> > > This is basically how it works in Barebox. It can display the pstore
> > > contents
> > > after a kernel crash and also (optionally) log to the pstore/ramooms console
> > > log. Slight RAM corruption can be handled by using error correcting codes.
> > >
> > > It's not perfect, of course, but still very useful.
> >
> > Thanks for the pointer. I had a look at this. How do you deal with
> > updating a filesystem that might be corrupt? Is that even a good idea,
> > if the purpose of it is to collect data from a kernel crash?
>
> This uses only the ramoops "backend" in pstore, so no filesystems are involved.
> If I remember correctly, ramoops in the kernel just discards any data that is
> too corrupted to process. Barebox should behave the same, as the code was ported
> from the kernel.

Yes...actually I found that U-Boot has pstore too, but it does not
support writing the console into it. I suppose it would be easy
enough, but it seems that U-Boot's pstore is not as advanced.

>
> > We are working on a firmware 'Transfer List' which is a simple data
> > structure to communicate through the different firmware phases. Since
> > U-Boot is the last one, in this case, I suppose it could do the
> > ramoops thing and add files for each of the firmware phases.
>
> For passing logs "forward" to the next step in the boot chain, this should work
> as well and could be more explicit than the ramoops console. One benefit would
> be that keeping the logs from each step separate, right?

Yes. But we can't use this to pass it to the kernel.

>
> ramoops has additional mechanisms to deal with the possible corruption caused by
> the crash or reset cycle, which shouldn't be needed in to "forward" direction.

But if there is corruption there, what does U-Boot do?

1. Clear the ramoops and write its console info (that will be annoying
for people trying to debug kernel crashes)
2. Leave it alone and not write the console info (then it is non-functional)
3. Or is it possible to write even when some things are corrupted?

>
> > What about logging support? It would be nice to have a format that
> > understands logging level, category, filename/function, etc.
>
> ramoops console is just unstructured text, Linux and Barebox just write
> characters to it. More structure might be nice some cases, but the necessary
> coordination between different projects could be a high barrier. ;)

Indeed it is, but that is the point of the binding :-)

>
> Perhaps a simple list of text blocks would be enough, though.

Do you mean a list of nul-terminated strings? What format are you thinking of?

>
> > > Regards,
> > > Jan
> > >
> > > > I think any new DT binding is premature and pstore/ramoops was just a
> > > > suggestion to consider. This needs wider consideration of how to
> > > > handle all the various (boot) firmware logs. I've added the
> > > > boot-architecture list for a bit more visibility.
> >
> > If this needs a call, I have not seen one for quite a while. It seems
> > to get cancelled at the last minute. I would be happy to attend one to
> > discuss this topic. But if people have ideas here, please weigh in.
>
> Looking at the proposed schema, I'd prefer to drop the boot-phase and project
> patterns and use the lists as suggestions only. The order of /chosen/logs/log@N
> should be enough to make sense of those.

Yes I suppose so, but I would really like to have a clear view of what
booted and which project it came from. Do you think it is an undue
burden?

>
> Also to keep it simple, perhaps support the memory reference only, and drop the
> in-DTB string?

Yes, that can work. We can always add it later...copying the text into
the DT does add overhead so it would be better to avoid it where
possible.

Regards,
Simon
Jan Lübbe Feb. 8, 2023, 8:14 a.m. UTC | #11
On Tue, 2023-02-07 at 11:39 -0700, Simon Glass wrote:
> Hi Jan,
> 
> On Tue, 7 Feb 2023 at 08:39, Jan Lübbe <jlu@pengutronix.de> wrote:
> > 
> > On Tue, 2023-02-07 at 06:38 -0700, Simon Glass wrote:
> > > Hi Jan,
> > > 
> > > On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
> > > 
[snip]
> > > Thanks for the pointer. I had a look at this. How do you deal with
> > > updating a filesystem that might be corrupt? Is that even a good idea,
> > > if the purpose of it is to collect data from a kernel crash?
> > 
> > This uses only the ramoops "backend" in pstore, so no filesystems are involved.
> > If I remember correctly, ramoops in the kernel just discards any data that is
> > too corrupted to process. Barebox should behave the same, as the code was ported
> > from the kernel.
> 
> Yes...actually I found that U-Boot has pstore too, but it does not
> support writing the console into it. I suppose it would be easy
> enough, but it seems that U-Boot's pstore is not as advanced.
> > 

> > > We are working on a firmware 'Transfer List' which is a simple data
> > > structure to communicate through the different firmware phases. Since
> > > U-Boot is the last one, in this case, I suppose it could do the
> > > ramoops thing and add files for each of the firmware phases.
> > 
> > For passing logs "forward" to the next step in the boot chain, this should work
> > as well and could be more explicit than the ramoops console. One benefit would
> > be that keeping the logs from each step separate, right?
> 
> Yes. But we can't use this to pass it to the kernel.
> 

Hmm, because we would need to reserve space for the text memory regions, which
couldn't be used by the kernel later?

> > ramoops has additional mechanisms to deal with the possible corruption caused by
> > the crash or reset cycle, which shouldn't be needed in to "forward" direction.
> 
> But if there is corruption there, what does U-Boot do?
> 
> 1. Clear the ramoops and write its console info (that will be annoying
> for people trying to debug kernel crashes)
> 2. Leave it alone and not write the console info (then it is non-functional)
> 3. Or is it possible to write even when some things are corrupted?

As the console is protected by ECC in blocks, you can have corrupted blocks in
the middle and still continue logging at the end, if you want. The corrupted
block can then either be repaired when reading or need to be skipped.

> > > What about logging support? It would be nice to have a format that
> > > understands logging level, category, filename/function, etc.
> > 
> > ramoops console is just unstructured text, Linux and Barebox just write
> > characters to it. More structure might be nice some cases, but the necessary
> > coordination between different projects could be a high barrier. ;)
> 
> Indeed it is, but that is the point of the binding :-)
> 
> > 
> > Perhaps a simple list of text blocks would be enough, though.
> 
> Do you mean a list of nul-terminated strings? What format are you thinking of?
> > > 

I think the format described in the binding should work well enough (ASCII
lines, with NUL termination). And it's readable on a terminal. :)

> > > > Regards,
> > > > Jan
> > > > 
> > > > > I think any new DT binding is premature and pstore/ramoops was just a
> > > > > suggestion to consider. This needs wider consideration of how to
> > > > > handle all the various (boot) firmware logs. I've added the
> > > > > boot-architecture list for a bit more visibility.
> > > 
> > > If this needs a call, I have not seen one for quite a while. It seems
> > > to get cancelled at the last minute. I would be happy to attend one to
> > > discuss this topic. But if people have ideas here, please weigh in.
> > 
> > Looking at the proposed schema, I'd prefer to drop the boot-phase and project
> > patterns and use the lists as suggestions only. The order of /chosen/logs/log@N
> > should be enough to make sense of those.
> 
> Yes I suppose so, but I would really like to have a clear view of what
> booted and which project it came from. Do you think it is an undue
> burden?
> 

I didn't mean to drop the properties, but to allow free-form text. Not all
firmware stacks use the same phases and not all bootloader project names start
with "^U-Boot|TF-A". :)

I don't think we'll see project name collisions, and the boot-phase name should
be unique with in a project, so free-form should be fine.

> > Also to keep it simple, perhaps support the memory reference only, and drop the
> > in-DTB string?
> 
> Yes, that can work. We can always add it later...copying the text into
> the DT does add overhead so it would be better to avoid it where
> possible.

Agreed.


Regards,
Jan
Simon Glass Feb. 9, 2023, 6:05 p.m. UTC | #12
Hi Jan,

On Wed, 8 Feb 2023 at 01:15, Jan Lübbe <jlu@pengutronix.de> wrote:
>
> On Tue, 2023-02-07 at 11:39 -0700, Simon Glass wrote:
> > Hi Jan,
> >
> > On Tue, 7 Feb 2023 at 08:39, Jan Lübbe <jlu@pengutronix.de> wrote:
> > >
> > > On Tue, 2023-02-07 at 06:38 -0700, Simon Glass wrote:
> > > > Hi Jan,
> > > >
> > > > On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
> > > >
> [snip]
> > > > Thanks for the pointer. I had a look at this. How do you deal with
> > > > updating a filesystem that might be corrupt? Is that even a good idea,
> > > > if the purpose of it is to collect data from a kernel crash?
> > >
> > > This uses only the ramoops "backend" in pstore, so no filesystems are involved.
> > > If I remember correctly, ramoops in the kernel just discards any data that is
> > > too corrupted to process. Barebox should behave the same, as the code was ported
> > > from the kernel.
> >
> > Yes...actually I found that U-Boot has pstore too, but it does not
> > support writing the console into it. I suppose it would be easy
> > enough, but it seems that U-Boot's pstore is not as advanced.
> > >
>
> > > > We are working on a firmware 'Transfer List' which is a simple data
> > > > structure to communicate through the different firmware phases. Since
> > > > U-Boot is the last one, in this case, I suppose it could do the
> > > > ramoops thing and add files for each of the firmware phases.
> > >
> > > For passing logs "forward" to the next step in the boot chain, this should work
> > > as well and could be more explicit than the ramoops console. One benefit would
> > > be that keeping the logs from each step separate, right?
> >
> > Yes. But we can't use this to pass it to the kernel.
> >
>
> Hmm, because we would need to reserve space for the text memory regions, which
> couldn't be used by the kernel later?

Because the transfer list does not get passed to the kernel. We don't
want to invent another way to pass info to Linux, since we already
have FDT, ACPI and cmdline. In fact I have a horrible suspicion that
someone added a structured cmdline a bit like an FDT but in text...

>
> > > ramoops has additional mechanisms to deal with the possible corruption caused by
> > > the crash or reset cycle, which shouldn't be needed in to "forward" direction.
> >
> > But if there is corruption there, what does U-Boot do?
> >
> > 1. Clear the ramoops and write its console info (that will be annoying
> > for people trying to debug kernel crashes)
> > 2. Leave it alone and not write the console info (then it is non-functional)
> > 3. Or is it possible to write even when some things are corrupted?
>
> As the console is protected by ECC in blocks, you can have corrupted blocks in
> the middle and still continue logging at the end, if you want. The corrupted
> block can then either be repaired when reading or need to be skipped.

OK I see.

>
> > > > What about logging support? It would be nice to have a format that
> > > > understands logging level, category, filename/function, etc.
> > >
> > > ramoops console is just unstructured text, Linux and Barebox just write
> > > characters to it. More structure might be nice some cases, but the necessary
> > > coordination between different projects could be a high barrier. ;)
> >
> > Indeed it is, but that is the point of the binding :-)
> >
> > >
> > > Perhaps a simple list of text blocks would be enough, though.
> >
> > Do you mean a list of nul-terminated strings? What format are you thinking of?
> > > >
>
> I think the format described in the binding should work well enough (ASCII
> lines, with NUL termination). And it's readable on a terminal. :)

Yes I think that is important.

>
> > > > > Regards,
> > > > > Jan
> > > > >
> > > > > > I think any new DT binding is premature and pstore/ramoops was just a
> > > > > > suggestion to consider. This needs wider consideration of how to
> > > > > > handle all the various (boot) firmware logs. I've added the
> > > > > > boot-architecture list for a bit more visibility.
> > > >
> > > > If this needs a call, I have not seen one for quite a while. It seems
> > > > to get cancelled at the last minute. I would be happy to attend one to
> > > > discuss this topic. But if people have ideas here, please weigh in.
> > >
> > > Looking at the proposed schema, I'd prefer to drop the boot-phase and project
> > > patterns and use the lists as suggestions only. The order of /chosen/logs/log@N
> > > should be enough to make sense of those.
> >
> > Yes I suppose so, but I would really like to have a clear view of what
> > booted and which project it came from. Do you think it is an undue
> > burden?
> >
>
> I didn't mean to drop the properties, but to allow free-form text. Not all
> firmware stacks use the same phases and not all bootloader project names start
> with "^U-Boot|TF-A". :)
>
> I don't think we'll see project name collisions, and the boot-phase name should
> be unique with in a project, so free-form should be fine.
>
> > > Also to keep it simple, perhaps support the memory reference only, and drop the
> > > in-DTB string?
> >
> > Yes, that can work. We can always add it later...copying the text into
> > the DT does add overhead so it would be better to avoid it where
> > possible.
>
> Agreed.

Regards,
Simon
Ard Biesheuvel Feb. 10, 2023, 9:12 a.m. UTC | #13
On Thu, 9 Feb 2023 at 19:05, Simon Glass <sjg@chromium.org> wrote:
>
> Hi Jan,
>
> On Wed, 8 Feb 2023 at 01:15, Jan Lübbe <jlu@pengutronix.de> wrote:
> >
> > On Tue, 2023-02-07 at 11:39 -0700, Simon Glass wrote:
> > > Hi Jan,
> > >
> > > On Tue, 7 Feb 2023 at 08:39, Jan Lübbe <jlu@pengutronix.de> wrote:
> > > >
> > > > On Tue, 2023-02-07 at 06:38 -0700, Simon Glass wrote:
> > > > > Hi Jan,
> > > > >
> > > > > On Tue, 7 Feb 2023 at 04:56, Jan Lübbe <jlu@pengutronix.de> wrote:
> > > > >
> > [snip]
> > > > > Thanks for the pointer. I had a look at this. How do you deal with
> > > > > updating a filesystem that might be corrupt? Is that even a good idea,
> > > > > if the purpose of it is to collect data from a kernel crash?
> > > >
> > > > This uses only the ramoops "backend" in pstore, so no filesystems are involved.
> > > > If I remember correctly, ramoops in the kernel just discards any data that is
> > > > too corrupted to process. Barebox should behave the same, as the code was ported
> > > > from the kernel.
> > >
> > > Yes...actually I found that U-Boot has pstore too, but it does not
> > > support writing the console into it. I suppose it would be easy
> > > enough, but it seems that U-Boot's pstore is not as advanced.
> > > >
> >
> > > > > We are working on a firmware 'Transfer List' which is a simple data
> > > > > structure to communicate through the different firmware phases. Since
> > > > > U-Boot is the last one, in this case, I suppose it could do the
> > > > > ramoops thing and add files for each of the firmware phases.
> > > >
> > > > For passing logs "forward" to the next step in the boot chain, this should work
> > > > as well and could be more explicit than the ramoops console. One benefit would
> > > > be that keeping the logs from each step separate, right?
> > >
> > > Yes. But we can't use this to pass it to the kernel.
> > >
> >
> > Hmm, because we would need to reserve space for the text memory regions, which
> > couldn't be used by the kernel later?
>
> Because the transfer list does not get passed to the kernel. We don't
> want to invent another way to pass info to Linux, since we already
> have FDT, ACPI and cmdline. In fact I have a horrible suspicion that
> someone added a structured cmdline a bit like an FDT but in text...
>

Yes, the tracing folks in Linux cooked up 'bootconfig' without
involving a single person that was already active in boot
architecture, boot loaders, firmware, etc. I was quite shocked by that
as well.

It seems to be another hierarchical key/value pair store, used for
passing a large set of command line arguments which may otherwise
exceed the maximum length of the kernel command line. It is appended
to the initrd by the boot loader. Android have already started using
it as well.
diff mbox series

Patch

diff --git a/dtschema/schemas/chosen.yaml b/dtschema/schemas/chosen.yaml
index 86194dd..46cc9fb 100644
--- a/dtschema/schemas/chosen.yaml
+++ b/dtschema/schemas/chosen.yaml
@@ -236,6 +236,9 @@  properties:
       system.
 
 patternProperties:
+  '^logs$':
+    $ref: logs.yaml#
+
   "^framebuffer": true
 
 additionalProperties: false
diff --git a/dtschema/schemas/log.yaml b/dtschema/schemas/log.yaml
new file mode 100644
index 0000000..5218234
--- /dev/null
+++ b/dtschema/schemas/log.yaml
@@ -0,0 +1,176 @@ 
+# SPDX-License-Identifier: BSD-2-Clause
+# Copyright 2023 Google LLC
+%YAML 1.2
+---
+$id: http://devicetree.org/schemas/log.yaml#
+$schema: http://devicetree.org/meta-schemas/core.yaml#
+
+title: Log-output binding
+
+maintainers:
+  - Simon Glass <sjg@chromium.org>
+
+description:
+  This holds a log file or console dump created by a single phase of the boot.
+  It typically consists of plain ASCII text, but it is also possible to
+  add metadata like files and line numbers.
+
+  Each log node has a hex unit address which indicates the order of progress
+  through the boot phases. The first node must be log@0, followed by
+  log@1, etc.
+
+select: false
+
+properties:
+  reg:
+    description:
+      Defines a unique log ID for the log represented by the log node.
+
+  boot-phase:
+    $ref: types.yaml#/definitions/string
+    description: |
+      Indicates the phase of boot which produced this log:
+
+        - pre-sram: Before SRAM is available
+        - verify: Verification step, which decides which of the available images
+          should be run next
+        - pre-ram: Sets up SDRAM
+        - some-ram: After SDRAM is working but before all of it is available.
+          Some RAM is available but it is limited (e.g. it may be split into
+          two pieces by the location of the running program) because the
+          program code is not yet relocated out of the way.
+        - loader: OS loader, typically the final firmware step
+
+    pattern: "^pre-sram|verify|pre-ram|some-ram|loader$"
+
+  project:
+    $ref: types.yaml#/definitions/string
+    description:
+      Indicates the name of the project which produced this log
+
+    pattern: "^U-Boot|TF-A"
+
+  time-format:
+    $ref: types.yaml#/definitions/string
+    description: |
+      Indicates the time format used by the log. Options are:
+
+        usec - a integer number of microseconds since reset was released,
+               expressed in ASCII, e.g. "123"
+
+    pattern: "^usec$"
+
+  text-start:
+    oneOf:
+      - $ref: types.yaml#/definitions/uint32
+      - $ref: types.yaml#/definitions/uint64
+    description:
+      These properties hold the physical start and end address of the log text
+      if the 'text' property is not used.
+
+      Note that text-start is inclusive, but text-end is exclusive.
+
+      The text must be terminated with a NUL character.
+
+  text-end:
+    oneOf:
+      - $ref: types.yaml#/definitions/uint32
+      - $ref: types.yaml#/definitions/uint64
+    description:
+      These properties hold the physical start and end address of the log text
+      if the 'text' property is not used.
+
+      Note that text-start is inclusive, but text-end is exclusive.
+
+      The text must be terminated with a NUL character.
+
+  text:
+    $ref: types.yaml#/definitions/string
+    description: |
+      Contains the log text, if it is not referred to by text-start / text-end.
+
+      The format is ASCII with US and SOT used to indicate optional fields:
+
+        [timestamp<US>][level[:category[:filename[:line[:function]]]]]<SOT>]message[<LF>|<ETX>]
+
+      where:
+
+        timestamp is the timestamp, according to time-format
+
+        level is the single-digit log level:
+           0 - emergency (program is unstable)
+           1 - alert (action must be taken immediately)
+           2 - crit (critical conditions)
+           3 - err (error that prevents something from working
+           4 - warning (may prevent optimal operation)
+           5 - notice (normal but significant condition, printf())
+           6 - info (general information message)
+           7 - debug (basic debug-level message)
+           8 - debug content (debug message showing full message content)
+           9 - debug I/O (debug message showing hardware I/O access)
+
+        category is the category name which is project-dependent
+
+        filename is the relative filename (__FILE__ in C)
+
+        line is the line number starting from 1 (__LINE__ in C)
+
+        function is the function name (__func__ in C)
+
+        message is the message string, which may not contain control
+        characters (beyond those listed above) except for HT and LF. DEL and CR
+        are not permitted.
+
+      The timestamp is present only if US is in the string.
+
+      The fields before <SOT> are all optional, but must be listed in order.
+      To omit a field in the middle, use an empty string between two colons.
+      To omit a field at the end, just leave it out along with the colon before
+      it.
+
+      Typically LF is used as a line delimiter, but if a record does not
+      end with a newline, ETX can be used. This indicates that it is a new
+      log record but without a newline between them. Often (but not always)
+      the 'continuation' does not include the US and SOT information.
+
+      A log record without a LF or ETX terminator is considered invalid, even
+      if it is the final record.
+
+      Examples:
+
+         123<US>5:tpm:lib/tpm.c:334:tpm_init<SOT>TPM starting...<LF>
+         23<US>Hello<LF>
+         2:boot:lib/panic.c:84:panic<SOT>Memory training failed<LF>
+         7:mmc:::mmc_bind<SOT>Cannot create block device<LF>
+         Net:   eth0: host_lo, eth1: host_enp1s0<ETX>
+
+      ASCII characters:
+
+        SOT - 0x2  - indicates the start of the message. This is optional if
+                     the record has nothing but a message
+        ETX - 0x3  - indicates the end of a log record (without new line)
+        LF  - 0xa  - indicates the end of a log record (and new line)
+        US  - 0x1f - indicates the end of the timestamp (and that it is present
+                     in the record)
+
+      The above format is intended to be unambiguous, while still being fairly
+      readable it just shown on a terminal with all control characters except
+      LF dropped. The CR character is not permitted since it is not needed to
+      signal an end of line and it avoids worrying about what <CR><LF> actually
+      means.
+
+      The text size is determined by the property size. The last byte must be
+      a NUL character.
+
+required:
+  - boot-phase
+  - project
+
+anyOf:
+  - required:
+    - text
+  - required:
+    - text-start
+    - text-end
+
+additionalProperties: false
diff --git a/dtschema/schemas/logs.yaml b/dtschema/schemas/logs.yaml
new file mode 100644
index 0000000..76ba2b0
--- /dev/null
+++ b/dtschema/schemas/logs.yaml
@@ -0,0 +1,30 @@ 
+# SPDX-License-Identifier: BSD-2-Clause
+# Copyright 2023 Google LLC
+%YAML 1.2
+---
+$id: http://devicetree.org/schemas/logs.yaml#
+$schema: http://devicetree.org/meta-schemas/core.yaml#
+
+title: Log information collected during firmware execution
+
+maintainers:
+  - Simon Glass <sjg@chromium.org>
+
+description:
+  This holds a set of logs build up during booting of the machine. The
+  collection of logs is described in the "/logs" node.  This node in turn
+  contains a number of subnodes representing individual log output from
+  different boot phases.
+
+properties:
+  '#address-cells':
+    const: 1
+
+  '#size-cells':
+    const: 0
+
+patternProperties:
+  '^log@[0-9a-f]+$':
+    $ref: log.yaml#
+
+additionalProperties: false
diff --git a/test/logs.dts b/test/logs.dts
new file mode 100644
index 0000000..7d044df
--- /dev/null
+++ b/test/logs.dts
@@ -0,0 +1,47 @@ 
+// SPDX-License-Identifier: BSD-2-Clause
+// Copyright 2023 Google LLC
+
+// Used to validate the "logs" node and its child "log" nodes
+
+// dtc -O dtb -o test.dtb test/bootphases.dts && tools/dt-validate -s test/schemas -m test.dtb
+
+
+/dts-v1/;
+
+/ {
+	model = "none";
+	compatible = "foo";
+
+	#address-cells = <1>;
+	#size-cells = <1>;
+
+	chosen {
+		logs {
+			#address-cells = <1>;
+			#size-cells = <0>;
+
+			log@0 {
+				reg = <0>;
+				boot-phase = "pre-ram";
+				project = "U-Boot";
+				text = "\nU-Boot SPL 2023.01 (Feb 03 2023 - 14:45:39 -0700)\nTrying to boot from sandbox_image\nTrying to boot from sandbox_file\n";
+			};
+
+			log@1 {
+				reg = <1>;
+				boot-phase = "loader";
+				project = "U-Boot";
+				time-format = "usec";
+				text = "\n\n123\x1f2:boot:lib/display_options.c:43:display_options\x02U-Boot 2023.01 (Feb 03 2023 - 14:45:39 -0700)\n\nReset Status: COLD\nModel: sandbox\nDRAM:  256 MiB\n";
+			};
+
+			log@2 {
+				reg = <2>;
+				boot-phase = "pre-ram";
+				project = "TF-A";
+				text-start = <0x103000>;
+				text-end = <0x107000>;
+			};
+		};
+	};
+};