Catch firmware errors #1075

marc-hb · 2023-06-30T02:49:20Z

Final PR at last.

EDIT: "final" except for stable-v2.2; followup in:

hijack.sh: fail on stable-v2.2 FW errors too #1188

See commit messages.

For a (lot of) context see

Check for a valid trace for ALL tests #297

... and all the links from there.

cc:

marc-hb · 2023-07-01T00:40:41Z

There are a LOT of ERRORs in stable-v2.2 https://sof-ci.01.org/softestpr/PR1075/build537/devicetest/index.html , about half the tests have some.

They all seem to be this timeout:

    60561676.864329] (        1924.374878) c0 wait    src/lib/wait.c:53   ERROR poll timeout reg 488520 mask 63 val 0 us 937

Should it really be at the ERROR level?

In one sample context:

[    58851889.953103] (         114.739578) c0 ll-schedule        ./schedule/ll_schedule.c:186  INFO task 0xbe0a2280 pipe-task  avg 1763, max 1796
[    59389729.931731] (      537840.000000) c0 ll-schedule        ./schedule/ll_schedule.c:186  INFO task 0x9e08c858 agent-work  avg 114, max 119
[    60558956.656103] (     1169226.750000) c0 ipc                  src/ipc/ipc3/handler.c:1605 INFO ipc: new cmd 0x60050000
[    60558979.833186] (          23.177082) c0 pipe         9.50  ....../pipeline-stream.c:270  INFO pipe trigger cmd 0
[    60559752.489405] (         772.656189) c0 ssp-dai      1.2   /drivers/intel/ssp/ssp.c:1122 INFO ssp_trigger() cmd 0
[    60561676.864329] (        1924.374878) c0 wait                         src/lib/wait.c:53   ERROR poll timeout reg 488520 mask 63 val 0 us 937
[    60561693.478911] (          16.614582) c0 ssp-dai      1.2   /drivers/intel/ssp/ssp.c:61   WARN ssp_empty_tx_fifo() warning: timeout
[    60561711.655994] (          18.177082) c0 ssp-dai      1.2   /drivers/intel/ssp/ssp.c:1084 INFO ssp_stop(), TX stop
[    60561733.374743] (          21.718750) c0 dw-dma                 src/drivers/dw/dma.c:413  INFO dw_dma_stop(): dma 0 channel 0 stop
[    60561767.437242] (          34.062500) c0 ll-schedule        ./schedule/ll_schedule.c:159  INFO task complete 0xbe0a2200 pipe-task

marc-hb · 2023-07-01T00:46:07Z

cavs25 https://sof-ci.01.org/softestpr/PR1075/build536/devicetest/index.html and MTL https://sof-ci.ostc.intel.com/#/result/planresultdetail/28422 show both the same,
interesting ERROR pattern: the nocodec configurations have firmware <err> in practically every test. The configuration with codec have no ERROR message at all (except in very few, other, unrelated and known failures)

Most error messages seem be this timeout

[    0.037243] <inf> dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power en_ssp_power index 0
[    0.037381] <err> dai_intel_ssp: dai_ssp_poll_for_register_delay: dai_ssp_poll_for_register_delay poll timeout reg 465924 mask 256 val 0 us 125
[    0.037413] <wrn> dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power warning: timeout
[    0.037421] <inf> dai_intel_ssp: dai_ssp_pm_runtime_en_ssp_power: dai_ssp_pm_runtime_en_ssp_power I2SLCTL

marc-hb · 2023-07-06T00:30:16Z

New run, same results.

nocodec configurations have the same DAI timeouts in MTL https://sof-ci.01.org/softestpr/PR1075/build550/devicetest/index.html and cavs25 https://sof-ci.01.org/softestpr/PR1075/build548/devicetest/index.html
stable-v2.2 also seems to have the same poll timeouts as before in https://sof-ci.01.org/softestpr/PR1075/build549/devicetest/index.html, no change either.

marc-hb · 2023-09-08T22:14:45Z

test run on 2023-07-18

No change in stable-v2.2 https://sof-ci.01.org/softestpr/PR1075/build629/devicetest/index.html

cavs2.5 https://sof-ci.01.org/softestpr/PR1075/build630/devicetest/index.html

and in MTL https://sof-ci.01.org/softestpr/PR1075/build631/devicetest/index.html

Same errors all around.

September 19th, no change in:
ACE https://sof-ci.01.org/softestpr/PR1075/build754/devicetest/index.html
CAVS https://sof-ci.01.org/softestpr/PR1075/build753/devicetest/index.html
stable-v2.2 https://sof-ci.01.org/softestpr/PR1075/build752/devicetest/index.html

marc-hb · 2023-12-13T22:36:30Z

SOFCI TEST

marc-hb · 2024-04-09T22:38:49Z

cavs https://sof-ci.01.org/softestpr/PR1075/build129/devicetest/index.html has some new type of error:

[    0.598035] <inf> dai_intel_dmic_nhlt: dai_dmic_configure_coeff: fir_length_a = 101, fir_length_b = 247, packed = 0
[    0.598055] <inf> dai_intel_dmic_nhlt: dai_nhlt_dmic_dai_params_get: set 4ch pdm0 and pdm1
[    0.598065] <err> dai_intel_dmic_nhlt: dai_nhlt_get_clock_div: pdm = 0, FIR_CONFIG = 0x00010064
[    0.598078] <err> dai_intel_dmic_nhlt: dai_nhlt_get_clock_div: dai_index = 0, rate_div = 800, p_clkdiv = 16, p_mcic = 25, p_mfir = 2
[    0.598090] <inf> dai_intel_dmic_nhlt: dai_nhlt_update_rate: rate = 48000, channels = 4, format = 2
[    0.598100] <inf> dai_intel_dmic_nhlt: dai_nhlt_update_rate: io_clk 38400000, rate_div 800
[    0.598111] <inf> dai_intel_dmic_nhlt: dai_dmic_set_config_nhlt: dmic_set_config_nhlt(): enable0 3, enable1 3

cavs25 https://sof-ci.01.org/softestpr/PR1075/build753/devicetest/index.html is from the old build service and very old (sept 2023)

MTL https://sof-ci.01.org/softestpr/PR1075/build128/devicetest/index.html has plenty of FW errors but unfortunately no logs, dunno why.

stable-v2.2 has underruns https://sof-ci.01.org/softestpr/PR1075/build130/devicetest/index.html and suspend/resume failures, otherwise mostly OK.

marc-hb · 2024-04-09T22:38:57Z

SOFCI TEST

EDIT, now blocked by (among others):

dai_ssp_set_reg_config: SSPx configuration: Ignoring SSCR1:TSRE SSCR1:RSRE from blob sof#9026

marc-hb · 2024-04-10T20:21:14Z

cavs https://sof-ci.01.org/softestpr/PR1075/build269/devicetest/index.html has the "ignoring blob" errors in NOCODEC and not much else I could find.

Same thing with ACE https://sof-ci.01.org/softestpr/PR1075/build270/devicetest/index.html

stable-v2.2 https://sof-ci.01.org/softestpr/PR1075/build271/devicetest/index.html seems to have many underruns ~~and that's it~~

ujfalusi · 2024-04-11T06:50:11Z

@marc-hb, the underruns looks like to be coming from pause/resume tests only, right?

All logs contains that I can see via CI (2023-09-04 is the oldest)

marc-hb · 2024-04-11T07:05:02Z

I think you might be right. The rest in https://sof-ci.01.org/softestpr/PR1075/build269/devicetest/index.html seems to be ERROR dtrace_add_event() which could probably be lowered to a WARN and that's it?

In any case stable-v2.2 is obviously not the priority. I'd really like to enable this for Zephyr.

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining one, see thesofproject/sof-test#1075 (comment) Signed-off-by: Marc Herbert <marc.herbert@intel.com>

marc-hb · 2024-04-23T17:06:44Z

SOFCI TEST

EDIT: MTL https://sof-ci.01.org/softestpr/PR1075/build327/devicetest/index.html is 100% green!

CAVS https://sof-ci.01.org/softestpr/PR1075/build328/devicetest/index.html has only one device available but it's all green.

LNL https://sof-ci.01.org/softestpr/PR1075/build326/devicetest/index.html has one unrelated device PM runtime misconfiguration.

stable-v2.2 still has a lot of dtrace dropped logs errors https://sof-ci.01.org/softestpr/PR1075/build325/devicetest/index.html
thesofproject/sof#9036

Internal Intel issue 448. Signed-off-by: Marc Herbert <marc.herbert@intel.com>

At last. Signed-off-by: Marc Herbert <marc.herbert@intel.com>

fredoh9

Looks good, let's merge this now

marc-hb · 2024-04-24T00:08:49Z

MTL https://sof-ci.01.org/softestpr/PR1075/build331/devicetest/index.html 100% green.

stable-v2.2 100% (cause not catching errors yet) https://sof-ci.01.org/softestpr/PR1075/build332/devicetest/index.html

LNL has a couple of known issues already listed above
https://sof-ci.01.org/softestpr/PR1075/build329/devicetest/index.html

CAVS https://sof-ci.01.org/softestpr/PR1075/build330/devicetest/index.html had only one MODEL available but it's all green.

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining one, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace" and stop using the DMA trace when it's already saturated. Signed-off-by: Marc Herbert <marc.herbert@intel.com>

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see Signed-off-by: Marc Herbert <marc.herbert@intel.com>

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see thesofproject#9036 Signed-off-by: Marc Herbert <marc.herbert@intel.com>

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see #9036 Signed-off-by: Marc Herbert <marc.herbert@intel.com>

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see thesofproject#9036 Signed-off-by: Marc Herbert <marc.herbert@intel.com> (cherry picked from commit bb31696)

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see #9036 Signed-off-by: Marc Herbert <marc.herbert@intel.com> (cherry picked from commit bb31696)

Dropping logs is bad but it should not be fatal in itself. This ERROR is one of the last remaining errors in stable-v2.2, see thesofproject/sof-test#1075 (comment) Also switch to the "etrace": drop the dubious recursion and stop using the DMA trace when it's already saturated. Disclaimer: this was (successfully) tested only on stable-v2.2, see thesofproject#9036 Signed-off-by: Marc Herbert <marc.herbert@intel.com>

marc-hb mentioned this pull request Jun 30, 2023

Small log collection refactor to prepare catching fw errors #1076

Merged

marc-hb force-pushed the catch-fw-errors branch from 24d96e2 to 2f8bc05 Compare July 1, 2023 00:56

marc-hb changed the title ~~Catch firmware errors~~ [SKIP SOF-TEST] Catch firmware errors Jul 1, 2023

marc-hb force-pushed the catch-fw-errors branch from 2f8bc05 to 4a1e6da Compare July 1, 2023 00:59

marc-hb changed the title ~~[SKIP SOF-TEST] Catch firmware errors~~ Catch firmware errors Jul 1, 2023

marc-hb mentioned this pull request Jul 3, 2023

Check for a valid trace for ALL tests #297

Closed

This comment was marked as outdated.

Sign in to view

marc-hb mentioned this pull request Dec 13, 2023

dai_zephyr: Silence benign warnings thesofproject/sof#8621

Closed

marc-hb added the P1 Blocker bugs or important features label Dec 13, 2023

marc-hb mentioned this pull request Dec 13, 2023

boot test and virtual heap testing thesofproject/sof#7688

Merged

This was referenced Dec 14, 2023

debug_overlay.conf: temporarily disable SOF_BOOT_TEST thesofproject/sof#8624

Merged

[BUG] vmh_test_single test fails thesofproject/sof#8629

Open

marc-hb mentioned this pull request Jan 11, 2024

intel_adsp: dmic: Refactoring of blob parsing function zephyrproject-rtos/zephyr#60172

Merged

marc-hb mentioned this pull request Apr 9, 2024

dai_ssp_set_reg_config: SSPx configuration: Ignoring SSCR1:TSRE SSCR1:RSRE from blob thesofproject/sof#9026

Closed

marc-hb mentioned this pull request Apr 10, 2024

Catch firmware errors reported in logs #1173

Closed

marc-hb mentioned this pull request Apr 11, 2024

[STABLE-2.2] dma-trace.c: lower log level of dropped logs and stop the recursion thesofproject/sof#9036

Merged

lib.sh: warn about HTML bug hiding zephyr log levels

dc580c5

Internal Intel issue 448. Signed-off-by: Marc Herbert <marc.herbert@intel.com>

hijack.sh: fail when an error is found in Zephyr firmware logs

2825652

At last. Signed-off-by: Marc Herbert <marc.herbert@intel.com>

marc-hb force-pushed the catch-fw-errors branch from 4a1e6da to 2825652 Compare April 23, 2024 22:48

marc-hb marked this pull request as ready for review April 23, 2024 23:20

marc-hb requested a review from a team as a code owner April 23, 2024 23:20

fredoh9 approved these changes Apr 23, 2024

View reviewed changes

fredoh9 merged commit d10020d into thesofproject:main Apr 23, 2024
3 of 7 checks passed

marc-hb deleted the catch-fw-errors branch April 23, 2024 23:35

marc-hb mentioned this pull request Apr 25, 2024

dma-trace.c: lower log level of dropped logs and stop recursion thesofproject/sof#9083

Merged

marc-hb mentioned this pull request May 9, 2024

hijack.sh: fail on stable-v2.2 FW errors too #1188

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Catch firmware errors #1075

Catch firmware errors #1075

marc-hb commented Jun 30, 2023 •

edited

Loading

marc-hb commented Jul 1, 2023

marc-hb commented Jul 1, 2023 •

edited

Loading

marc-hb commented Jul 6, 2023 •

edited

Loading

This comment was marked as outdated.

marc-hb commented Sep 8, 2023 •

edited

Loading

This comment was marked as outdated.

marc-hb commented Dec 13, 2023

marc-hb commented Apr 9, 2024 •

edited

Loading

marc-hb commented Apr 9, 2024 •

edited

Loading

marc-hb commented Apr 10, 2024 •

edited

Loading

ujfalusi commented Apr 11, 2024 •

edited

Loading

marc-hb commented Apr 11, 2024

marc-hb commented Apr 23, 2024 •

edited

Loading

fredoh9 left a comment

marc-hb commented Apr 24, 2024 •

edited

Loading

Catch firmware errors #1075

Catch firmware errors #1075

Conversation

marc-hb commented Jun 30, 2023 • edited Loading

marc-hb commented Jul 1, 2023

marc-hb commented Jul 1, 2023 • edited Loading

marc-hb commented Jul 6, 2023 • edited Loading

This comment was marked as outdated.

marc-hb commented Sep 8, 2023 • edited Loading

This comment was marked as outdated.

marc-hb commented Dec 13, 2023

marc-hb commented Apr 9, 2024 • edited Loading

marc-hb commented Apr 9, 2024 • edited Loading

marc-hb commented Apr 10, 2024 • edited Loading

ujfalusi commented Apr 11, 2024 • edited Loading

marc-hb commented Apr 11, 2024

marc-hb commented Apr 23, 2024 • edited Loading

fredoh9 left a comment

Choose a reason for hiding this comment

marc-hb commented Apr 24, 2024 • edited Loading

marc-hb commented Jun 30, 2023 •

edited

Loading

marc-hb commented Jul 1, 2023 •

edited

Loading

marc-hb commented Jul 6, 2023 •

edited

Loading

marc-hb commented Sep 8, 2023 •

edited

Loading

marc-hb commented Apr 9, 2024 •

edited

Loading

marc-hb commented Apr 9, 2024 •

edited

Loading

marc-hb commented Apr 10, 2024 •

edited

Loading

ujfalusi commented Apr 11, 2024 •

edited

Loading

marc-hb commented Apr 23, 2024 •

edited

Loading

marc-hb commented Apr 24, 2024 •

edited

Loading