[BUG][BSW][EHL] DMA is broken and get aplay "write error: Input/output error" in multi-pipeline playback/capture test

[mengdonglin]

Describe the bug
DMA is broken and get aplay "write error: Input/output error" in multi-pipeline playback/capture test on Braswell.

To Reproduce
Run 2 playback pipelines and 1 capture pipeline.

1. aplay -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2. aplay -D hw:0,1 -c 2 -r 48000 -f S16_LE /dev/zero -q
3. arecord -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/null -q

Reproduction Rate
random. It may happen at the 1st iteration of the multi-pipeline test.

Expected behavior
Playback and capture of all 3 pipelines should work without error.

Impact
Get "aplay: pcm_write:2061: write error: Input/output error" on 2 pipelines.

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel Branch: topic/sof-dev, commit: 40e44b3a
   • SOF Branch: stable-v1.6 , commit 6e98d9d
2. Name of the topology file
   • Topology: sof-cht-max98090
3. Name of the platform(s) on which the bug is observed.
   • Platform: BSW_CYN_MAX98090 - Braswell Chromebook with max98090 codec

Screenshots or console output

Output of test log:

2020-09-23 11:26:07 UTC [REMOTE_INFO] ===== Testing: (Loop: 1/200) =====
2020-09-23 11:26:07 UTC [REMOTE_INFO] /home/ubuntu/sof-test/test-case/multiple-pipeline-playback.sh will use topology /lib/firmware/intel/sof-tplg/sof-cht-max98090.tplg to run the test case
2020-09-23 11:26:07 UTC [REMOTE_INFO] Pipeline list to ignore is specified, will ignore 'pcm=HDA Digital,Media Playback' in test case
2020-09-23 11:26:07 UTC [REMOTE_INFO] Run command to get pipeline parameters
2020-09-23 11:26:07 UTC [REMOTE_COMMAND] sof-tplgreader.py /lib/firmware/intel/sof-tplg/sof-cht-max98090.tplg -f 'type:playback' -b ' pcm:HDA Digital,Media Playback' -e
2020-09-23 11:26:07 UTC [REMOTE_INFO] Testing: PCM [hw:0,0]
2020-09-23 11:26:07 UTC [REMOTE_COMMAND] aplay -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q
2020-09-23 11:26:07 UTC [REMOTE_INFO] Testing: PCM Deep Buffer [hw:0,1]
2020-09-23 11:26:07 UTC [REMOTE_COMMAND] aplay -D hw:0,1 -c 2 -r 48000 -f S16_LE /dev/zero -q
2020-09-23 11:26:07 UTC [REMOTE_INFO] /home/ubuntu/sof-test/test-case/multiple-pipeline-playback.sh will use topology /lib/firmware/intel/sof-tplg/sof-cht-max98090.tplg to run the test case
2020-09-23 11:26:07 UTC [REMOTE_INFO] Pipeline list to ignore is specified, will ignore 'pcm=HDA Digital,Media Playback' in test case
2020-09-23 11:26:07 UTC [REMOTE_INFO] Run command to get pipeline parameters
2020-09-23 11:26:07 UTC [REMOTE_COMMAND] sof-tplgreader.py /lib/firmware/intel/sof-tplg/sof-cht-max98090.tplg -f 'type:capture' -b ' pcm:HDA Digital,Media Playback' -e
2020-09-23 11:26:07 UTC [REMOTE_INFO] Testing: PCM [hw:0,0]
2020-09-23 11:26:07 UTC [REMOTE_COMMAND] arecord -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/null -q
2020-09-23 11:26:07 UTC [REMOTE_INFO] pipeline start sleep 0.5s for device wakeup
aplay: pcm_write:2061: write error: Input/output error
aplay: pcm_write:2061: write error: Input/output error
2020-09-23 11:26:12 UTC [REMOTE_ERROR] Target pipeline count: 3, current process count: 1

Output of etrace

[ 17235491.822917] ( 17235492.000000) c0 dma-trace             src/trace/dma-trace.c:327  ERROR FW ABI 0x3011000 DBG ABI 0x5002000 tag v1.5-rc1-714-g6e98d9dde423 src hash 0xb4ce6f04 (ldc hash 0xb4ce6f04)
[8159108968.593750] (             nan) c0 dw-dma                 src/drivers/dw/dma.c:283  ERROR dw_dma_start(): dma 0 channel 2 not ready ena 0x5 status 0x3
[8159108982.656250] (       14.062500) c0 host         4.23          src/audio/host.c:317  ERROR host_copy_one_shot(): dma_copy() failed, ret = 4294967280
[8159108993.177084] (       10.520833) c0 pipe         4.27      src/audio/pipeline.c:1023 ERROR pipeline_copy(): ret = -16, start->comp.id = 24, dir = 1
[8159109005.833334] (       12.656250) c0 pipe         4.27      src/audio/pipeline.c:1213 ERROR pipeline_task(): xrun recover failed! pipeline will be stopped!
error: in logger_read(), fread(..., /sys/kernel/debug/sof/etrace) failed: Inappropriate ioctl for device(25)

[lgirdwood]

[8159108968.593750] (             nan) c0 dw-dma                 src/drivers/dw/dma.c:283  ERROR dw_dma_start(): dma 0 channel 2 not ready ena 0x5 status 0x3

Means the channel still has data within it's internal FIFO (not SSP FIFO) from the last block copied and cannot be recovered. FW should make sure that DMA channel FIFO is completely drained prior to channel disable.

#if CONFIG_DMA_SUSPEND_DRAIN
	/* channel cannot be disabled right away, so first we need to
	 * suspend it and drain the FIFO
	 */
	dma_reg_write(dma, DW_CFG_LOW(channel->index),
		      dw_chan->cfg_lo | DW_CFGL_SUSPEND | DW_CFGL_DRAIN);

	/* now we wait for FIFO to be empty */
	ret = poll_for_register_delay(dma_base(dma) +
				      DW_CFG_LOW(channel->index),
				      DW_CFGL_FIFO_EMPTY,
				      DW_CFGL_FIFO_EMPTY,
				      DW_DMA_TIMEOUT);
	if (ret < 0)
		tr_err(&dwdma_tr, "dw_dma_stop(): dma %d channel %d timeout",
		       dma->plat_data.id, channel->index);
#endif

There may be an error further up the logs showing the above timeout error.

[mengdonglin]

Keep this as a known issue.

[libinyang]

EHL has the similar issue.

2020-09-29 23:06:00 UTC [REMOTE_INFO] pipeline start sleep 0.5s for device wakeup
2020-09-29 23:06:05 UTC [REMOTE_INFO] checking pipeline status
2020-09-29 23:06:06 UTC [REMOTE_INFO] preparing sleep 5
2020-09-29 23:06:11 UTC [REMOTE_ERROR] Target pipeline count: 4, current process count: 3
/home/ubuntu/sof-test/test-case/multiple-pipeline-capture.sh: line 96: 66560 Killed "${APP_LST[$1]}" -D $dev -c $channel -r $rate -f $fmt "${DEV_LST[$1]}" -q
2020-09-29 23:06:11 UTC [REMOTE_ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
/home/ubuntu/sof-test/case-lib/hijack.sh: line 17: 66531 Killed "${APP_LST[$1]}" -D $dev -c $channel -r $rate -f $fmt "${DEV_LST[$1]}" -q
/home/ubuntu/sof-test/case-lib/hijack.sh: line 17: 66540 Killed "${APP_LST[$1]}" -D $dev -c $channel -r $rate -f $fmt "${DEV_LST[$1]}" -q
/home/ubuntu/sof-test/case-lib/hijack.sh: line 23: 66522 Killed "${APP_LST[$1]}" -D $dev -c $channel -r $rate -f $fmt "${DEV_LST[$1]}" -q
2020-09-29 23:06:11 UTC [REMOTE_ERROR] func_error_exit() @ /home/ubuntu/sof-test/test-case/multiple-pipeline-capture.sh
2020-09-29 23:06:11 UTC [REMOTE_ERROR] main() @ /home/ubuntu/sof-test/test-case/multiple-pipeline-capture.sh:140
2020-09-29 23:06:11 UTC [REMOTE_INFO] Starting /usr/bin/sof-logger -l /etc/sof/sof-ehl.ldc -o /home/ubuntu/sof-test/logs/multiple-pipeline-capture/2020-09-29-22:59:52-12824/etrace.txt
2020-09-29 23:06:12 UTC [REMOTE_INFO] pkill -TERM sof-logger
Terminated
2020-09-29 23:06:13 UTC [REMOTE_INFO] nlines=7 /home/ubuntu/sof-test/logs/multiple-pipeline-capture/2020-09-29-22:59:52-12824/etrace.txt
2020-09-29 23:06:13 UTC [REMOTE_INFO] Test Result: FAIL!

output etrace:
[11069850519.218750] ( nan) c0 dma-trace src/trace/dma-trace.c:327 ERROR FW ABI 0x3011000 DBG ABI 0x5002000 tag v1.5-rc1-740-gd9eb16aa6655 src hash 0x3b2dd859 (ldc hash 0x3b2dd859)
[11069850519.218750] ( 0.000000) c0 dma-trace src/trace/dma-trace.c:327 ERROR FW ABI 0x3011000 DBG ABI 0x5002000 tag v1.5-rc1-740-gd9eb16aa6655 src hash 0x3b2dd859 (ldc hash 0x3b2dd859)
[11069850534.739584] ( 15.520833) c0 hda-dma ..../intel/hda/hda-dma.c:479 hda-dmac: 4 channel 0 -> get
[11069850654.270834] ( 119.531250) c0 hda-dma ..../intel/hda/hda-dma.c:672 hda-dmac: 4 channel 0 -> config
[11069850705.156250] ( 50.885418) c0 hda-dma ..../intel/hda/hda-dma.c:536 hda-dmac: 4 channel 0 -> start
[11069850714.218750] ( 9.062500) c0 hda-dma ..../intel/hda/hda-dma.c:393 hda-dmac: 4 channel 0 -> enable

[lgirdwood]

@libinyang I've changed the title to mark this as EHL too. @slawblauciak fyi.

[plbossart]

@libinyang @lgirdwood EHL should be a separate issue, there's nothing common between the two hardware solutions, it can't possibly be a common root cause.

[lgirdwood]

@plbossart this will hopefully be clarified at the next scrub, I just want to rule out anything in the pipeline logic with multiple streams.