Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] WARN validate(), ll drift detected #3854

Closed
oleggtitoff opened this issue Feb 18, 2021 · 17 comments
Closed

[BUG] WARN validate(), ll drift detected #3854

oleggtitoff opened this issue Feb 18, 2021 · 17 comments
Labels
bug Something isn't working as expected

Comments

@oleggtitoff
Copy link

oleggtitoff commented Feb 18, 2021

Describe the bug
See the bunch of warnings after building SOF from master upstream:
[180448660.052083] ( 87622544.000000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41010 [182488660.000000] ( 2040000.000000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41007 [190708671.250000] ( 8220011.000000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41013 [196196674.010417] ( 5488003.000000) c0 sa src/lib/agent.c:79 WARN validate(), ll drift detected, delta = 41013

To Reproduce

  1. git clone https://github.com/thesofproject/sof.git
  2. Setup Xtensa environment.
  3. cd sof/
    rm -rf tmp
    mkdir tmp
    cd tmp
    cmake -DTOOLCHAIN=xt -DROOT_DIR=$CORE_PATH -DMEU_OPENSSL= '' -DRIMAGE_PRIVATE_KEY=/home/otitov/xcc/meu/otc_private_key_3k.pem ..
    make tgplp_defconfig
    cp ../src/arch/xtensa/configs/override/tigerlake_chrome.config override.config
    make overrideconfig
    make bin -j
    cd ..
    ./scripts/build-tools.sh -T
  4. Copy sof-tgl.ri, sof-tgl.ldc and topology to the device. Reboot the device.
  5. Connect to the device through ssh and run sof-logger. Play some music on the device. See drift warnings.

Reproduction Rate
Every time.

Expected behavior
Expected not to see these warnings.

Impact
Can impact on third party integration.

Environment

  1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
    • Kernel (v5.4): {e1b05a5f0f81e0b8e35129f45c335f7882f263d0}
    • SOF: {b0faccc}
  2. Name of the topology file
    • Topology: {sof-tgl-max98357a-rt5682.tplg}
  3. Name of the platform(s) on which the bug is observed.
    • Platform: {tigerlake_chrome}

Screenshots or console output

[131978267.239583] (      747.656250) c0 kd-test      12.61 ..../audio/detect_test.c:556  test_keyword_cmd()
[131978285.104167] (       17.864584) c0 kd-test      12.61 ..../audio/detect_test.c:470  test_keyword_cmd_set_data(), SOF_CTRL_CMD_BINARY
[131978302.916667] (       17.812500) c0 kd-test      12.61 ..../audio/detect_test.c:410  test_keyword_set_config(), blob size = 32
[131979656.614583] (     1353.697876) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 42177
[131979716.250000] (       59.635418) c0 pga          11.54 ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131979735.208333] (       18.958334) c0 pga          11.54 ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131980457.239583] (      722.031250) c0 pga          8.40  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131980473.854167] (       16.614584) c0 pga          8.40  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131981126.250000] (      652.395813) c0 pga          7.34  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131981143.125000] (       16.875000) c0 pga          7.34  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131981641.406250] (      498.281250) c0 pga          6.28  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131981658.593750] (       17.187500) c0 pga          6.28  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131982283.072917] (      624.479187) c0 pga          5.22  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131982299.322917] (       16.250000) c0 pga          5.22  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131982952.291667] (      652.968750) c0 pga          3.16  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131982968.854167] (       16.562500) c0 pga          3.16  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131983650.416667] (      681.562500) c0 pga          2.10  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131983667.031250] (       16.614584) c0 pga          2.10  ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131984290.781250] (      623.750000) c0 demux        1.2        src/audio/mux/mux.c:343  mux_cmd() cmd = 0x00000066
[131984308.385417] (       17.604166) c0 demux        1.2        src/audio/mux/mux.c:284  mux_ctrl_set_cmd(), cdata->cmd = 0x00000003
[131984325.989583] (       17.604166) c0 demux        1.2        src/audio/mux/mux.c:100  mux_set_values()
[131985087.187500] (      761.197937) c0 pga          1.1   ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 0, value = 65536
[131985103.802083] (       16.614584) c0 pga          1.1   ../audio/volume/volume.c:561  volume_ctrl_set_cmd(), channel = 1, value = 65536
[131985597.187500] (      493.385406) c0 ipc                       src/ipc/handler.c:606  ipc: pm -> restore
[131986372.083333] (      774.895813) c0 pipe         1.7       src/audio/pipeline.c:541  pipe params dir 0 frame_fmt 0 buffer_fmt 0 rate 48000
[131986390.208333] (       18.125000) c0 pipe         1.7       src/audio/pipeline.c:545  pipe params stream_tag 1 channels 2 sample_valid_bytes 2 sample_container_bytes 2
[131986497.916667] (      107.708336) c0 demux        1.2        src/audio/mux/mux.c:265  mux_params()
[131986564.687500] (       66.770836) c0 dai          1.6            src/audio/dai.c:351  dai_playback_params() dest_dev = 4 stream_id = 0 src_width = 2 dest_width = 2
[131986583.593750] (       18.906250) c0 dai          1.6            src/audio/dai.c:357  dai_playback_params() fifo 0x77210
[131986611.458333] (       27.864584) c0 pipe         1.7       src/audio/pipeline.c:668  pipe prepare
[131986672.864583] (       61.406250) c0 demux        1.2        src/audio/mux/mux.c:642  mux_prepare()
[131989236.354167] (     2563.489502) c0 pipe         1.7       src/audio/pipeline.c:863  pipe trigger cmd 1
[131989330.520833] (       94.166664) c0 demux        1.2        src/audio/mux/mux.c:698  mux_trigger(), command = 1
[131989351.093750] (       20.572916) c0 ssp-dai      1.1   /drivers/intel/ssp/ssp.c:843  ssp_trigger() cmd 1
[131989369.375000] (       18.281250) c0 ssp-dai      1.1   /drivers/intel/ssp/ssp.c:631  ssp_pre_start()
[131989426.979167] (       57.604168) c0 mn                 ./drivers/intel/ssp/mn.c:264  mclk_rate 19200000, mclk_source_clock 1
[131989445.468750] (       18.489584) c0 mn                 ./drivers/intel/ssp/mn.c:226  mclk_id 0 mdivr_val 2
[131989467.760417] (       22.291666) c0 mn                 ./drivers/intel/ssp/mn.c:328  find_mn for freq 38400000 bclk 1536000
[131989485.729167] (       17.968750) c0 mn                 ./drivers/intel/ssp/mn.c:633  bclk_rate 1536000, *out_scr_div 25, m 1, n 1
[131989503.385417] (       17.656250) c0 ssp-dai      1.1   /drivers/intel/ssp/ssp.c:687  ssp_set_config(), sscr0 = 0xc1c0187f
[131989522.812500] (       19.427084) c0 ssp-dai      1.1   /drivers/intel/ssp/ssp.c:760  ssp_start()
[131989645.520833] (      122.708336) c0 ll-schedule        ./schedule/ll_schedule.c:348  task add 0xbe090100 pipe-task <f11818eb-e92e-4082-82a3-dc54c604ebb3>
[131989662.604167] (       17.083334) c0 ll-schedule        ./schedule/ll_schedule.c:352  task params pri 0 flags 0 start 0 period 1000
[131989683.177083] (       20.572916) c0 ll-schedule        ./schedule/ll_schedule.c:252  num_tasks 3 total_num_tasks 3
[131991619.218750] (     1936.041626) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 42519
[170507717.031250] ( 38516096.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41003
[219535741.770833] ( 49028024.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41007
[230141701.718750] ( 10605960.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41023
[241587734.375000] ( 11446033.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41012
[252069733.854167] ( 10481999.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41025
[253667728.854167] (  1597995.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41013
[268751700.364583] ( 15083972.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41014
[283257740.364583] ( 14506040.000000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41024
[284153721.041667] (   895980.687500) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41020
[292335710.416667] (  8181989.500000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41013
[293047734.322917] (   712023.875000) c0 sa                          src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41005

sof_logger_log.txt
dmesg_log.txt

@oleggtitoff oleggtitoff added the bug Something isn't working as expected label Feb 18, 2021
@oleggtitoff oleggtitoff changed the title [BUG] [BUG] WARN validate(), ll drift detected Feb 18, 2021
@slawblauciak
Copy link
Collaborator

@oleggtitoff hi, can you please check the releases/tgl/v11.0-hotfix2 tag and test it? Thanks.

@oleggtitoff
Copy link
Author

Hi @slawblauciak, thanks for your advice.

Unfortunately, we are not able to build FW from this tag.
Got this error:

/sof/rimage/src/rimage.c:185: main: Assertion `image.adsp->write_firmware' failed.
Aborted (core dumped)
src/arch/xtensa/CMakeFiles/run_rimage.dir/build.make:74: recipe for target 'src/arch/xtensa/CMakeFiles/run_rimage' failed
make[3]: *** [src/arch/xtensa/CMakeFiles/run_rimage] Error 134
CMakeFiles/Makefile2:2484: recipe for target 'src/arch/xtensa/CMakeFiles/run_rimage.dir/all' failed
make[2]: *** [src/arch/xtensa/CMakeFiles/run_rimage.dir/all] Error 2
CMakeFiles/Makefile2:2101: recipe for target 'src/arch/xtensa/CMakeFiles/bin.dir/rule' failed
make[1]: *** [src/arch/xtensa/CMakeFiles/bin.dir/rule] Error 2
Makefile:662: recipe for target 'bin' failed
make: *** [bin] Error 2

We build it the same way as in the reproduction steps above, the only difference is to git checkout tags/releases/tgl/v11.0-hotfix2.
Do you have any ideas?

@keyonjie
Copy link
Contributor

looks the rimage version with the release branch is different, can you try 'git submodule update' in the sof/ folder before building.

@oleggtitoff
Copy link
Author

Hi @keyonjie, @slawblauciak, thanks for your comments.

Added submodule update command after checkout:

git checkout tags/releases/tgl/v11.0-hotfix2
git submodule update

But got the same error. Could you please suggest, what else can we try?

@lgirdwood
Copy link
Member

@oleggtitoff are you able to clone rimage repo and build ? Something may be out of sync, sub repo may need to be pulled as well.

@keyonjie
Copy link
Contributor

keyonjie commented Mar 1, 2021

@oleggtitoff yes, do something like 'rm rimage -rf' before the 'git submodule update'.

@oleggtitoff
Copy link
Author

Hi guys, thank you very much.
We managed to build firmware from releases/tgl/v11.0-hotfix2 tag. There are no warnings with this version.
But please tell us if you are planning to fix these warnings in the master too?

@keyonjie
Copy link
Contributor

keyonjie commented Mar 2, 2021

hi @oleggtitoff I think the master is already aligned with tgl/v11 after the #3768 was merged, can you try the latest master?

@oleggtitoff
Copy link
Author

Hi @keyonjie,
I tried the latest master and still can see the bunch of warnings.

@keyonjie
Copy link
Contributor

keyonjie commented Mar 4, 2021

Hi @oleggtitoff thanks for information, looks we need to define different warn_timeout for TGL platforms, the reason why you didn't see it with tgl-011 is that SA is disabled there.

@marc-hb
Copy link
Collaborator

marc-hb commented Mar 5, 2021

@keyonjie could this issue explain the very recent 25_02_TestGenericProcessorCompMultiCorePlb48000Hz32b32b4ch PR_CODEC_REGRESSION failure in https://sof-ci.01.org/sof-pr-viewer/#/build/PR3896/build6134676? (WHL/CNL)

Its dma_trace.log shows hundreds of WARN validate(), ll drift detected, delta = 25605

The more visible error is: SNR value is smaller than acceptable value (80.00) on channel 0: 16.12 , 16.43, 14.99, 13.15 on channels 1,2,3 and 4

@marc-hb
Copy link
Collaborator

marc-hb commented Mar 5, 2021

Same failure in https://sof-ci.01.org/sof-pr-viewer/#/build/PR3891/build6130418 but on TGL this time:

01:40:59.079        SNR value is smaller than acceptable value (80.00) on channel 0: 6.51
01:40:59.079       Wave verification failed on channel 1

01:40:59.126        SNR value is smaller than acceptable value (80.00) on channel 0: 6.33
01:40:59.126       Wave verification failed on channel 2

01:40:59.158        SNR value is smaller than acceptable value (80.00) on channel 0: 8.56
01:40:59.158       Wave verification failed on channel 3

01:40:59.220        SNR value is smaller than acceptable value (80.00) on channel 0: 6.98
01:40:59.220       Wave verification failed on channel 4

The dma_trace.log has "only" tens of

[  3612396.718750] (    11993.437500) c0 sa      src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 41007
[  3656401.041667] (    44004.324219) c0 sa      src/lib/agent.c:79   WARN validate(), ll drift detected, delta = 40990

@marc-hb
Copy link
Collaborator

marc-hb commented Mar 5, 2021

PR #2686 downgraded this error to a warning, because of "non-critical" drifts (~ "soft" real-time?). However I don't see anything about "critical" drifts in #2686

Should it be upgraded to an error again when the drift is too large or when there are too many in a row or both?

https://github.com/thesofproject/sof/issues?q=%22ll+detected+drift%2C+delta%22+
returns 28 issues which seems a lot, however github search syntax for whitespace unfortunately does not work; this other, disordered search returns the same issues: https://github.com/thesofproject/sof/issues?q=%22delta+detected+drift+ll%22

https://docs.github.com/en/github/searching-for-information-on-github/understanding-the-search-syntax#use-quotation-marks-for-queries-with-whitespace

@keyonjie
Copy link
Contributor

keyonjie commented Mar 8, 2021

Hi all, looks the drift comes from re-requesting HPRO during exiting from WFI, @oleggtitoff can you try if #3762 can fix the issue at your end?

@marc-hb I am not sure if the drift can lead to bad SNR or other errors, but at least it raise flag of abnormal issues happened, so at least a warning here is legit to me. BTW, PR #3762 should fix the drift issue so it worth to try with it for other quality issues IMO.

@mwasko
Copy link
Contributor

mwasko commented Mar 8, 2021

Hi all, looks the drift comes from re-requesting HPRO during exiting from WFI, @oleggtitoff can you try if #3762 can fix the issue at your end?

To avoid any regression the #3762 should be taken alongside with the #3865 (merged to master).

@lgirdwood
Copy link
Member

@keyonjie both merged now, can we close ?

@oleggtitoff
Copy link
Author

Hi everybody, the issue is fixed. Thank you very much!

marc-hb added a commit to marc-hb/sof-test that referenced this issue Apr 27, 2021
Probably the main change is fixing the huge etrace test gaps thesofproject#321 and
thesofproject/sof#3281

Also fixes DMA trace gaps thesofproject#297 and thesofproject#298

I initial tried to preserve some of the existing code but it was just
too bad. PR thesofproject#161 / commit 9136776 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in thesofproject#167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to marc-hb/sof-test that referenced this issue Apr 27, 2021
Probably the main change is fixing the huge etrace test gaps thesofproject#321 and
thesofproject/sof#3281

Also fixes DMA trace gaps thesofproject#297 and thesofproject#298

I initial tried to preserve some of the existing code but it was just
too bad. PR thesofproject#161 / commit 7274f49 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in thesofproject#167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to marc-hb/sof-test that referenced this issue Apr 27, 2021
Probably the main change is fixing the huge etrace test gaps thesofproject#321 and
thesofproject/sof#3281

Also fixes DMA trace gaps thesofproject#297 and thesofproject#298

I initial tried to preserve some of the existing code but it was just
too bad. PR thesofproject#161 / commit 7274f49 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in thesofproject#167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to marc-hb/sof-test that referenced this issue Apr 28, 2021
Probably the main change is fixing the huge etrace test gaps thesofproject#321 and
thesofproject/sof#3281

Also fixes DMA trace gaps thesofproject#297 and thesofproject#298

I initial tried to preserve some of the existing code but it was just
too bad. PR thesofproject#161 / commit 7274f49 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in thesofproject#167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to marc-hb/sof-test that referenced this issue Jun 9, 2021
Probably the main change is fixing the huge etrace test gaps thesofproject#321 and
thesofproject/sof#3281

Also fixes DMA trace gaps thesofproject#297 and thesofproject#298

I initial tried to preserve some of the existing code but it was just
too bad. PR thesofproject#161 / commit 7274f49 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in thesofproject#167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to thesofproject/sof-test that referenced this issue Jun 10, 2021
Probably the main change is fixing the huge etrace test gaps #321 and
thesofproject/sof#3281

Also fixes DMA trace gaps #297 and #298

I initial tried to preserve some of the existing code but it was just
too bad. PR #161 / commit 7274f49 seemed especially bad:

- It tried to ignore a specific `ll drift` error but instead it filtered
out almost every log statement out of... stderr, that does not have show
log statements!! (Just for the record this `ll drift` error has been
downgraded to warning now, see
thesofproject/sof#2686 and
thesofproject/sof#3854)

- That same commit also added code that merely starts the DMA trace with
"there is an error below" (without failing the test) but that's eclipsed
by the entire log that follows. Later, the firmware started printing
ERROR every single time when the ERROR FW ABI prefix was introduced yet
no one ever noticed which proves how useless this prefix is was.

So remove this DMA trace prefix as the purpose of this test is - as
clearly stated in #167 - not to find firmware errors but errors with the
sof-logger itself (even though we never had anything looking at firmware
errors so far)

Don't grep for "error" on stderr: anything on stderr is a logger
failure (not a firmware failure).

Don't require whitespace before the TIMESTAMP header.

Add set -e.

Use shell functions.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working as expected
Projects
None yet
Development

No branches or pull requests

6 participants