check-sof-logger: catch ERROR in firmware traces and fail

[marc-hb]

Add function find_logger_error() in case-lib so it can re-used by other
tests later.

Signed-off-by: Marc Herbert [email protected]

[marc-hb]

https://sof-ci.01.org/softestpr/PR799/build917/devicetest/?model=BDW_WSB_RT286&testcase=check-sof-logger has a very interesting:

 TIMESTAMP      (us)           DELTA  C# COMPONENT          LOCATION                      CONTENT	ktime=117.383s  @  2021-11-01 23:27:33 +0000 UTC
[  1852324251.812] (           0.000) c0 dma-trace             src/trace/dma-trace.c:422  INFO SHM: FW ABI 0x3014000 DBG ABI 0x5003000 tag v1.9-rc1-211-gb0bb21dc0ee6 src hash 0xa9c07289 (ldc hash 0xa9c07289)
[      324686.862] (      324686.875) c0 dma-trace             src/trace/dma-trace.c:605  ERROR dtrace_add_event(): number of dropped logs = 1

[marc-hb]

SOFCI TEST

[marc-hb]

https://sof-ci.01.org/softestpr/PR799/build917/devicetest/?model=BDW_WSB_RT286&testcase=check-sof-logger has a very interesting:

https://sof-ci.01.org/softestpr/PR799/build16/devicetest has something similar on BYT (BDW is not in PR testing anywmore)

[   178559514.207] (           0.000) c0 dma-trace             src/trace/dma-trace.c:347  INFO SHM: FW ABI 0x3016000 DBG ABI 0x5003000 tags SOF:v2.0-rc1-813-g5cfc37040bbe src hash 0xb72c3013 (ldc hash 0xb72c3013)
[       27442.082] (       27442.082) c0 dma-trace             src/trace/dma-trace.c:654  ERROR dtrace_add_event(): number of dropped logs = 8

[ujfalusi]

@marc-hb, is it a recent issue or it has been there?
It is very likely to happen if the firmware is generating 'enough' trace messages up to the point when sof-logger starts and opens the sof/trace debugfs file to start consuming the dtrace messages.

If you do not start the sof-logger at all then yeah, you are going to drop messages, but is this an error?

[marc-hb]

Thanks @ujfalusi for the prompt review!

Interesting. So this reproduced systematically on BYT and BDW... because the buffer is smaller / too small? Or maybe because they have more interfaces and more to log.

So I can just downgrade this ERROR to a WARN, right?

[ujfalusi]

@marc-hb, I think it is WARN rather an ERR, yes (if you refer to the fw print about the dropped new entries. It only takes to not start sof-logger to eventually have them, which is fine?

It can explain 'blackouts' in logs

[marc-hb]

https://sof-ci.01.org/softestpr/PR799/build112/devicetest is all green. I recommend we merge this "as is" and if this error message become too frequent we can downgrade it.

[marc-hb]

https://sof-ci.01.org/softestpr/PR799/build113/devicetest/ has one usual WHL UPX suspend/resume TIMEOUT, everything else is green.

[keqiaozhang]

LGTM

[marc-hb]

Thanks @keqiaozhang

[marc-hb]

Pattern matching fix submitted in

• lib.sh: fix recent check_error_in_file() . Exclude BSW #946