Hey,
This is next attempt to create firmware and bootloader log specification.
Due to high interest among industry it is an extension to the initial
bootloader log only specification. It takes into the account most of the
comments which I got up until now.
The goal is to pass all logs produced by various boot components to the
running OS. The OS kernel should expose these logs to the user space
and/or process them internally if needed. The content of these logs
should be human readable. However, they should also contain the
information which allows admins to do e.g. boot time analysis.
The log specification should be as much as possible platform agnostic
and self contained. The final version of this spec should be merged into
existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
spec, e.g. as a part of OASIS Standards. The former seems better but is
not perfect too...
Here is the description (pseudocode) of the structures which will be
used to store the log data.
struct bf_log
{
uint32_t version;
char producer[64];
uint64_t flags;
uint64_t next_bf_log_addr;
uint32_t next_msg_off;
bf_log_msg msgs[];
}
struct bf_log_msg
{
uint32_t size;
uint64_t ts_nsec;
uint32_t level;
uint32_t facility;
uint32_t msg_off;
char strings[];
}
The members of struct bf_log:
- version: the firmware and bootloader log format version number, 1 for now,
- producer: the producer/firmware/bootloader/... type; the length
allows ASCII UUID storage if somebody needs that functionality,
- flags: it can be used to store information about log state, e.g.
it was truncated or not (does it make sense to have an information
about the number of lost messages?),
- next_bf_log_addr: address of next bf_log struct; none if zero (I think
newer spec versions should not change anything in first 5 bf_log members;
this way older log parsers will be able to traverse/copy all logs regardless
of version used in one log or another),
- next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
of the next byte after the last log message in the msgs[]; i.e. the offset
of the next available log message slot; it is equal to the total size of
the log buffer including the bf_log struct,
- msgs: the array of log messages,
- should we add CRC or hash or signatures here?
The members of struct bf_log_msg:
- size: total size of bf_log_msg struct,
- ts_nsec: timestamp expressed in nanoseconds starting from 0,
- level: similar to syslog meaning; can be used to differentiate normal messages
from debug messages; the exact interpretation depends on the current producer
type specified in the bf_log.producer,
- facility: similar to syslog meaning; can be used to differentiate the sources of
the messages, e.g. message produced by networking module; the exact interpretation
depends on the current producer type specified in the bf_log.producer,
- msg_off: the log message offset in strings[],
- strings[0]: the beginning of log message type, similar to the facility member but
NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
for messages printed using grub_dprintf(),
- strings[msg_off]: the beginning of log message, NUL terminated string.
Note: The producers are free to use/ignore any given set of level, facility and/or
log type members. Though the usage of these members has to be clearly defined.
Ignored integer members should be set to 0. Ignored log message type should
contain an empty NUL terminated string. The log message is mandatory but can
be an empty NUL terminated string.
There is still not fully solved problem how the logs should be presented to the OS.
On the UEFI platforms we can use config tables to do that. Then probably
bf_log.next_bf_log_addr should not be used. On the ACPI and Device Tree platforms
we can use these mechanisms to present the logs to the OSes. The situation gets more
difficult if neither of these mechanisms are present. However, maybe we should not
bother too much about that because probably these platforms getting less and less
common.
Anyway, I am aware that this is not specification per se. The goal of this email is
to continue the discussion about the idea of the firmware and booloader log and to
find out where the final specification should land. Of course taking into the account
assumptions made above.
You can find previous discussions about related topics at [1], [2] and [3].
Additionally, I am going to present this during GRUB mini-summit session on Tuesday,
17th of November at 15:45 UTC. So, if you want to discuss the log design please join
us. You can find more details here [4].
Daniel
[1] https://lists.gnu.org/archive/html/grub-devel/2019-10/msg00107.html
[2] https://lists.gnu.org/archive/html/grub-devel/2019-11/msg00079.html
[3] https://lists.gnu.org/archive/html/grub-devel/2020-05/msg00223.html
[4] https://twitter.com/3mdeb_com/status/1327278804100931587
On 11/13/20 3:52 PM, Daniel Kiper wrote:
> Hey,
>
>
> Here is the description (pseudocode) of the structures which will be
> used to store the log data.
>
> Anyway, I am aware that this is not specification per se.
Yes, you have caveats here. I'm sure that you either already know
or would learn soon enough that struct struct bf_log has some
padding added to it (for alignment) unless it is packed.
Or you could rearrange the order of some of its fields
and save 8 bytes per struct on x86_64.
> struct bf_log
> {
> uint32_t version;
> char producer[64];
> uint64_t flags;
> uint64_t next_bf_log_addr;
> uint32_t next_msg_off;
> bf_log_msg msgs[];
> }
>
> struct bf_log_msg
> {
> uint32_t size;
> uint64_t ts_nsec;
> uint32_t level;
> uint32_t facility;
> uint32_t msg_off;
> char strings[];
> }
cheers.
--
~Randy
Hi Daniel,
I think this is a good idea. Alas, as I hear for the first time about
it, I lack any context of prior discussions / context. So bear with me,
if I ask things that have already been answered.
On 14.11.20 00:52, Daniel Kiper wrote:
> The goal is to pass all logs produced by various boot components to the
> running OS. The OS kernel should expose these logs to the user space
> and/or process them internally if needed. The content of these logs
> should be human readable. However, they should also contain the
> information which allows admins to do e.g. boot time analysis.
>
> The log specification should be as much as possible platform agnostic
> and self contained. The final version of this spec should be merged into
> existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
> spec, e.g. as a part of OASIS Standards. The former seems better but is
> not perfect too...
>
> Here is the description (pseudocode) of the structures which will be
> used to store the log data.
I guess using C syntax for your "pseudocode" isn't a good choice as it
can confuse people and might lead to (unportable) implementations that
try to copy this definition to C. IMHO, it's much better for a specifi-
cation to provide exact bit/byte offsets. The protocol tool [P], for
instance, can be used to draw things in ASCII. A portable C implemen-
tation could then use these offsets for proper (de)serialization with-
out structs that try to mimic the representation in memory.
> The members of struct bf_log:
> - version: the firmware and bootloader log format version number, 1 for now,
> - producer: the producer/firmware/bootloader/... type; the length
> allows ASCII UUID storage if somebody needs that functionality,
So, is this always supposed to be a string?
> - flags: it can be used to store information about log state, e.g.
> it was truncated or not (does it make sense to have an information
> about the number of lost messages?),
Truncation is an interesting point as I see no length for the available
space specified. I assume most implementations would want a field for
this. Otherwise they would have to track it separately.
In coreboot, we use a ring-buffer for messages as it seems more useful
to keep the most recent messages, it's also extended across reboots and
suspend/resume cycles. For this, it would need an additional pointer
where the oldest message resides, iow. where to start reading messages.
> - next_bf_log_addr: address of next bf_log struct; none if zero
Do I understand this correctly that a later-stage boot component would
use this to add its own `bf_log` to the chain? e.g. if I start initia-
lizing hardware with coreboot and then use GRUB2 to boot, each of them
would set up its own ` bf_log` and GRUB2 would set this pointer if
possible?
> (I think
> newer spec versions should not change anything in first 5 bf_log members;
> this way older log parsers will be able to traverse/copy all logs regardless
> of version used in one log or another),
Good point, which brings me to another good practice regarding such
data formats: A length field for the header. In this case the length
from the start of `bf_log` to the start of `msgs`. This would give
us backwards compatibility in case additional fields are added in
the future. And would also allow the various implementation to add
custom fields (not for communication with log parser but for their
own use).
> - next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
> of the next byte after the last log message in the msgs[]; i.e. the offset
> of the next available log message slot; it is equal to the total size of
> the log buffer including the bf_log struct,
> - msgs: the array of log messages,
> - should we add CRC or hash or signatures here?
>
> The members of struct bf_log_msg:
> - size: total size of bf_log_msg struct,
Does this include the actual message string?
> - ts_nsec: timestamp expressed in nanoseconds starting from 0,
But what is 0? In coreboot, we log timestamps relative to the last
reset. Which, if applied to our log ring-buffer, might make things
confusing because it can contain messages from multiple boots.
> - level: similar to syslog meaning; can be used to differentiate normal messages
> from debug messages; the exact interpretation depends on the current producer
> type specified in the bf_log.producer,
> - facility: similar to syslog meaning; can be used to differentiate the sources of
> the messages, e.g. message produced by networking module; the exact interpretation
> depends on the current producer type specified in the bf_log.producer,
> - msg_off: the log message offset in strings[],
> - strings[0]: the beginning of log message type, similar to the facility member but
> NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
> for messages printed using grub_dprintf(),
I don't think this is a good idea. It seems you want to start a new spec
that already supports two competing formats (the `facility` field and
this string). I know it's sometimes hard to make everybody happy, but
think we should decide for a single format. I'll try to find some time
to read about this GRUB string and prior discussions.
> - strings[msg_off]: the beginning of log message, NUL terminated string.
> There is still not fully solved problem how the logs should be presented to the OS.
> On the UEFI platforms we can use config tables to do that. Then probably
> bf_log.next_bf_log_addr should not be used. On the ACPI and Device Tree platforms
> we can use these mechanisms to present the logs to the OSes. The situation gets more
> difficult if neither of these mechanisms are present. However, maybe we should not
> bother too much about that because probably these platforms getting less and less
> common.
There is also the question how a later-stage boot component would do
this. It might not be easy for them to adapt ACPI, for instance (and
if no `bf_log` chain is set up yet, it can't extend that either). Maybe
just leave this open. Beside references to the big ones of course, which
may need some assigned number (UEFI? ACPI?).
Nico
[P] http://www.luismg.com/protocol/
>>> Daniel Kiper <[email protected]> schrieb am 14.11.2020 um 00:52 in
Nachricht <[email protected]>:
...
> The members of struct bf_log_msg:
> ‑ size: total size of bf_log_msg struct,
> ‑ ts_nsec: timestamp expressed in nanoseconds starting from 0,
Who or what defines t == 0?
...
Regards,
Ulrich Windl
On 16/11/2020 08.02, Ulrich Windl wrote:
>>>> Daniel Kiper <[email protected]> schrieb am 14.11.2020 um 00:52 in
> Nachricht <[email protected]>:
> ...
>> The members of struct bf_log_msg:
>> ‑ size: total size of bf_log_msg struct,
>> ‑ ts_nsec: timestamp expressed in nanoseconds starting from 0,
>
> Who or what defines t == 0?
Some sort of "clapperboard" log entry, stating "the RTC says X, the
cycle counter is Y, the onboard ACME atomic clock says Z, I'm now
starting to count ts_nsec from W" might be useful for some eventual
userspace tool to try to stitch together the log entries from the
various stages. I have no idea how a formal spec of such an entry would
look like or if it's even feasible to do formally. But even just such
entries in free-form prose could at least help a human consumer.
Rasmus
On 14.11.20 00:52, Daniel Kiper wrote:
> Hey,
>
> This is next attempt to create firmware and bootloader log specification.
> Due to high interest among industry it is an extension to the initial
> bootloader log only specification. It takes into the account most of the
> comments which I got up until now.
>
> The goal is to pass all logs produced by various boot components to the
> running OS. The OS kernel should expose these logs to the user space
> and/or process them internally if needed. The content of these logs
> should be human readable. However, they should also contain the
> information which allows admins to do e.g. boot time analysis.
>
> The log specification should be as much as possible platform agnostic
> and self contained. The final version of this spec should be merged into
> existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
> spec, e.g. as a part of OASIS Standards. The former seems better but is
> not perfect too...
>
> Here is the description (pseudocode) of the structures which will be
> used to store the log data.
Hello Daniel,
thanks for your suggestion which makes good sense to me.
Why can't we simply use the message format defined in "The Syslog
Protocol", https://tools.ietf.org/html/rfc5424?
>
> struct bf_log
> {
> uint32_t version;
> char producer[64];
> uint64_t flags;
> uint64_t next_bf_log_addr;
> uint32_t next_msg_off;
> bf_log_msg msgs[];
As bf_log_msg is does not have defined length msgs[] cannot be an array.
> }
>
> struct bf_log_msg
> {
> uint32_t size;
> uint64_t ts_nsec;
> uint32_t level;
> uint32_t facility;
> uint32_t msg_off;
> char strings[];
> }
>
> The members of struct bf_log:
> - version: the firmware and bootloader log format version number, 1 for now,
> - producer: the producer/firmware/bootloader/... type; the length
> allows ASCII UUID storage if somebody needs that functionality,
> - flags: it can be used to store information about log state, e.g.
> it was truncated or not (does it make sense to have an information
> about the number of lost messages?),
> - next_bf_log_addr: address of next bf_log struct; none if zero (I think
> newer spec versions should not change anything in first 5 bf_log members;
> this way older log parsers will be able to traverse/copy all logs regardless
> of version used in one log or another),
> - next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
> of the next byte after the last log message in the msgs[]; i.e. the offset
> of the next available log message slot; it is equal to the total size of
> the log buffer including the bf_log struct,
Why would you need an offset to first unused byte?
We possibly have multiple producers of messages:
- TF-A
- U-Boot
- iPXE
- GRUB
What we need is the offset to the next struct bf_log.
> - msgs: the array of log messages,
> - should we add CRC or hash or signatures here?
>
> The members of struct bf_log_msg:
> - size: total size of bf_log_msg struct,
> - ts_nsec: timestamp expressed in nanoseconds starting from 0,
Would each message producer start from 0?
Shouldn't we use the time from the hardware RTC if it is available via
boot service GetTime()?
> - level: similar to syslog meaning; can be used to differentiate normal messages
> from debug messages; the exact interpretation depends on the current producer
> type specified in the bf_log.producer,
> - facility: similar to syslog meaning; can be used to differentiate the sources of
> the messages, e.g. message produced by networking module; the exact interpretation
> depends on the current producer type specified in the bf_log.producer,
> - msg_off: the log message offset in strings[],
What is this field good for? Why don't you start the the string at
strings[0]?
What would be useful would be the offset to the next bf_log_msg.
> - strings[0]: the beginning of log message type, similar to the facility member but
> NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
> for messages printed using grub_dprintf(),
> - strings[msg_off]: the beginning of log message, NUL terminated string.
Why strings in plural? Do you want to put multiple strings into
'strings'? What identifies the last string?
>
> Note: The producers are free to use/ignore any given set of level, facility and/or
> log type members. Though the usage of these members has to be clearly defined.
> Ignored integer members should be set to 0. Ignored log message type should
> contain an empty NUL terminated string. The log message is mandatory but can
> be an empty NUL terminated string.
>
> There is still not fully solved problem how the logs should be presented to the OS.
> On the UEFI platforms we can use config tables to do that. Then probably
> bf_log.next_bf_log_addr should not be used.
Why? How would you otherwise find the entries of the next produser in
the configuration table? What I am missing is a GUID for the
configuration table.
> On the ACPI and Device Tree platforms
> we can use these mechanisms to present the logs to the OSes. The situation gets more
I do not understand this.
UEFI implementations use either of ACPI and device-trees and support
configuration tables. Why do you want to use some other binding?
Best regards
Heinrich
> difficult if neither of these mechanisms are present. However, maybe we should not
> bother too much about that because probably these platforms getting less and less
> common.
>
> Anyway, I am aware that this is not specification per se. The goal of this email is
> to continue the discussion about the idea of the firmware and booloader log and to
> find out where the final specification should land. Of course taking into the account
> assumptions made above.
>
> You can find previous discussions about related topics at [1], [2] and [3].
>
> Additionally, I am going to present this during GRUB mini-summit session on Tuesday,
> 17th of November at 15:45 UTC. So, if you want to discuss the log design please join
> us. You can find more details here [4].
>
> Daniel
>
> [1] https://lists.gnu.org/archive/html/grub-devel/2019-10/msg00107.html
> [2] https://lists.gnu.org/archive/html/grub-devel/2019-11/msg00079.html
> [3] https://lists.gnu.org/archive/html/grub-devel/2020-05/msg00223.html
> [4] https://twitter.com/3mdeb_com/status/1327278804100931587
>
Standardizing in-memory logging sounds like an interesting idea,
especially with regards to components that can run on top of different
firmware stacks (things like GRUB or TF-A). But I would be a bit wary
of creating a "new standard to rule them all" and then expecting all
projects to switch what they have over to that. I think we all know
https://xkcd.com/927/.
Have you looked around and evaluated existing solutions that already
have some proliferation first? I think it would be much easier to
convince people to standardize on something that already has existing
users and drivers available in multiple projects.
In coreboot we're using a very simple character ring buffer that only
has two 4-byte header fields: total size and cursor (i.e. current
position where you would write the next character). The top 4 bits of
the cursor field are reserved for flags, one of which is the
"overflow" flag that tells you whether the ring-buffer already
overflowed or not (so readers know whether to print the whole ring
buffer, or only from the start to the current cursor). We try to
dimension the buffers so they don't overflow on a single boot, but
this approach allows us to log multiple boots on platforms that can
persist memory across reboots, which sometimes comes in handy.
The disadvantages of that approach compared to your proposal are lack
of some features, like the facilities field (although one can still
just print a tag like "<0>" or "<4>" behind each newline) or
timestamps (coreboot instead has separate timestamp logging). But I
think a really big advantage is size: in early firmware environments
before DDR training, space is often very precious and we struggle to
find more than a couple of kilobytes for the log buffer. If I look at
the structure you proposed, that's already 24 bytes of overhead per
individual message. If we were hooking that up to our normal printk()
facility in coreboot (such that each invocation creates a new message
header), that would probably waste about a third of the whole log
buffer on overhead. I think a complicated, syslog-style logging
structure that stores individual message blocks instead of a
continuous character string isn't really suitable for firmware
logging.
FWIW the coreboot console has existing support in Linux
(https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/firmware/google/memconsole-coreboot.c),
SeaBIOS (https://github.com/coreboot/seabios/blob/master/src/fw/coreboot.c#L219),
TF-A (https://github.com/ARM-software/arm-trusted-firmware/blob/master/drivers/coreboot/cbmem_console/aarch64/cbmem_console.S),
GRUB (https://git.savannah.gnu.org/cgit/grub.git/tree/grub-core/term/i386/coreboot/cbmemc.c),
U-Boot (https://github.com/u-boot/u-boot/blob/master/drivers/misc/cbmem_console.c)
and probably a couple of others I'm not aware of. And the code to add
support (especially when only appending) is so simple that it just
takes a couple of lines to implement (binary code size to implement
the format is also always a concern for firmware environments).
On Wed, Nov 18, 2020 at 7:04 AM Heinrich Schuchardt <[email protected]> wrote:
>
> On 14.11.20 00:52, Daniel Kiper wrote:
> > Hey,
> >
> > This is next attempt to create firmware and bootloader log specification.
> > Due to high interest among industry it is an extension to the initial
> > bootloader log only specification. It takes into the account most of the
> > comments which I got up until now.
> >
> > The goal is to pass all logs produced by various boot components to the
> > running OS. The OS kernel should expose these logs to the user space
> > and/or process them internally if needed. The content of these logs
> > should be human readable. However, they should also contain the
> > information which allows admins to do e.g. boot time analysis.
> >
> > The log specification should be as much as possible platform agnostic
> > and self contained. The final version of this spec should be merged into
> > existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
> > spec, e.g. as a part of OASIS Standards. The former seems better but is
> > not perfect too...
> >
> > Here is the description (pseudocode) of the structures which will be
> > used to store the log data.
>
> Hello Daniel,
>
> thanks for your suggestion which makes good sense to me.
>
> Why can't we simply use the message format defined in "The Syslog
> Protocol", https://tools.ietf.org/html/rfc5424?
>
> >
> > struct bf_log
> > {
> > uint32_t version;
> > char producer[64];
> > uint64_t flags;
> > uint64_t next_bf_log_addr;
> > uint32_t next_msg_off;
> > bf_log_msg msgs[];
>
> As bf_log_msg is does not have defined length msgs[] cannot be an array.
>
> > }
> >
> > struct bf_log_msg
> > {
> > uint32_t size;
> > uint64_t ts_nsec;
> > uint32_t level;
> > uint32_t facility;
> > uint32_t msg_off;
> > char strings[];
> > }
> >
> > The members of struct bf_log:
> > - version: the firmware and bootloader log format version number, 1 for now,
> > - producer: the producer/firmware/bootloader/... type; the length
> > allows ASCII UUID storage if somebody needs that functionality,
> > - flags: it can be used to store information about log state, e.g.
> > it was truncated or not (does it make sense to have an information
> > about the number of lost messages?),
> > - next_bf_log_addr: address of next bf_log struct; none if zero (I think
> > newer spec versions should not change anything in first 5 bf_log members;
> > this way older log parsers will be able to traverse/copy all logs regardless
> > of version used in one log or another),
> > - next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
> > of the next byte after the last log message in the msgs[]; i.e. the offset
> > of the next available log message slot; it is equal to the total size of
> > the log buffer including the bf_log struct,
>
> Why would you need an offset to first unused byte?
>
> We possibly have multiple producers of messages:
>
> - TF-A
> - U-Boot
> - iPXE
> - GRUB
>
> What we need is the offset to the next struct bf_log.
>
> > - msgs: the array of log messages,
> > - should we add CRC or hash or signatures here?
> >
> > The members of struct bf_log_msg:
> > - size: total size of bf_log_msg struct,
> > - ts_nsec: timestamp expressed in nanoseconds starting from 0,
>
> Would each message producer start from 0?
>
> Shouldn't we use the time from the hardware RTC if it is available via
> boot service GetTime()?
>
> > - level: similar to syslog meaning; can be used to differentiate normal messages
> > from debug messages; the exact interpretation depends on the current producer
> > type specified in the bf_log.producer,
> > - facility: similar to syslog meaning; can be used to differentiate the sources of
> > the messages, e.g. message produced by networking module; the exact interpretation
> > depends on the current producer type specified in the bf_log.producer,
> > - msg_off: the log message offset in strings[],
>
> What is this field good for? Why don't you start the the string at
> strings[0]?
> What would be useful would be the offset to the next bf_log_msg.
>
> > - strings[0]: the beginning of log message type, similar to the facility member but
> > NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
> > for messages printed using grub_dprintf(),
> > - strings[msg_off]: the beginning of log message, NUL terminated string.
>
>
> Why strings in plural? Do you want to put multiple strings into
> 'strings'? What identifies the last string?
>
>
> >
> > Note: The producers are free to use/ignore any given set of level, facility and/or
> > log type members. Though the usage of these members has to be clearly defined.
> > Ignored integer members should be set to 0. Ignored log message type should
> > contain an empty NUL terminated string. The log message is mandatory but can
> > be an empty NUL terminated string.
> >
> > There is still not fully solved problem how the logs should be presented to the OS.
> > On the UEFI platforms we can use config tables to do that. Then probably
> > bf_log.next_bf_log_addr should not be used.
>
> Why? How would you otherwise find the entries of the next produser in
> the configuration table? What I am missing is a GUID for the
> configuration table.
>
> > On the ACPI and Device Tree platforms
> > we can use these mechanisms to present the logs to the OSes. The situation gets more
>
> I do not understand this.
>
> UEFI implementations use either of ACPI and device-trees and support
> configuration tables. Why do you want to use some other binding?
>
> Best regards
>
> Heinrich
>
> > difficult if neither of these mechanisms are present. However, maybe we should not
> > bother too much about that because probably these platforms getting less and less
> > common.
> >
> > Anyway, I am aware that this is not specification per se. The goal of this email is
> > to continue the discussion about the idea of the firmware and booloader log and to
> > find out where the final specification should land. Of course taking into the account
> > assumptions made above.
> >
> > You can find previous discussions about related topics at [1], [2] and [3].
> >
> > Additionally, I am going to present this during GRUB mini-summit session on Tuesday,
> > 17th of November at 15:45 UTC. So, if you want to discuss the log design please join
> > us. You can find more details here [4].
> >
> > Daniel
> >
> > [1] https://lists.gnu.org/archive/html/grub-devel/2019-10/msg00107.html
> > [2] https://lists.gnu.org/archive/html/grub-devel/2019-11/msg00079.html
> > [3] https://lists.gnu.org/archive/html/grub-devel/2020-05/msg00223.html
> > [4] https://twitter.com/3mdeb_com/status/1327278804100931587
> >
>
On Sat, Nov 14, 2020 at 2:01 AM Daniel Kiper <[email protected]> wrote:
...
> The log specification should be as much as possible platform agnostic
> and self contained. The final version of this spec should be merged into
> existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
> spec, e.g. as a part of OASIS Standards. The former seems better but is
> not perfect too...
With all respect... https://xkcd.com/927/
--
With Best Regards,
Andy Shevchenko
Hello Julius,
I agree with you. Using an existing standard is better than inventing a new one in this case. I think using the coreboot logging is a good idea as there is indeed a lot of support already available and it is lightweight and simple.
Best Regards,
Wim Vervoorn
Eltan B.V.
Ambachtstraat 23
5481 SM Schijndel
The Netherlands
T : +31-(0)73-594 46 64
E : [email protected]
W : http://www.eltan.com
"This message contains confidential information. Unless you are the intended recipient of this message, any use of this message is strictly prohibited. If you have received this message in error, please immediately notify the sender by telephone +31-(0)73-5944664 or reply email, and immediately delete this message and all copies."
-----Original Message-----
From: Grub-devel [mailto:[email protected]] On Behalf Of Julius Werner
Sent: Thursday, December 3, 2020 2:18 AM
To: Daniel Kiper <[email protected]>
Cc: Coreboot <[email protected]>; The development of GRUB 2 <[email protected]>; LKML <[email protected]>; [email protected]; [email protected]; U-Boot Mailing List <[email protected]>; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; [email protected]; Vladimir 'phcoder' Serbinenko <[email protected]>; [email protected]; [email protected]; Paul Menzel <[email protected]>; [email protected]; [email protected]; [email protected]; Heinrich Schuchardt <[email protected]>
Subject: Re: [SPECIFICATION RFC] The firmware and bootloader log specification
Standardizing in-memory logging sounds like an interesting idea, especially with regards to components that can run on top of different firmware stacks (things like GRUB or TF-A). But I would be a bit wary of creating a "new standard to rule them all" and then expecting all projects to switch what they have over to that. I think we all know https://xkcd.com/927/.
Have you looked around and evaluated existing solutions that already have some proliferation first? I think it would be much easier to convince people to standardize on something that already has existing users and drivers available in multiple projects.
In coreboot we're using a very simple character ring buffer that only has two 4-byte header fields: total size and cursor (i.e. current position where you would write the next character). The top 4 bits of the cursor field are reserved for flags, one of which is the "overflow" flag that tells you whether the ring-buffer already overflowed or not (so readers know whether to print the whole ring buffer, or only from the start to the current cursor). We try to dimension the buffers so they don't overflow on a single boot, but this approach allows us to log multiple boots on platforms that can persist memory across reboots, which sometimes comes in handy.
The disadvantages of that approach compared to your proposal are lack of some features, like the facilities field (although one can still just print a tag like "<0>" or "<4>" behind each newline) or timestamps (coreboot instead has separate timestamp logging). But I think a really big advantage is size: in early firmware environments before DDR training, space is often very precious and we struggle to find more than a couple of kilobytes for the log buffer. If I look at the structure you proposed, that's already 24 bytes of overhead per individual message. If we were hooking that up to our normal printk() facility in coreboot (such that each invocation creates a new message header), that would probably waste about a third of the whole log buffer on overhead. I think a complicated, syslog-style logging structure that stores individual message blocks instead of a continuous character string isn't really suitable for firmware logging.
FWIW the coreboot console has existing support in Linux (https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/firmware/google/memconsole-coreboot.c),
SeaBIOS (https://github.com/coreboot/seabios/blob/master/src/fw/coreboot.c#L219),
TF-A (https://github.com/ARM-software/arm-trusted-firmware/blob/master/drivers/coreboot/cbmem_console/aarch64/cbmem_console.S),
GRUB (https://git.savannah.gnu.org/cgit/grub.git/tree/grub-core/term/i386/coreboot/cbmemc.c),
U-Boot (https://github.com/u-boot/u-boot/blob/master/drivers/misc/cbmem_console.c)
and probably a couple of others I'm not aware of. And the code to add support (especially when only appending) is so simple that it just takes a couple of lines to implement (binary code size to implement the format is also always a concern for firmware environments).
On Wed, Nov 18, 2020 at 7:04 AM Heinrich Schuchardt <[email protected]> wrote:
>
> On 14.11.20 00:52, Daniel Kiper wrote:
> > Hey,
> >
> > This is next attempt to create firmware and bootloader log specification.
> > Due to high interest among industry it is an extension to the
> > initial bootloader log only specification. It takes into the account
> > most of the comments which I got up until now.
> >
> > The goal is to pass all logs produced by various boot components to
> > the running OS. The OS kernel should expose these logs to the user
> > space and/or process them internally if needed. The content of these
> > logs should be human readable. However, they should also contain the
> > information which allows admins to do e.g. boot time analysis.
> >
> > The log specification should be as much as possible platform
> > agnostic and self contained. The final version of this spec should
> > be merged into existing specifications, e.g. UEFI, ACPI, Multiboot2,
> > or be a standalone spec, e.g. as a part of OASIS Standards. The
> > former seems better but is not perfect too...
> >
> > Here is the description (pseudocode) of the structures which will be
> > used to store the log data.
>
> Hello Daniel,
>
> thanks for your suggestion which makes good sense to me.
>
> Why can't we simply use the message format defined in "The Syslog
> Protocol", https://tools.ietf.org/html/rfc5424?
>
> >
> > struct bf_log
> > {
> > uint32_t version;
> > char producer[64];
> > uint64_t flags;
> > uint64_t next_bf_log_addr;
> > uint32_t next_msg_off;
> > bf_log_msg msgs[];
>
> As bf_log_msg is does not have defined length msgs[] cannot be an array.
>
> > }
> >
> > struct bf_log_msg
> > {
> > uint32_t size;
> > uint64_t ts_nsec;
> > uint32_t level;
> > uint32_t facility;
> > uint32_t msg_off;
> > char strings[];
> > }
> >
> > The members of struct bf_log:
> > - version: the firmware and bootloader log format version number, 1 for now,
> > - producer: the producer/firmware/bootloader/... type; the length
> > allows ASCII UUID storage if somebody needs that functionality,
> > - flags: it can be used to store information about log state, e.g.
> > it was truncated or not (does it make sense to have an information
> > about the number of lost messages?),
> > - next_bf_log_addr: address of next bf_log struct; none if zero (I think
> > newer spec versions should not change anything in first 5 bf_log members;
> > this way older log parsers will be able to traverse/copy all logs regardless
> > of version used in one log or another),
> > - next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
> > of the next byte after the last log message in the msgs[]; i.e. the offset
> > of the next available log message slot; it is equal to the total size of
> > the log buffer including the bf_log struct,
>
> Why would you need an offset to first unused byte?
>
> We possibly have multiple producers of messages:
>
> - TF-A
> - U-Boot
> - iPXE
> - GRUB
>
> What we need is the offset to the next struct bf_log.
>
> > - msgs: the array of log messages,
> > - should we add CRC or hash or signatures here?
> >
> > The members of struct bf_log_msg:
> > - size: total size of bf_log_msg struct,
> > - ts_nsec: timestamp expressed in nanoseconds starting from 0,
>
> Would each message producer start from 0?
>
> Shouldn't we use the time from the hardware RTC if it is available via
> boot service GetTime()?
>
> > - level: similar to syslog meaning; can be used to differentiate normal messages
> > from debug messages; the exact interpretation depends on the current producer
> > type specified in the bf_log.producer,
> > - facility: similar to syslog meaning; can be used to differentiate the sources of
> > the messages, e.g. message produced by networking module; the exact interpretation
> > depends on the current producer type specified in the bf_log.producer,
> > - msg_off: the log message offset in strings[],
>
> What is this field good for? Why don't you start the the string at
> strings[0]?
> What would be useful would be the offset to the next bf_log_msg.
>
> > - strings[0]: the beginning of log message type, similar to the facility member but
> > NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
> > for messages printed using grub_dprintf(),
> > - strings[msg_off]: the beginning of log message, NUL terminated string.
>
>
> Why strings in plural? Do you want to put multiple strings into
> 'strings'? What identifies the last string?
>
>
> >
> > Note: The producers are free to use/ignore any given set of level, facility and/or
> > log type members. Though the usage of these members has to be clearly defined.
> > Ignored integer members should be set to 0. Ignored log message type should
> > contain an empty NUL terminated string. The log message is mandatory but can
> > be an empty NUL terminated string.
> >
> > There is still not fully solved problem how the logs should be presented to the OS.
> > On the UEFI platforms we can use config tables to do that. Then
> > probably bf_log.next_bf_log_addr should not be used.
>
> Why? How would you otherwise find the entries of the next produser in
> the configuration table? What I am missing is a GUID for the
> configuration table.
>
> > On the ACPI and Device Tree platforms we can use these mechanisms to
> > present the logs to the OSes. The situation gets more
>
> I do not understand this.
>
> UEFI implementations use either of ACPI and device-trees and support
> configuration tables. Why do you want to use some other binding?
>
> Best regards
>
> Heinrich
>
> > difficult if neither of these mechanisms are present. However, maybe
> > we should not bother too much about that because probably these
> > platforms getting less and less common.
> >
> > Anyway, I am aware that this is not specification per se. The goal
> > of this email is to continue the discussion about the idea of the
> > firmware and booloader log and to find out where the final
> > specification should land. Of course taking into the account assumptions made above.
> >
> > You can find previous discussions about related topics at [1], [2] and [3].
> >
> > Additionally, I am going to present this during GRUB mini-summit
> > session on Tuesday, 17th of November at 15:45 UTC. So, if you want
> > to discuss the log design please join us. You can find more details here [4].
> >
> > Daniel
> >
> > [1]
> > https://lists.gnu.org/archive/html/grub-devel/2019-10/msg00107.html
> > [2]
> > https://lists.gnu.org/archive/html/grub-devel/2019-11/msg00079.html
> > [3]
> > https://lists.gnu.org/archive/html/grub-devel/2020-05/msg00223.html
> > [4] https://twitter.com/3mdeb_com/status/1327278804100931587
> >
>
_______________________________________________
Grub-devel mailing list
[email protected]
https://lists.gnu.org/mailman/listinfo/grub-devel
Dear Wim, dear Daniel,
First, thank you for including all parties in the discussion.
Am 04.12.20 um 13:52 schrieb Wim Vervoorn:
> I agree with you. Using an existing standard is better than inventing
> a new one in this case. I think using the coreboot logging is a good
> idea as there is indeed a lot of support already available and it is
> lightweight and simple.
In my opinion coreboot’s format is lacking, that it does not record the
timestamp, and the log level is not stored as metadata, but (in
coreboot) only used to decide if to print the message or not.
I agree with you, that an existing standard should be used, and in my
opinion it’s Linux message format. That is most widely supported, and
existing tools could then also work with pre-Linux messages.
Sean Hudson from Mentor Graphics presented that idea at Embedded Linux
Conference Europe 2016 [1]. No idea, if anything came out of that
effort. (Unfortunately, I couldn’t find an email. Does somebody have
contacts at Mentor to find out, how to reach him?)
Kind regards,
Paul
[1]:
http://events17.linuxfoundation.org/sites/events/files/slides/2016-10-12%20-%20ELCE%20-%20Shared%20Logging%20-%20Part%20Deux.pdf
On Fri, Dec 04, 2020 at 02:23:23PM +0100, Paul Menzel wrote:
> Dear Wim, dear Daniel,
>
>
> First, thank you for including all parties in the discussion.
> Am 04.12.20 um 13:52 schrieb Wim Vervoorn:
>
> > I agree with you. Using an existing standard is better than inventing
> > a new one in this case. I think using the coreboot logging is a good
> > idea as there is indeed a lot of support already available and it is
> > lightweight and simple.
> In my opinion coreboot’s format is lacking, that it does not record the
> timestamp, and the log level is not stored as metadata, but (in coreboot)
> only used to decide if to print the message or not.
>
> I agree with you, that an existing standard should be used, and in my
> opinion it’s Linux message format. That is most widely supported, and
> existing tools could then also work with pre-Linux messages.
>
> Sean Hudson from Mentor Graphics presented that idea at Embedded Linux
> Conference Europe 2016 [1]. No idea, if anything came out of that effort.
> (Unfortunately, I couldn’t find an email. Does somebody have contacts at
> Mentor to find out, how to reach him?)
I believe the main thing that came out of this was the reminder that
there was an even older attempt by U-Boot to have such a mechanism, and
that at the time getting the work accepted in Linux faced some hurdles
or another.
That said, I too agree with taking what's already a de facto standard,
the coreboot logging, and expand on it as needed.
--
Tom
On 12/4/20 7:23 AM, Paul Menzel wrote:
> Dear Wim, dear Daniel,
>
>
> First, thank you for including all parties in the discussion.
> Am 04.12.20 um 13:52 schrieb Wim Vervoorn:
>
>> I agree with you. Using an existing standard is better than inventing
>> a new one in this case. I think using the coreboot logging is a good
>> idea as there is indeed a lot of support already available and it is
>> lightweight and simple.
> In my opinion coreboot’s format is lacking, that it does not record the timestamp, and the log level is not stored as metadata, but (in coreboot) only used to decide if to print the message or not.
>
> I agree with you, that an existing standard should be used, and in my opinion it’s Linux message format. That is most widely supported, and existing tools could then also work with pre-Linux messages.
>
> Sean Hudson from Mentor Graphics presented that idea at Embedded Linux Conference Europe 2016 [1]. No idea, if anything came out of that effort. (Unfortunately, I couldn’t find an email. Does somebody have contacts at Mentor to find out, how to reach him?)
I forwarded this to Sean.
-Frank
>
>
> Kind regards,
>
> Paul
>
>
> [1]: http://events17.linuxfoundation.org/sites/events/files/slides/2016-10-12%20-%20ELCE%20-%20Shared%20Logging%20-%20Part%20Deux.pdf
Hi Daniel,
On Fri, 13 Nov 2020 at 19:07, Daniel Kiper <[email protected]> wrote:
>
> Hey,
>
> This is next attempt to create firmware and bootloader log specification.
> Due to high interest among industry it is an extension to the initial
> bootloader log only specification. It takes into the account most of the
> comments which I got up until now.
>
> The goal is to pass all logs produced by various boot components to the
> running OS. The OS kernel should expose these logs to the user space
> and/or process them internally if needed. The content of these logs
> should be human readable. However, they should also contain the
> information which allows admins to do e.g. boot time analysis.
>
> The log specification should be as much as possible platform agnostic
> and self contained. The final version of this spec should be merged into
> existing specifications, e.g. UEFI, ACPI, Multiboot2, or be a standalone
> spec, e.g. as a part of OASIS Standards. The former seems better but is
> not perfect too...
>
> Here is the description (pseudocode) of the structures which will be
> used to store the log data.
>
> struct bf_log
> {
> uint32_t version;
> char producer[64];
> uint64_t flags;
> uint64_t next_bf_log_addr;
> uint32_t next_msg_off;
> bf_log_msg msgs[];
> }
>
> struct bf_log_msg
> {
> uint32_t size;
> uint64_t ts_nsec;
> uint32_t level;
> uint32_t facility;
> uint32_t msg_off;
> char strings[];
> }
>
> The members of struct bf_log:
> - version: the firmware and bootloader log format version number, 1 for now,
> - producer: the producer/firmware/bootloader/... type; the length
> allows ASCII UUID storage if somebody needs that functionality,
> - flags: it can be used to store information about log state, e.g.
> it was truncated or not (does it make sense to have an information
> about the number of lost messages?),
> - next_bf_log_addr: address of next bf_log struct; none if zero (I think
> newer spec versions should not change anything in first 5 bf_log members;
> this way older log parsers will be able to traverse/copy all logs regardless
> of version used in one log or another),
> - next_msg_off: the offset, in bytes, from the beginning of the bf_log struct,
> of the next byte after the last log message in the msgs[]; i.e. the offset
> of the next available log message slot; it is equal to the total size of
> the log buffer including the bf_log struct,
> - msgs: the array of log messages,
> - should we add CRC or hash or signatures here?
>
> The members of struct bf_log_msg:
> - size: total size of bf_log_msg struct,
> - ts_nsec: timestamp expressed in nanoseconds starting from 0,
> - level: similar to syslog meaning; can be used to differentiate normal messages
> from debug messages; the exact interpretation depends on the current producer
> type specified in the bf_log.producer,
> - facility: similar to syslog meaning; can be used to differentiate the sources of
> the messages, e.g. message produced by networking module; the exact interpretation
> depends on the current producer type specified in the bf_log.producer,
> - msg_off: the log message offset in strings[],
> - strings[0]: the beginning of log message type, similar to the facility member but
> NUL terminated string instead of integer; this will be used by, e.g., the GRUB2
> for messages printed using grub_dprintf(),
> - strings[msg_off]: the beginning of log message, NUL terminated string.
>
> Note: The producers are free to use/ignore any given set of level, facility and/or
> log type members. Though the usage of these members has to be clearly defined.
> Ignored integer members should be set to 0. Ignored log message type should
> contain an empty NUL terminated string. The log message is mandatory but can
> be an empty NUL terminated string.
>
> There is still not fully solved problem how the logs should be presented to the OS.
> On the UEFI platforms we can use config tables to do that. Then probably
> bf_log.next_bf_log_addr should not be used. On the ACPI and Device Tree platforms
> we can use these mechanisms to present the logs to the OSes. The situation gets more
> difficult if neither of these mechanisms are present. However, maybe we should not
> bother too much about that because probably these platforms getting less and less
> common.
>
> Anyway, I am aware that this is not specification per se. The goal of this email is
> to continue the discussion about the idea of the firmware and booloader log and to
> find out where the final specification should land. Of course taking into the account
> assumptions made above.
>
> You can find previous discussions about related topics at [1], [2] and [3].
>
> Additionally, I am going to present this during GRUB mini-summit session on Tuesday,
> 17th of November at 15:45 UTC. So, if you want to discuss the log design please join
> us. You can find more details here [4].
I hesitate to add my opinions here since it is probably more important
to settle on something than get everyone happy.
It would be nice if the format were extensible in a simple way. As
others have mentioned, we may want to provide logs from various
different sources (EC, AP firmware through various
read-only/read-write paths, trusted firmware). Each of these is
presumably its own separate log, but with a coherent timestamp. I
think the log level and 'facility' (category) that you have are
important features, because they help to provide hierarchy and
attribution to the messages, allowing filtering out debugging, etc.
It could be more compact - e.g. a byte is enough for the level, use \0
instead of size, add a flags bytes to allow things to be optional. Is
ns necessary it would it be good enough and we could use 32-bit and
have an hour before wrapping.
Thinking about U-Boot TPL, where every byte counts, we would likely
store it in a different format and expand it later, but it would be
better if the format were efficient enough that it did not matter. A
flag byte indicating what fields are present? Overall, is it important
to have a simple struct for this, or is something more compact
possible?
IMO timestamp 0 should be the time the SoC comes out of reset, so far
as it can be known / estimated.
Also if we can repurpose something existing that is extensible, that
would be nice. I'm not arguing for legacy, just for retiring old
things.
Regards,
Simon
>
> Daniel
>
> [1] https://lists.gnu.org/archive/html/grub-devel/2019-10/msg00107.html
> [2] https://lists.gnu.org/archive/html/grub-devel/2019-11/msg00079.html
> [3] https://lists.gnu.org/archive/html/grub-devel/2020-05/msg00223.html
> [4] https://twitter.com/3mdeb_com/status/1327278804100931587