On 2/14/2023 3:19 PM, Jakub Kicinski wrote:

On Tue, 14 Feb 2023 14:39:18 -0800 Jacob Keller wrote:

quoted

On 2/14/2023 8:14 AM, Paul M Stillwell Jr wrote:

quoted

quoted

I believe that's in line with devlink health. The devlink health log
is "formatted" but I really doubt that any user can get far in debugging
without vendor support.
 

I agree, I just don't see what the trigger is in our case for FW logging.
  

Here's the thoughts I had for devlink health:

1) support health reporters storing more than a single event. Currently
all health reporters respond to a single event and then do not allow
storing new captures until the current one is processed. This breaks for
our firmware logging because we get separate events from firmware for
each buffer of messages. We could make this configurable such that we
limit the total maximum to prevent kernel memory overrun. (and some
policy for how to discard events when the buffer is full?)

I think the idea is that the system keeps a continuous ring buffer of
logs and dumps it whenever bad events happens. That's in case of logs,
obviously you can expose other types of state with health.

Ok so in our case the firmware presumably has some internal storage for
messages and some set of masks for what messages it will "store" and
forward to us.

We can enable logging and enable the modules and logging levels. This
this enables firmware to log messages to its buffer, which is then
periodically flushed to us. The messages may be for "bad" events but may
not be. Sometimes its tracing information, or other details about how
the firmware. This is all encoded, and we (driver devs) are not given
the tools to decode it. My understanding is that this partly is from
fear of tying to specific driver versions.

We're supposed to dump this binary contents and give it to firmware devs
who can then decode it using the appropriate decoder for the given version.

The information is very helpful for debugging problems, but we can't
exactly translate it into usable information on our own. The mere
presence of some information (once logging is enabled) is *not*
sufficient to know if there was a problem. Basically every flow can be
enabled to log all kinds of detail.

Additionally, we get messages in blocks, and don't have any mechanism in
the driver to split these blocks into individual messages, or to tell
what log level or module the messages in a block are from.

quoted

2a) add some knobs to enable/disable a health reporter

For ad-hoc collection of the ring buffer there are dump and diagnose
callbacks which can be triggered at any time.

Sure. The point I was making is that we need some indication from user
space whether to enable or disable the logging.. because otherwise we'd
potentially just consume memory indefinitely, or we'd have limited space
to store messages and we'd overflow it.

The volume of logs can be very high depending on what modules or log
level is enabled. Thus storing all messages all the time is not really
viable.

One of our early prototypes for this feature hex-encoded the messages to
syslog but we pretty much always lost messages doing this because we'd
overflow the syslog buffer. That is what led us to use debugfs for
reading/writing the binary data. (Not to mention that since its binary
data only decodable by Intel there is no reason to spam the syslog
buffer...)

quoted

2b) add some firmware logging specific knobs as a "build on top of
health reporters" or by creating a separate firmware logging bit that
ties into a reporter. These knows would be how to set level, etc.

Right, the level setting is the part that I'm the least sure of.
That sounds like something more fitting to ethtool dumps.

I don't feel like this fits into ethtool at all as its not network
specific and tying it to a netdev feels weird.

quoted

3) for ice, once the health reporter is enabled we request the firmware
to send us logging, then we get our admin queue message and simply copy
this into the health reporter as a new event

4) user space is in charge of monitoring health reports and can decide
how to copy events out to disk and when to delete the health reports
from the kernel.

That's also out of what's expected with health reporters. User should
not have to run vendor tools with devlink health. Decoding of the dump
may require vendor tools but checking if system is healthy or something
crashed should happen without any user space involvement.

So this wasn't about using a specific "vendor" tool, but more that
devlink health can decide when to delete a given dump?

Ultimately we have to take the binary data and give it to a vendor
specific tool to decode (whether I like that or not...). The information
required to decode the messages is not something we have permission to
share and code into the driver.

quoted

Basically: extend health reporters to allow multiple captures and add a
related module to configure firmware logging via a health reporter,
where the "event" is just "I have a new blob to store".

How does this sound?

For the specifics of 2b) I think we can probably agree that levels is
fairly generic (i.e. the specifics of what each level are is vendor
specific but the fact that there are numbers and that higher or lower
numbers means more severe is fairly standard)

I know the ice firmware has many such modules we can enable or disable
and we would ideally be able to set which modules are active or not.
However all messages come through in the same blobs so we can't separate
them and report them to individual health reporter events. I think we
could have modules as a separate option for toggling which ones are on
or off. I would expect other vendors to have something similar or have
no modules at all and just an on/off switch?

I bet all vendors at this point have separate modules in the FW.
It's been the case for a while, that's why we have multiple versions
supported in devlink dev info.

So one key here is that module for us refers to various sub-components
of our main firmware, and does not tie into the devlink info modules at
all, nor would that even make sense to us.

Its more like sections i.e.

DCB,
MDIO,
NVM,
Scheduler,
Tx queue management,
SyncE,
LLDP,
Link Management,
...

I believe when a firmware dev adds a log message they choose an
appropriate section and log level for when it should be reported.

This makes me think the right approach is to add a new "devlink fwlog"
section entirely where we can define its semantics. It doesn't quite
line up with the current intention of health reporters.

We also considered some sort of extension to devlink regions, where each
new batch of messages from firmware would be a new snapshot.

Again this still requires some form of controls for whether to enable
logging, how many snapshots to store, how to discard old snapshots if we
run out of space, and what modules and log levels to enable.

Thanks,
Jake