Skip to content

multiple-pipeline: remove initial sleep and clarify second sleep #543

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.

Sign up for GitHub

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

Jump to bottom
Merged
marc-hb merged 1 commit into from
Apr 27, 2021
Merged

multiple-pipeline: remove initial sleep and clarify second sleep #543

marc-hb merged 1 commit into from
Apr 27, 2021

Conversation

@marc-hb
Copy link
Collaborator

@marc-hb marc-hb commented Dec 2, 2020

Having the same -w parameter for both this initial sleep and the test
duration made no sense: fixed by removing the first sleep.

It's not clear what the purpose of this first sleep was, it has been in
multiple-pipeline-capture/playback.sh since the dawn of time (= commit
39cd964) For sure this first sleep was helping hide
"uninterruptible state" bug #472 by giving the DSP more time to wake up!

Signed-off-by: Marc Herbert marc.herbert@intel.com

@marc-hb marc-hb marked this pull request as ready for review December 2, 2020 22:16
@marc-hb marc-hb requested a review from a team as a code owner December 2, 2020 22:16
@marc-hb
Copy link
Collaborator Author

marc-hb commented Dec 2, 2020 •
edited
Loading

https://sof-ci.01.org/softestpr/PR543/build480/devicetest is all green.

This PR should save about 20 minutes in nightly testing.

It's ready for review but let's not merge it until we have confirmation that #472 is confirmed fixed and closed.

UPDATE: #472 is closed, this is ready.

@marc-hb marc-hb mentioned this pull request Dec 2, 2020
Merged
@marc-hb
Copy link
Collaborator Author

marc-hb commented Dec 4, 2020

No new shellcheck warning in https://travis-ci.org/github/thesofproject/sof-test/jobs/747267512

xiulipan
xiulipan reviewed Dec 17, 2020
View reviewed changes
test-case/multiple-pipeline.sh Outdated
esac

dlogi "sleep ${OPT_VALUE_lst['w']}s for sound device wakeup"
sleep ${OPT_VALUE_lst['w']}
Copy link
Contributor

@xiulipan xiulipan Dec 17, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this sleep is used to avoid delay in PM resume.
Not sure if this is still a blocker for us.
@aiChaoSONG @keqiaozhang Any idea？

Copy link
Collaborator Author

@marc-hb marc-hb Mar 5, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ping?

@marc-hb
multiple-pipeline: remove initial sleep and clarify second sleep
d42d281 
Having the same -w parameter for both this initial sleep and the test
duration made no sense: fixed by removing the first sleep.

It's not clear what the purpose of this first sleep was, it has been in
multiple-pipeline-capture/playback.sh since the dawn of time (= commit
39cd964) For sure this first sleep was helping hide
"uninterruptible state" bug thesofproject#472 by giving the DSP more time to wake up!

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
fredoh9
fredoh9 approved these changes Apr 26, 2021
View reviewed changes
Copy link
Contributor

@fredoh9 fredoh9 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Logically making sense. But I do remember it was introduced due to some errors in some cases. (don't know why we put same value with before/after ps_check).
By the device test result, it looks good.

@marc-hb
Copy link
Collaborator Author

marc-hb commented Apr 27, 2021 •
edited
Loading

SOFCI TEST

EDIT: https://sof-ci.01.org/softestpr/PR543/build596/devicetest/?model=TGLH_RVP_HDA&testcase=check-suspend-resume-5 was all green except for the usual #650 TIMEOUT. However it was 1.5 months old, so testing again to be on the safe side.

@marc-hb
Copy link
Collaborator Author

marc-hb commented Apr 27, 2021

The only failure in https://sof-ci.01.org/softestpr/PR543/build676/devicetest/?model=BYT_MB_NOCODEC&testcase=simultaneous-playback-capture is some input/output error that sounds familiar but that is more importantly in a different test not modified at all by this PR. Merging

@marc-hb marc-hb merged commit f93a3c8 into thesofproject:main Apr 27, 2021
@marc-hb marc-hb deleted the multi-no-sleep branch April 27, 2021 04:30
marc-hb added a commit to marc-hb/sof-test that referenced this pull request Apr 28, 2021
@marc-hb
Revert "multiple-pipeline: remove initial sleep and clarify second sl…
d26b45b 
…eep"

This reverts commit f93a3c8.

This broke multiple-pipeline-playback-50 on sh-tglu-sku0a3e-sdw-01 and
jf-cml-sku0983-sdw-2, see below. Almost all other platforms ran
fine.

Found by Keqiao in daily test run 3577 (thx)

It's not clear what exactly the issue/race is yet (let's discuss in
original PR thesofproject#543 or in a new bug linked from there) but the top
priority is to fix the tests.

```
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: Speaker [hw:0,2]
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,2 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: HDMI 1 [hw:0,5]
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,5 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: HDMI 2 [hw:0,6]
2021-04-27 22:35:17 UTC [REMOTE_INFO] checking pipeline status
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,6 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Letting playback/capture run for 5s
2021-04-27 22:35:22 UTC [REMOTE_INFO] checking pipeline status again
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] pkill -9 aplay arecord
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59208 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59216 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59190 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
declare -- cmd="journalctl_cmd --since=@1619562912"

2021-04-27 22:35:22 UTC [REMOTE_INFO] ===== Testing: (Loop: 2/50) =====

2021-04-27 22:35:22 UTC [REMOTE_INFO] /home/ubuntu/sof-test/test-case/multiple-pipeline.sh will use topology /lib/firmware/intel/sof-tplg/sof-tgl-rt715-rt711-rt1308-mono.tplg to run the test case
2021-04-27 22:35:22 UTC [REMOTE_INFO] Pipeline list to ignore is specified, will ignore 'pcm=HDA Digital' in test case
2021-04-27 22:35:22 UTC [REMOTE_INFO] Run command to get pipeline parameters
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] sof-tplgreader.py /lib/firmware/intel/sof-tplg/sof-tgl-rt715-rt711-rt1308-mono.tplg -f 'type:playback' -b ' pcm:HDA Digital' -s 0 -e
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: Jack Out [hw:0,0]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: Speaker [hw:0,2]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,2 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: HDMI 1 [hw:0,5]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,5 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: HDMI 2 [hw:0,6]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,6 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] checking pipeline status
2021-04-27 22:35:22 UTC [REMOTE_ERROR] Running process count is 5, but 4 is expected
```
@marc-hb marc-hb mentioned this pull request Apr 28, 2021
Merged
marc-hb added a commit that referenced this pull request Apr 28, 2021
@marc-hb
Revert "multiple-pipeline: remove initial sleep and clarify second sl…
4173e84 
…eep"

This reverts commit f93a3c8.

This broke multiple-pipeline-playback-50 on sh-tglu-sku0a3e-sdw-01 and
jf-cml-sku0983-sdw-2, see below. Almost all other platforms ran
fine.

Found by Keqiao in daily test run 3577 (thx)

It's not clear what exactly the issue/race is yet (let's discuss in
original PR #543 or in a new bug linked from there) but the top
priority is to fix the tests.

```
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: Speaker [hw:0,2]
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,2 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: HDMI 1 [hw:0,5]
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,5 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Testing: HDMI 2 [hw:0,6]
2021-04-27 22:35:17 UTC [REMOTE_INFO] checking pipeline status
2021-04-27 22:35:17 UTC [REMOTE_COMMAND] aplay   -D hw:0,6 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:17 UTC [REMOTE_INFO] Letting playback/capture run for 5s
2021-04-27 22:35:22 UTC [REMOTE_INFO] checking pipeline status again
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] pkill -9 aplay arecord
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59208 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59216 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
/home/ubuntu/sof-test/test-case/../case-lib/lib.sh: line 312: 59190 Killed                  aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
declare -- cmd="journalctl_cmd --since=@1619562912"

2021-04-27 22:35:22 UTC [REMOTE_INFO] ===== Testing: (Loop: 2/50) =====

2021-04-27 22:35:22 UTC [REMOTE_INFO] /home/ubuntu/sof-test/test-case/multiple-pipeline.sh will use topology /lib/firmware/intel/sof-tplg/sof-tgl-rt715-rt711-rt1308-mono.tplg to run the test case
2021-04-27 22:35:22 UTC [REMOTE_INFO] Pipeline list to ignore is specified, will ignore 'pcm=HDA Digital' in test case
2021-04-27 22:35:22 UTC [REMOTE_INFO] Run command to get pipeline parameters
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] sof-tplgreader.py /lib/firmware/intel/sof-tplg/sof-tgl-rt715-rt711-rt1308-mono.tplg -f 'type:playback' -b ' pcm:HDA Digital' -s 0 -e
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: Jack Out [hw:0,0]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: Speaker [hw:0,2]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,2 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: HDMI 1 [hw:0,5]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,5 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] Testing: HDMI 2 [hw:0,6]
2021-04-27 22:35:22 UTC [REMOTE_COMMAND] aplay   -D hw:0,6 -c 2 -r 48000 -f S16_LE /dev/zero -q
2021-04-27 22:35:22 UTC [REMOTE_INFO] checking pipeline status
2021-04-27 22:35:22 UTC [REMOTE_ERROR] Running process count is 5, but 4 is expected
```
@keqiaozhang
Copy link
Contributor

keqiaozhang commented Apr 29, 2021 •
edited
Loading

@marc-hb , I added more logs and got below information. From the output, the processe ID 4986 marked in red was not cleaned up during the next round of testing, that's why it failed with:

2021-04-28 09:02:43 UTC [ERROR] Running process count is 5, but 4 is expected

Capture

So the sleep time between each round of testing is necessary to ensure that all processes of the previous round of testing are completely cleared

marc-hb added a commit to marc-hb/sof-test that referenced this pull request Apr 29, 2021
@marc-hb
multiple-pipeline: simplify sleeps
61761f9 
Having the same -w parameter for two different sleeps in the same
iteration made no sense.

It was not clear what the purpose of this first sleep was, it has been in
multiple-pipeline-capture/playback.sh since the dawn of time (= commit
39cd964) For sure this first sleep was helping hide
"uninterruptible state" bug thesofproject#472 by giving the DSP more time to wake up!

More recently it was found after merging and reverting an earlier
version of this (PR thesofproject#543 / commit f93a3c8) that this first sleep
was (accidentally?) giving more time for processes to actually
disappeared after being killed at the end of a test round and not
pollute the next test iteration. Make that clearer by moving the first
sleep to the end of the iteration, right after the kills and hardcode to
one second.

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
@marc-hb marc-hb mentioned this pull request Apr 29, 2021
Merged
@marc-hb
Copy link
Collaborator Author

marc-hb commented Apr 29, 2021

Reverted in #669 and new version submitted in #671

marc-hb added a commit that referenced this pull request Apr 29, 2021
@marc-hb
multiple-pipeline: simplify sleeps
a726dc1 
Having the same -w parameter for two different sleeps in the same
iteration made no sense.

It was not clear what the purpose of this first sleep was, it has been in
multiple-pipeline-capture/playback.sh since the dawn of time (= commit
39cd964) For sure this first sleep was helping hide
"uninterruptible state" bug #472 by giving the DSP more time to wake up!

More recently it was found after merging and reverting an earlier
version of this (PR #543 / commit f93a3c8) that this first sleep
was (accidentally?) giving more time for processes to actually
disappeared after being killed at the end of a test round and not
pollute the next test iteration. Make that clearer by moving the first
sleep to the end of the iteration, right after the kills and hardcode to
one second.

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

Reviewers

@fredoh9 fredoh9 fredoh9 approved these changes

@aiChaoSONG aiChaoSONG Awaiting requested review from aiChaoSONG

+2 more reviewers

@xiulipan xiulipan xiulipan left review comments

@keqiaozhang keqiaozhang keqiaozhang approved these changes

Reviewers whose approvals may not affect merge requirements

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

4 participants

@marc-hb @keqiaozhang @xiulipan @fredoh9