check-kmod: set the kernel check point before starting a test #655

fredoh9 · 2021-04-22T20:39:12Z

In error case, no kernel check point causes TIMEOUT in SOF CI. The below
line will be last log without verdict, then ends with TIMEOUT.

[ERROR] Kernel check point "KERNEL_CHECKPOINT" is not properly set

Signed-off-by: Fred Oh fred.oh@linux.intel.com

In error case, no kernel check point causes TIMEOUT in SOF CI. The below line will be last log without verdict, then ends with TIMEOUT. [ERROR] Kernel check point "KERNEL_CHECKPOINT" is not properly set Signed-off-by: Fred Oh <fred.oh@linux.intel.com>

fredoh9 · 2021-04-22T20:41:01Z

I was able to test with TGLU_RVP_NOCODEC. With this PR, there is verdict at the end. Without this PR, last error was [ERROR] Kernel check point "KERNEL_CHECKPOINT" is not properly set

2021-04-22 20:18:47 UTC Sub-Test: [INFO] ===== Testing: (Round: 1/1) (PCM: smart-nocodec [hw:0,2]<playback>) (Loop: 1/1) =====
2021-04-22 20:18:47 UTC Sub-Test: [COMMAND] aplay   -Dhw:0,2 -r 48000 -c 2 -f S16_LE -d 3 /dev/zero -v -q
aplay: main:830: audio open error: Invalid argument
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/120/gvfs
      Output information may be incomplete.
2021-04-22 20:18:47 UTC Sub-Test: [ERROR] aplay on PCM hw:0,2 failed at 1/1.
2021-04-22 20:18:47 UTC Sub-Test: [ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2021-04-22 20:18:47 UTC Sub-Test: [ERROR]  die()  @  /home/ubuntu/sof-test/test-case/../case-lib/lib.sh
2021-04-22 20:18:47 UTC Sub-Test: [ERROR]  main()  @  /home/ubuntu/sof-test/test-case/check-playback.sh:99
2021-04-22 20:18:47 UTC Sub-Test: [INFO] Starting /usr/bin/sof-logger  -l /etc/sof/sof-tgl.ldc -o /home/ubuntu/sof-test/logs/check-kmod-load-unload-after-playback/2021-04-22-20:18:47-11971/etrace.txt
2021-04-22 20:18:48 UTC Sub-Test: [INFO] pkill -TERM sof-logger
Terminated
2021-04-22 20:18:49 UTC Sub-Test: [INFO] nlines=3 /home/ubuntu/sof-test/logs/check-kmod-load-unload-after-playback/2021-04-22-20:18:47-11971/etrace.txt
2021-04-22 20:18:49 UTC Sub-Test: [INFO] Test Result: FAIL!
2021-04-22 20:18:49 UTC [ERROR] aplay check failed
2021-04-22 20:18:49 UTC [ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2021-04-22 20:18:49 UTC [ERROR]  die()  @  /home/ubuntu/sof-test/test-case/../case-lib/lib.sh
2021-04-22 20:18:49 UTC [ERROR]  main()  @  /home/ubuntu/sof-test/test-case/check-kmod-load-unload-after-playback.sh:67
2021-04-22 20:18:49 UTC [INFO] Test Result: FAIL!

And TIMEOUT errors can be found in internal daily test 3430 with TGLU_RVP_NOCODEC also.

plbossart · 2021-04-22T21:11:18Z

test-case/check-kmod-load-unload-after-playback.sh


-func_opt_parse_option "$@"
+fxunc_opt_parse_option "$@"
+setup_kernel_check_point


@fredoh9 @marc-hb maybe a stupid question, but there was a similar change (EDIT: c76cb0b) from @aiChaoSONG for pm_runtime tests yesterday, so should we add this in ALL tests?

This is more or less what I asked in #639 (comment)

Some (future?) tests may want to scan the entire log since boot though. For instance we discussed one "empty" test only for the purpose of checking SOF modules loaded at boot time. It's still not clear what such a test should do wrt checkpoints, @aiChaoSONG

After excluding aliases and non-audio tests I found only 2 tests that don't invoke setup_kernel_check_point() directly:

+test-case/check-audio-equalizer.sh +test-case/check-volume-levels.sh

Would these two tests also timeout if they fail?

@plbossart @marc-hb Previously, when we were using DMESG_KERNEL_LAST_LINE which acted like kernel check point, this variable is implicitly set up in lib.sh. But I think it is better to set up check point explicitly in every test case, this will tell where the log collect is started.

In PR #653, I add an option to disable check point, with it, we are able to collect log from kernel boot

so should we add this in ALL tests

I have a round of clean up on this within the journalctl PR, only minor number of test case(s) which is not run in PR test or daily test may need this. And also, when this happens now, some boundary condition is triggered.

marc-hb · 2021-04-22T22:23:39Z

@fredoh9 , @aiChaoSONG can you say more about this TIMEOUT, why does it happen, where and how long it is?

Can we please change this checkpoint failure so it fails immediately? EDIT: done in separate #661

marc-hb · 2021-04-22T22:26:05Z

In https://sof-ci.01.org/softestpr/PR655/build666/devicetest and https://sof-ci.01.org/softestpr/PR655/build687/devicetest/ the modified test failed on all platforms with: check-kmod-load-unload-after-playback.sh: line 51: fxunc_opt_parse_option: command not found

It's very good that it failed, no green failure for a change.

It's not so good that it timed-out. ~~Why did the exit_handler not run?~~ (it ran). Can we just print some magic string at the end?

marc-hb · 2021-04-22T23:27:04Z

Some (future?) tests may want to scan the entire log since boot though. For instance we discussed one "empty" test only for the purpose of checking SOF modules loaded at boot time. It's still not clear what such a test should do wrt checkpoints, @aiChaoSONG

Already answered 3 days ago by @aiChaoSONG in #653, sorry I've been running behind with code reviews.

marc-hb · 2021-04-23T00:39:49Z

It's not so good that it timed-out. Why did the exit_handler not run? (it ran). Can we just print some magic string at the end?

All checkpoint timeouts fixed in new #661 "don't die in the die handler"

marc-hb · 2021-04-23T00:41:02Z

test-case/check-kmod-load-unload-after-playback.sh

 OPT_HAS_ARG['p']=0             OPT_VAL['p']=1

-func_opt_parse_option "$@"
+fxunc_opt_parse_option "$@"


While fixing this typo, can you also add set -e if testing is OK?

If set -e requires some other changes then forget it, does not really belong to this PR.

fredoh9 · 2021-04-26T23:05:42Z

#661 is merged

marc-hb · 2021-04-29T05:40:40Z

I'm confused @fredoh9 , @aiChaoSONG : don't we still want this?

aiChaoSONG · 2021-04-29T05:47:03Z

I'm confused @fredoh9 , @aiChaoSONG : don't we still want this?

I think we still need this, we don't die but only print error messages, without this, we may see the error messages printed out.

marc-hb · 2021-11-01T19:47:49Z

SOFCI TEST

EDIT: the fxunc_opt_parse_option typo still fails across all platforms.

marc-hb · 2022-06-16T22:38:44Z

New KERNEL_CHECKPOINT discussion in

check-suspend-resume: add new -u option to test without audio #918

fredoh9 requested a review from a team as a code owner April 22, 2021 20:39

fredoh9 requested review from aiChaoSONG and keqiaozhang April 22, 2021 20:41

plbossart reviewed Apr 22, 2021

View reviewed changes

marc-hb changed the title ~~sof-test: set the kernel check point before starting a test~~ check-kmod: set the kernel check point before starting a test Apr 23, 2021

marc-hb requested changes Apr 23, 2021

View reviewed changes

fredoh9 closed this Apr 26, 2021

marc-hb reopened this Apr 29, 2021

fredoh9 closed this Jun 3, 2022

check-kmod: set the kernel check point before starting a test #655

check-kmod: set the kernel check point before starting a test #655

Uh oh!

Conversation

fredoh9 commented Apr 22, 2021

Uh oh!

fredoh9 commented Apr 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

plbossart Apr 22, 2021 • edited by marc-hb Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marc-hb Apr 22, 2021

Choose a reason for hiding this comment

Uh oh!

aiChaoSONG Apr 23, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

aiChaoSONG Apr 23, 2021

Choose a reason for hiding this comment

Uh oh!

marc-hb commented Apr 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

marc-hb commented Apr 22, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

marc-hb commented Apr 22, 2021

Uh oh!

marc-hb commented Apr 23, 2021

Uh oh!

marc-hb Apr 23, 2021

Choose a reason for hiding this comment

Uh oh!

fredoh9 commented Apr 26, 2021

Uh oh!

marc-hb commented Apr 29, 2021

Uh oh!

aiChaoSONG commented Apr 29, 2021

Uh oh!

marc-hb commented Nov 1, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

marc-hb commented Jun 16, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

fredoh9 commented Apr 22, 2021 •

edited

Loading

plbossart Apr 22, 2021 •

edited by marc-hb

Loading

aiChaoSONG Apr 23, 2021 •

edited

Loading

marc-hb commented Apr 22, 2021 •

edited

Loading

marc-hb commented Apr 22, 2021 •

edited

Loading

marc-hb commented Nov 1, 2021 •

edited

Loading