Repository navigation
aplay failed after speaker test with Dhw:0,1 on BYT-mb-rt5651 #1161
Description
Summary:
Aplay with Dhw:0,0 failed after speaker test with Dhw:0,1 on BYT-mb-rt5651.
Step:
1.speaker-test -Dhw:0,1 -c2 -t wav
speaker-test 1.1.3
Playback device is hw:0,1
Stream parameters are 48000Hz, S16_LE, 2 channels
WAV file(s)
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 384 to 2095104
Period size range from 192 to 65472
Using max buffer size 2095104
Periods = 4
Unable to set hw params for playback: Invalid argument
Setting of hwparams failed: Invalid argument
2.aplay -Dhw:0,0 -c2 -r48000 -fS16_LE Music/California_Dreaming_48k_16bit.wav -vv -i
Playing WAVE 'Music/California_Dreaming_48k_16bit.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
Hardware PCM card 0 'sof-bytcr-rt5651' device 0 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 : 16320
period_size : 4032
period_time : 84000
tstamp_mode : NONE
tstamp_type : MONOTONIC
period_step : 1
avail_min : 4032
period_event : 0
start_threshold : 16320
stop_threshold : 16320
silence_threshold: 0
silence_size : 0
boundary : 9187343239835811840
appl_ptr : 0
hw_ptr : 0
#+ | 00%aplay: pcm_write:2011: write error: Input/output error
Dmesg:
[ 19.998283] sof-audio-acpi 80860F28:01: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE: SET_VALUE
[ 20.300654] sof-audio-acpi 80860F28:01: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 20.300664] sof-audio-acpi 80860F28:01: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 20.800929] sof-audio-acpi 80860F28:01: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 20.800943] sof-audio-acpi 80860F28:01: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 22.381706] systemd-journald[1429]: File /var/log/journal/925896dd495840eca8c6be1ff455ace4/user-1000.journal corrupted or uncleanly shut down, renaming and replacing.
[ 23.825355] igb 0000:03:00.0 enp3s0: igb: enp3s0 NIC Link is Up 100 Mbps Full Duplex, Flow Control: RX
[ 23.825957] IPv6: ADDRCONF(NETDEV_CHANGE): enp3s0: link becomes ready
[ 125.294196] sof-audio-acpi 80860F28:01: pcm: open stream 1 dir 0
[ 125.294202] sof-audio-acpi 80860F28:01: period min 192 max 262144 bytes
[ 125.294205] sof-audio-acpi 80860F28:01: period count 2 max 32
[ 125.294207] sof-audio-acpi 80860F28:01: buffer max 8388608 bytes
[ 125.294404] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 125.294407] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 125.294412] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 125.294415] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 125.305698] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 125.305703] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 125.305713] sof-audio-acpi 80860F28:01: pcm: hw params stream 1 dir 0
[ 125.305720] sof-audio-acpi 80860F28:01: generating page table for 00000000bc28ba37 size 0x7fe000 pages 2046
[ 125.305744] sof-audio-acpi 80860F28:01: stream_tag 0
[ 125.305754] sof-audio-acpi 80860F28:01: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 125.306179] sof-audio-acpi 80860F28:01: error: ipc error for 0x60010000 size 20
[ 125.306187] sof-audio-acpi 80860F28:01: error: hw params ipc failed for stream 0
[ 125.306190] sof-audio-acpi 80860F28:01: ASoC: 80860F28:01 hw params failed: -22
[ 125.306194] Media Playback 1: ASoC: hw_params FE failed -22
[ 125.306202] sof-audio-acpi 80860F28:01: pcm: free stream 1 dir 0
[ 125.306207] sof-audio-acpi 80860F28:01: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 125.306368] sof-audio-acpi 80860F28:01: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 125.306483] sof-audio-acpi 80860F28:01: pcm: close stream 1 dir 0
[ 125.343068] sof-audio-acpi 80860F28:01: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 125.343091] sof-audio-acpi 80860F28:01: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 158.074172] random: crng init done
[ 158.074177] random: 7 urandom warning(s) missed due to ratelimiting
[ 168.079201] rfkill: input handler disabled
[ 187.329927] sof-audio-acpi 80860F28:01: pcm: open stream 0 dir 0
[ 187.329932] sof-audio-acpi 80860F28:01: period min 192 max 16384 bytes
[ 187.329935] sof-audio-acpi 80860F28:01: period count 2 max 16
[ 187.329938] sof-audio-acpi 80860F28:01: buffer max 65536 bytes
[ 187.333506] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 187.333511] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 187.333518] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 187.333520] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 187.333530] sof-audio-acpi 80860F28:01: rate_min: 48000 rate_max: 48000
[ 187.333532] sof-audio-acpi 80860F28:01: channels_min: 2 channels_max: 2
[ 187.336620] sof-audio-acpi 80860F28:01: pcm: hw params stream 0 dir 0
[ 187.336642] sof-audio-acpi 80860F28:01: generating page table for 000000004dc19d72 size 0xff00 pages 16
[ 187.336655] sof-audio-acpi 80860F28:01: stream_tag 0
[ 187.336675] sof-audio-acpi 80860F28:01: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 187.337032] sof-audio-acpi 80860F28:01: ipc tx succeeded: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 187.367977] sof-audio-acpi 80860F28:01: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 187.368000] sof-audio-acpi 80860F28:01: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 187.740825] sof-audio-acpi 80860F28:01: pcm: trigger stream 0 dir 0 cmd 1
[ 187.740833] sof-audio-acpi 80860F28:01: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 187.740911] sof-audio-acpi 80860F28:01: ipc tx succeeded: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 188.342128] sof-audio-acpi 80860F28:01: PCM: stream 0 dir 0 DMA position 0 DAI position 0
[ 188.849832] sof-audio-acpi 80860F28:01: pcm: trigger stream 0 dir 0 cmd 0
[ 188.849841] sof-audio-acpi 80860F28:01: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 188.851427] sof-audio-acpi 80860F28:01: error: ipc error for 0x60050000 size 12
[ 188.851439] Low Latency: ASoC: trigger FE failed -5
[ 188.851459] sof-audio-acpi 80860F28:01: pcm: free stream 0 dir 0
[ 188.851464] sof-audio-acpi 80860F28:01: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 188.851775] sof-audio-acpi 80860F28:01: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 188.851833] sof-audio-acpi 80860F28:01: pcm: close stream 0 dir 0
Sof-logger:
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 IPC 111617668.281250 111617672.000000 src/ipc/handler.c:296 ipc: comp 21 parse descriptors failed -12
0 1 DMA 111617681.875000 13.593750 src/drivers/dw/dma.c:442 dw-dma: 1 invalid channel -1
0 1 DMA 111617934.947917 253.072922 src/drivers/dw/dma.c:442 dw-dma: 1 invalid channel -1
0 1 DMA 174154314.322917 62536380.000000 src/drivers/dw/dma.c:807 dw-dma: 0 channel 0 not enough elems for config with irq disabled
0 1 BUFFER 174154324.843750 10.520833 src/lib/dma-trace.c:90 trace_work() error: dma_copy_to_host_nowait() failed
0 1 DMA 174654314.322917 499989.468750 src/drivers/dw/dma.c:807 dw-dma: 0 channel 0 not enough elems for config with irq disabled
0 1 BUFFER 174654324.843750 10.520833 src/lib/dma-trace.c:90 trace_work() error: dma_copy_to_host_nowait() failed
0 1 WAIT 175137506.562500 483181.718750 src/lib/wait.c:118 ewt
0 1 DMA 175137513.125000 6.562500 src/drivers/dw/dma.c:647 dw-dma: 1 channel 0 timeout
0 1 IPC 175137527.708333 14.583333 src/audio/pipeline.c:541 pipeline_trigger() error: ret = -5, host->comp.id = 1, cmd = 0
0 1 IPC 175137543.229167 15.520833 src/ipc/handler.c:498 ipc: comp 1 trigger 0x50000 failed -5
Test env:
sof master: cd4633c
kernel sof-dev: 0ba314f
tplg: sof-byt-rt5651.tplg
Log:
dmesg.log
logger.log
Activity
tlauda commentedon Mar 21, 2019
Please verify after applying following patches: #1136, #1159, #1160 and #1162.
ranj063 commentedon Mar 21, 2019
@tlauda this is not related to the noise issue. so the above PR's likely wont help
ranj063 commentedon Mar 21, 2019
@Jiangxinx it looks like the speaker-test failed in the first step. So obviously aplay after that will fail as well.
I am suspecting the kernel is not updated.
ranj063 commentedon Mar 21, 2019
I have verified this issue doesnt exist with these commits:
kernel commit: thesofproject/linux@2293bc7
fw commit: de46954
tlauda commentedon Mar 21, 2019
@ranj063 I've suggested above PR's, because probably all of them are needed to make speaker test work. Error highlighted above is fixed by #1159.
ranj063 commentedon Mar 21, 2019
@tlauda all of the above PR's are merged to master now and the commit I included is the latest tip of master
tlauda commentedon Mar 28, 2019
@Jiangxinx Any updates?
Jiangxinx commentedon Mar 29, 2019
This issue can still be reproduced on daily test.
Test env:
sof master: 742f83b
kernel sof-dev: e29122d
tplg: sof-byt-rt5651.tplg
juimonen commentedon Mar 29, 2019
For me the speaker test (so playing to hw 0,1) will fail despite of playing first to hw 0,0.
attached logs for playing to hp (hw 0,0) and to speaker (0,1), not sure these correspond to actual speaker and hp devices, but you can understand the difference.
so:
aplay -Dhw:0,0 -c2 -r48000 -fS16_LE test48.wav:
hp_test_dmesg.txt
hp_test_logger.txt
aplay -Dhw:0,1 -c2 -r48000 -fS16_LE test48.wav
speaker_test_dmesg.txt
speaker_test_logger.txt
juimonen commentedon Mar 29, 2019
here's the topology graph for rt5651:
so there's a src on the failing pipeline, otherwise looks pretty much the same.
tlauda commentedon Mar 29, 2019
@juimonen Could you rebuild the topology and try again? From the error log I see, that you're missing some latest changes from master. Please attach the logs, if it fails again.
juimonen commentedon Mar 29, 2019
@tlauda you're right, sorry about the confusion. Now with latest sof master it fails for some volume copy stuff...
speaker_test_logger.txt
tlauda commentedon Mar 29, 2019
@juimonen The current issue you have is related to SRC copying #1147 (SRC copied 0 bytes during preload run). Nevertheless, after fixing SRC issue this ppl will still fail due to the fact, that pipelines are triggered independently and kernel didn't start mixer pipeline.
@lgirdwood Do you have any ideas regarding triggering connected pipelines or this is something we should discuss?
juimonen commentedon Mar 29, 2019
@tlauda ok. I tried similar topology in up2 and don't get the src error, maybe it is just faster and there's no underrun. However as you said the pipeline doesn't play, probably because other pipeline is not triggered. So as I understand this is not byt specific thing...
attached topology to test in up2, so in sof/topology dir do:
m4 -I m4 -I common -I platform/common sof-apl-src-pcm512x.m4 > sof-apl-src-pcm512x.conf
alsatplg -c sof-apl-src-pcm512x.conf -o sof-apl-src-pcm512x.tplg
sof-apl-src-pcm512x.zip
lgirdwood commentedon Apr 18, 2019
@juimonen can you update your test results and close if passes.
juimonen commentedon Apr 18, 2019
@lgirdwood I guess the scheduling should be enabled by #1228 which is merged, but @tlauda was mentioning some needed topology changes for the 0:1 pipeline branch...@tlauda are they somewhere already?
@lgirdwood I'm out-of-office so can't test this right now..
lgirdwood commentedon Apr 18, 2019
@juimonen Dhw:0,1 supported is targeted for v1.4 so I think we are good today for v1.3
tlauda commentedon Apr 29, 2019
@juimonen @Jiangxinx Can anyone confirm it's fixed?