[BUG] PCM IO error with multi stream capture topology on pause-resume test

[bardliao]

Describe the bug PCM IO error happen when I run the "~/sof-test/test-case/multiple-pause-resume.sh -r 50" test.

To Reproduce

1. export TPLG=/lib/firmware/intel/avs-tplg/sof-tgl-nocodec.tplg
2. ~/sof-test/test-case/multiple-pause-resume.sh -r 50

Reproduction Rate 100%. But I can't reproduce this issue if I start two PCMs and pause-resume them manually.

Expected behavior PASS "~/sof-test/test-case/multiple-pause-resume.sh -r 50" test

Impact This is a blocker to add multi capture stream on topology.

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel: topic/sof-dev: https://github.com/thesofproject/linux/commit/ec7f15280902c4599ad97d0a93226b2fa5f62993
   • SOF: main: https://github.com/thesofproject/sof/commit/1e3a4cfe9b26176e28287b913b35bcbe12bbef79 + https://github.com/thesofproject/sof/pull/6601
2. Name of the topology file
   • Topology: cavs-tgl-nocodec.tplg
3. Name of the platform(s) on which the bug is observed.
   • Platform: {TGL}

Screenshots or console output I can't find useful information from kernel or firmware log. Below is the console output.

2022-11-15 08:31:45 UTC [INFO] ssp-capture to command: arecord -D hw:0,12 -r 48000 -c 2 -f S16_LE -vv -i /dev/null -q
2022-11-15 08:31:45 UTC [INFO] Port1 to command: aplay -D hw:0,1 -r 48000 -c 2 -f S16_LE -vv -i /dev/zero -q
spawn arecord -D hw:0,12 -r 48000 -c 2 -f S16_LE -vv -i /dev/null -q
2022-11-15 08:31:45 UTC [INFO] wait for expect process finished
spawn aplay -D hw:0,1 -r 48000 -c 2 -f S16_LE -vv -i /dev/zero -q
Hardware PCM card 0 'sof-nocodec' device 12 subdevice 0
Its setup is:
  stream       : CAPTURE
  access       : RW_INTERLEAVED
  format       : S16_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate   : 48000 (48000/1)
  msbits       : 16
  buffer_size  : 16384
  period_size  : 4096
  period_time  : 85333
  tstamp_mode  : NONE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 4096
  period_event : 0
  start_threshold  : 1
  stop_threshold   : 16384
  silence_threshold: 0
  silence_size : 0
  boundary     : 4611686018427387904
  appl_ptr     : 0
  hw_ptr       : 0
Hardware PCM card 0 'sof-nocodec' device 1 subdevice 0
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S16_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate   : 48000 (48000/1)
  msbits       : 16
  buffer_size  : 16384
  period_size  : 4096
  period_time  : 85333
  tstamp_mode  : NONE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 4096
  period_event : 0
  start_threshold  : 16384
  stop_threshold   : 16384
  silence_threshold: 0
  silence_size : 0
  boundary     : 4611686018427387904
  appl_ptr     : 0
  hw_ptr       : 0
...
arecord: pcm_read:2178: read error: Input/output error
...
2022-11-15 08:31:50 UTC [INFO] pipeline: ssp-capture with arecord
2022-11-15 08:31:50 UTC [INFO] pipeline: Port1 with aplay
2022-11-15 08:31:50 UTC [INFO] Check expect exit status
declare -- cmd="journalctl_cmd --since=@1668501030"
2022-11-15 08:31:50 UTC [ERROR] pause resume PID 2222 had non-zero exit status
2022-11-15 08:31:50 UTC [ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2022-11-15 08:31:51 UTC [ERROR]  die()  @  /home/ubuntu/sof-test/test-case/../case-lib/lib.sh
2022-11-15 08:31:51 UTC [ERROR]  main()  @  /home/ubuntu/sof-test/test-case/multiple-pause-resume.sh:191
2022-11-15 08:31:51 UTC [INFO] pkill -TERM -f mtrace-reader.py
2022-11-15 08:31:51 UTC [INFO] ktime=258 sof-test PID=1575: ending
2022-11-15 08:31:51 UTC [INFO] Test Result: FAIL!

Full console output, kernel and firmware log are attached. console.txt out.txt dmesg.txt