thesofproject / linux

Linux kernel source tree
Other
91 stars 133 forks source link

ALSA/ASoC: Intel: log probe details once #4977

Closed plbossart closed 6 months ago

plbossart commented 6 months ago

Reported by @marc-hb, we keep printing the same information multiple times, e.g. in https://intel-gfx-ci.01.org/tree/intel-xe/xe-1239-5a43da669cdb9b8df66e32a661b09cd9c52e35f2/shard-lnl-1/boot21.txt

Use dev_info_once() for all those logs.

marc-hb commented 6 months ago

Will there still be a way to monitor (and count!) the deferred probe iterations with a higher log level?

marc-hb commented 6 months ago

Will there still be a way to monitor (and count!) the deferred probe iterations with a higher log level?

I'm asking because interactions between audio work in progress and display work in progress have always been incredibly time-consuming - so I'd hate losing any information in debug logs.

Examples:

plbossart commented 6 months ago

Will there still be a way to monitor (and count!) the deferred probe iterations with a higher log level?

I don't think so. The deferred probe is pretty simple, every time there's a new driver probe the kernel walks through the list of deferred probes and sees if some dependencies have been resolved. This is completely non-repeatable, so the level may change from one run to the other.

marc-hb commented 6 months ago

The deferred probe is pretty simple, every time there's a new driver probe the kernel walks through the list of deferred probes and sees if some dependencies have been resolved.

Thanks!

This is completely non-repeatable,

I don't mind "non-repeatable" as long as we have some sort of record of what happened.

so the level may change from one run to the other.

Not sure what "level" you're referring to; I was referring to log levels (ERR, WARN, INFO, DEBUG,...)

Is there a way to increase the log level of the deferred probe "resolver" and would that answer my concerns? Considering it's non-deterministic / full of races by design, I really hope there is away to get good logs out of it...

PS: @lucasdemarchi just pointed me to e6d0c13e9f46

marc-hb commented 6 months ago

@fredoh9 the test results have been published but Github has not been notified by Jenkins...

https://sof-ci.01.org/linuxpr/PR4977/build2732/devicetest/index.html OK https://sof-ci.01.org/linuxpr/PR4977/build2733/devicetest/index.html OK

Not OK:

Screenshot 2024-05-06 at 15 11 39
plbossart commented 6 months ago

The deferred probe is pretty simple, every time there's a new driver probe the kernel walks through the list of deferred probes and sees if some dependencies have been resolved.

Thanks!

This is completely non-repeatable,

I don't mind "non-repeatable" as long as we have some sort of record of what happened.

I thought you wanted the number of times the deferred probe was attempted. That's not really useful.

so the level may change from one run to the other.

Not sure what "level" you're referring to; I was referring to log levels (ERR, WARN, INFO, DEBUG,...)

deferred probe is NEVER an error, so we're never going to change the logs depending on when we attempt the probe

marc-hb commented 6 months ago

I thought you wanted the number of times the deferred probe was attempted. That's not really useful.

I'm interesting in everything that happened when something goes wrong and we've had a lot of timeouts and somewhat complex interactions in the past.

so we're never going to change the logs depending on when we attempt the probe

I meant increasing the log levels of the "resolver" always. Test failures cannot be predicted. Should be a small volume compared to what we currently enable for SOF.

plbossart commented 6 months ago

@marc-hb we rely on the deferred probe for codec drivers and machine drivers already. I don't think we want to log everything that happens when the probe is deferred, it'd be way too verbose and bring limited information. There's a reason why dev_err_probe() was introduced.

plbossart commented 6 months ago

@ujfalusi you good with this?