[PATCH 0/2] kselftest/alsa: Decrease pcm-test duration to avoid timeouts
This series decreases the pcm-test duration in order to avoid timeouts by first moving the audio stream duration to a variable and subsequently decreasing it.
Nícolas F. R. A. Prado (2): kselftest/alsa: pcm-test: Move stream duration and margin to variables kselftest/alsa: pcm-test: Decrease stream duration from 4 to 2 seconds
tools/testing/selftests/alsa/pcm-test.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-)
The duration to stream for and time margin to consider the stream failed are currently hardcoded values. Move them to variables so they can be reused and more easily changed.
Signed-off-by: Nícolas F. R. A. Prado nfraprado@collabora.com
---
tools/testing/selftests/alsa/pcm-test.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-)
diff --git a/tools/testing/selftests/alsa/pcm-test.c b/tools/testing/selftests/alsa/pcm-test.c index 3e390fe67eb9..a2b6db33b513 100644 --- a/tools/testing/selftests/alsa/pcm-test.c +++ b/tools/testing/selftests/alsa/pcm-test.c @@ -258,6 +258,8 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class, const char *test_name, snd_config_t *pcm_cfg) { char name[64], key[128], msg[256]; + const int duration_s = 4, margin_ms = 100; + const int duration_ms = duration_s * 1000; const char *cs; int i, err; snd_pcm_t *handle = NULL; @@ -442,7 +444,7 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class, skip = false;
timestamp_now(&tstamp); - for (i = 0; i < 4; i++) { + for (i = 0; i < duration_s; i++) { if (data->stream == SND_PCM_STREAM_PLAYBACK) { frames = snd_pcm_writei(handle, samples, rate); if (frames < 0) { @@ -472,8 +474,8 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class,
snd_pcm_drain(handle); ms = timestamp_diff_ms(&tstamp); - if (ms < 3900 || ms > 4100) { - snprintf(msg, sizeof(msg), "time mismatch: expected 4000ms got %lld", ms); + if (ms < duration_ms - margin_ms || ms > duration_ms + margin_ms) { + snprintf(msg, sizeof(msg), "time mismatch: expected %dms got %lld", duration_ms, ms); goto __close; }
Il 21/06/23 00:08, Nícolas F. R. A. Prado ha scritto:
The duration to stream for and time margin to consider the stream failed are currently hardcoded values. Move them to variables so they can be reused and more easily changed.
Signed-off-by: Nícolas F. R. A. Prado nfraprado@collabora.com
Reviewed-by: AngeloGioacchino Del Regno angelogioacchino.delregno@collabora.com
Currently test_pcm_time() streams audio on each PCM with each configuration for 4 seconds. This time can add up, and with the current 45 second kselftest timeout, some machines like mt8192-asurada-spherion can't even run to completion. Lower the duration to 2 seconds to cut the test duration in half, without reducing the test coverage.
Signed-off-by: Nícolas F. R. A. Prado nfraprado@collabora.com ---
tools/testing/selftests/alsa/pcm-test.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/testing/selftests/alsa/pcm-test.c b/tools/testing/selftests/alsa/pcm-test.c index a2b6db33b513..de42fc7e9b53 100644 --- a/tools/testing/selftests/alsa/pcm-test.c +++ b/tools/testing/selftests/alsa/pcm-test.c @@ -258,7 +258,7 @@ static void test_pcm_time(struct pcm_data *data, enum test_class class, const char *test_name, snd_config_t *pcm_cfg) { char name[64], key[128], msg[256]; - const int duration_s = 4, margin_ms = 100; + const int duration_s = 2, margin_ms = 100; const int duration_ms = duration_s * 1000; const char *cs; int i, err;
On Tue, Jun 20, 2023 at 06:08:26PM -0400, Nícolas F. R. A. Prado wrote:
- const int duration_s = 4, margin_ms = 100;
- const int duration_s = 2, margin_ms = 100;
This doesn't scale the margin with the duration which will affect the sensitivity of the test to misclocking. It should make it less sensitive which is *probably* safer but at least worth noting.
We might also have issues with some of the lower sample rates, IIRC some devices are constrained in ways that mean they want a minimum buffer size which is harder to satisfy with very short playbacks and low sample rates.
I don't know why Jaroslav picked the 4s number here.
On 21. 06. 23 15:08, Mark Brown wrote:
On Tue, Jun 20, 2023 at 06:08:26PM -0400, Nícolas F. R. A. Prado wrote:
- const int duration_s = 4, margin_ms = 100;
- const int duration_s = 2, margin_ms = 100;
This doesn't scale the margin with the duration which will affect the sensitivity of the test to misclocking. It should make it less sensitive which is *probably* safer but at least worth noting.
We might also have issues with some of the lower sample rates, IIRC some devices are constrained in ways that mean they want a minimum buffer size which is harder to satisfy with very short playbacks and low sample rates.
I don't know why Jaroslav picked the 4s number here.
You basically replied yourself. The values (time + margin) were picked to do the DMA test for a reasonable time - based on my experience.
I think that the problem is somewhere else here. The overall test timeout should be calculated dynamically. All tests may be queried for the maximal expected interval based on the hardware/software capabilities. It's a bit pitfall to have a fixed time limit where the realtime tests depend on the number of devices.
Jaroslav
On Wed, Jun 21, 2023 at 04:08:47PM +0200, Jaroslav Kysela wrote:
I think that the problem is somewhere else here. The overall test timeout should be calculated dynamically. All tests may be queried for the maximal expected interval based on the hardware/software capabilities. It's a bit pitfall to have a fixed time limit where the realtime tests depend on the number of devices.
I tend to agree here, unfortunately Shuah hasn't responded to queries from Nícolas about this which I imagine is what inspired this patch. We also have problems with mixer-test on one of the Dialog CODECs with a couple of 64k value controls and no cache only mode.
On Wed, Jun 21, 2023 at 03:39:12PM +0100, Mark Brown wrote:
On Wed, Jun 21, 2023 at 04:08:47PM +0200, Jaroslav Kysela wrote:
I think that the problem is somewhere else here. The overall test timeout should be calculated dynamically. All tests may be queried for the maximal expected interval based on the hardware/software capabilities. It's a bit pitfall to have a fixed time limit where the realtime tests depend on the number of devices.
I tend to agree here, unfortunately Shuah hasn't responded to queries from Nícolas about this which I imagine is what inspired this patch. We also have problems with mixer-test on one of the Dialog CODECs with a couple of 64k value controls and no cache only mode.
Yes, exactly. I've tried increasing the timeout for this test to a larger fixed value previously, and later asked for more information on how to deal with the kselftest timeout. [1]
Since I didn't hear back, I thought this patch would be a way to at least mitigate the issue for now, without limiting the test coverage, which was a concern with having limited scopes for the test.
I've just noticed that in the mean time a way to override the timeout when running kselftest has been introduced [2], so I suppose we could use that to work around the timeout limitation in CI systems and be able to run through completion on the different hardware at the lab. But I still believe, like you do, that calculating the timeout at runtime based on the hardware would make much more sense, though if there's such a desire to keep kselftests under the 45s mark, I'm not sure if it would be acceptable.
[1] https://lore.kernel.org/all/5302e70d-cb58-4e70-b44f-ff81b138a2e1@notapiano/ [2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?i...
Thanks, Nícolas
On Wed, 21 Jun 2023 18:03:22 +0200, Nícolas F. R. A. Prado wrote:
On Wed, Jun 21, 2023 at 03:39:12PM +0100, Mark Brown wrote:
On Wed, Jun 21, 2023 at 04:08:47PM +0200, Jaroslav Kysela wrote:
I think that the problem is somewhere else here. The overall test timeout should be calculated dynamically. All tests may be queried for the maximal expected interval based on the hardware/software capabilities. It's a bit pitfall to have a fixed time limit where the realtime tests depend on the number of devices.
I tend to agree here, unfortunately Shuah hasn't responded to queries from Nícolas about this which I imagine is what inspired this patch. We also have problems with mixer-test on one of the Dialog CODECs with a couple of 64k value controls and no cache only mode.
Yes, exactly. I've tried increasing the timeout for this test to a larger fixed value previously, and later asked for more information on how to deal with the kselftest timeout. [1]
Since I didn't hear back, I thought this patch would be a way to at least mitigate the issue for now, without limiting the test coverage, which was a concern with having limited scopes for the test.
I've just noticed that in the mean time a way to override the timeout when running kselftest has been introduced [2], so I suppose we could use that to work around the timeout limitation in CI systems and be able to run through completion on the different hardware at the lab. But I still believe, like you do, that calculating the timeout at runtime based on the hardware would make much more sense, though if there's such a desire to keep kselftests under the 45s mark, I'm not sure if it would be acceptable.
[1] https://lore.kernel.org/all/5302e70d-cb58-4e70-b44f-ff81b138a2e1@notapiano/ [2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?i...
So, we're back to square... Unless anyone has a strong objection, I'm inclined to take this as a workaround for 6.5 for now, as the merge window deadline is coming. We can improve things at the same time for the future kernel, too.
thanks,
Takashi
On Wed, Jun 21, 2023 at 06:34:22PM +0200, Takashi Iwai wrote:
So, we're back to square... Unless anyone has a strong objection, I'm inclined to take this as a workaround for 6.5 for now, as the merge window deadline is coming. We can improve things at the same time for the future kernel, too.
It feels like it might be good to let it cook for a bit longer before going to Linus (eg, applying after the merge window) so we've more chance to see what the impact is on other boards?
On Wed, 21 Jun 2023 19:08:27 +0200, Mark Brown wrote:
On Wed, Jun 21, 2023 at 06:34:22PM +0200, Takashi Iwai wrote:
So, we're back to square... Unless anyone has a strong objection, I'm inclined to take this as a workaround for 6.5 for now, as the merge window deadline is coming. We can improve things at the same time for the future kernel, too.
It feels like it might be good to let it cook for a bit longer before going to Linus (eg, applying after the merge window) so we've more chance to see what the impact is on other boards?
I'm fine with that option, too. Are most of selftests performed on linux-next basis, or rather on Linus tree?
Takashi
On Wed, Jun 21, 2023 at 08:13:11PM +0200, Takashi Iwai wrote:
Mark Brown wrote:
It feels like it might be good to let it cook for a bit longer before going to Linus (eg, applying after the merge window) so we've more chance to see what the impact is on other boards?
I'm fine with that option, too. Are most of selftests performed on linux-next basis, or rather on Linus tree?
For KernelCI we've got coverage on both. I can also run stuff on the boards I have in my lab on demand of course, but there's more coverage in KernelCI.
On Wed, 21 Jun 2023 20:19:46 +0200, Mark Brown wrote:
On Wed, Jun 21, 2023 at 08:13:11PM +0200, Takashi Iwai wrote:
Mark Brown wrote:
It feels like it might be good to let it cook for a bit longer before going to Linus (eg, applying after the merge window) so we've more chance to see what the impact is on other boards?
I'm fine with that option, too. Are most of selftests performed on linux-next basis, or rather on Linus tree?
For KernelCI we've got coverage on both. I can also run stuff on the boards I have in my lab on demand of course, but there's more coverage in KernelCI.
OK, now I applied those two patches to for-next branch (i.e. for 6.6 kernel). Let's watch out.
thanks,
Takashi
On Mon, Jul 10, 2023 at 09:00:09AM +0200, Takashi Iwai wrote:
Mark Brown wrote:
For KernelCI we've got coverage on both. I can also run stuff on the boards I have in my lab on demand of course, but there's more coverage in KernelCI.
OK, now I applied those two patches to for-next branch (i.e. for 6.6 kernel). Let's watch out.
I'm seeing failures on my i.MX6 boards, both the Q and DL have started failing in the same way:
# default.time3.0.0.0.PLAYBACK - 44.1kHz stereo large periods # default.time3.0.0.0.PLAYBACK hw_params.RW_INTERLEAVED.S16_LE.44100.2.16383.131064 sw_params.131064 not ok 10 default.time3.0.0.0.PLAYBACK # time mismatch: expected 2000ms got 2229
reliably (the actual time drifts by a few ms). The other boards I've got coverage of seem fine, and I didn't check any broader CI yet.
On Thu, 13 Jul 2023 00:03:24 +0200, Mark Brown wrote:
On Mon, Jul 10, 2023 at 09:00:09AM +0200, Takashi Iwai wrote:
Mark Brown wrote:
For KernelCI we've got coverage on both. I can also run stuff on the boards I have in my lab on demand of course, but there's more coverage in KernelCI.
OK, now I applied those two patches to for-next branch (i.e. for 6.6 kernel). Let's watch out.
I'm seeing failures on my i.MX6 boards, both the Q and DL have started failing in the same way:
# default.time3.0.0.0.PLAYBACK - 44.1kHz stereo large periods # default.time3.0.0.0.PLAYBACK hw_params.RW_INTERLEAVED.S16_LE.44100.2.16383.131064 sw_params.131064 not ok 10 default.time3.0.0.0.PLAYBACK # time mismatch: expected 2000ms got 2229
reliably (the actual time drifts by a few ms). The other boards I've got coverage of seem fine, and I didn't check any broader CI yet.
Interesting. With the current patch, we rather extended the margin in proportion; formerly 4 sec +/- 0.1s, now 2 sec +/- 0.1s. And it exceeded out of sudden.
I guess this rather caught a problem of the driver itself.
thanks,
Takashi
On Thu, Jul 13, 2023 at 10:47:43AM +0200, Takashi Iwai wrote:
Mark Brown wrote:
# default.time3.0.0.0.PLAYBACK - 44.1kHz stereo large periods # default.time3.0.0.0.PLAYBACK hw_params.RW_INTERLEAVED.S16_LE.44100.2.16383.131064 sw_params.131064 not ok 10 default.time3.0.0.0.PLAYBACK # time mismatch: expected 2000ms got 2229
reliably (the actual time drifts by a few ms). The other boards I've got coverage of seem fine, and I didn't check any broader CI yet.
Interesting. With the current patch, we rather extended the margin in proportion; formerly 4 sec +/- 0.1s, now 2 sec +/- 0.1s. And it exceeded out of sudden.
Right.
I guess this rather caught a problem of the driver itself.
Well, there's doubtless something driver/hardware related going on but I'm not sure if it's a problem there or not. The results from the 4s runtime were:
# default.time3.0.0.0.PLAYBACK - 44.1kHz stereo large periods # default.time3.0.0.0.PLAYBACK hw_params.RW_INTERLEAVED.S16_LE.44100.2.16383.131064 sw_params.131064 ok 10 default.time3.0.0.0.PLAYBACK
so the same buffer sizes and so on, and the period size is only 10ms unless I miscalculated which should be quite a long way off from the 100ms of margin we give ourselves. It does seem a little suspect that it's the large periods test that's falling over though.
participants (5)
-
AngeloGioacchino Del Regno -
Jaroslav Kysela -
Mark Brown -
Nícolas F. R. A. Prado -
Takashi Iwai