You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
[BUG] [TGL] WOV capture fails for the second time on TGL Chrome DUT #2511
Describe the bug
WOV capture fails for the second time.
To Reproduce
1)Start the WOV capture:
arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv
2)Start tapping on the DMIC and the WOV capture starts.
3)Press Ctrl+C
4)Second time start the WOV capture.
localhost ~ #
tmp.wav -vvv arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000
Recording WAVE 'tmp.wav' : Signed 16 bit Little Endian, Rate 16000 Hz, Stereo
arecord: set_params:1403: Unable to install hw params:
ACCESS: MMAP_INTERLEAVED
FORMAT: S16_LE
SUBFORMAT: STD
SAMPLE_BITS: 16
FRAME_BITS: 32
CHANNELS: 2
RATE: 16000
PERIOD_TIME: 999000
PERIOD_SIZE: 15984
PERIOD_BYTES: 63936
PERIODS: (4 5)
BUFFER_TIME: 3999000
BUFFER_SIZE: 63984
BUFFER_BYTES: 255936
TICK_TIME: 0
This capture shows failure. From the failure logs, it looks like the first capture stream did not freed
completely.(The allocated stream1 is not freed) and hence the second time capture does not start.
Reproduction Rate
Always
Keyword:
after Ctrl+C of first WOV capture
[ 376.026507] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power 0
[ 376.026531] sof-audio-pci 0000:00:1f.3: error: transition from 0 to 4 not allowed
[ 376.026532] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -22
[ 376.026543] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -22)
PFA the kernel & firmware logs.
changed the title [-][BUG] [TGL] WOV capture fails for the second time,[/-][+][BUG] [TGL] WOV capture fails for the second time on TGL Chrome DUT[/+]on Mar 9, 2020
I am currently using the OTC repo with few changes from broonie tree:
31f37b4d5033 ASoC: SOF: Intel: hda-loader: clear the IPC ack bit after FW_PURGE done
2337f615bf53 ASoC: SOF: ipc: check ipc return value before data copy
907e9be8f1ac ASoC: SOF: pcm: skip DMA buffer pre-allocation
Firmware used was:
TGL FW memory layout changing @Rajwa, Marcin have a simple test branch for the reference KWD HDA generic tplg in https://github.com/mrajwa/sof/tree/tgl_dev @xiulipan Can you please help with the kernel?
@RDharageswari, kernel has a problem with triggering stream. This is unknown kernel so I can't tell why is it failing, please provide link to the source.
Hi @mrajwa
I did check with the firmware on my kernel and still see issues.
First 2 /3 iterations go well and the moment i hit the failure..subsequent capture fails.
I am using the FW built out of https://github.com/mrajwa/sof/tree/tgl_dev_2
For the kernel i am trying to re-test with v5.4.Will update once i test.
command i use:
record -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=68000 tmp.wav -vvv
@mengdonglin, sure however we still don't know what is the reason of the issue @RDharageswari is describing. @RDharageswari, on the beginning you said the second capture fails, now you are saying "First 2 /3 iterations go well..." so something changed recently?
The issue seems to be on kernel side not being able to change states.
I am waiting for your tests results with different kernel.
@RDharageswari looking at the original logs: It looks like after you start the WoV stream, the DSP enters D0I3 but never exits back to D0I0 when you close the stream. And this is why you see that the transition from D0I3 -> D3 ( 0 to 4 in the logs) is not allowed.
Since we work remotely i was just able to do
arecord
Ctrl+C
multiple times and verify. I couldn't still validate the end to end stack.
As of now using the board from India,will verify the complete functionality with and without S0ix tonight when someone is there at lab and update
i verified the Wov functionality with the latest master FW 9da1fce
and the missed patch "ASoC: SOF: Intel: CNL: add set_power_state() ops" thesofproject/linux@73b5195
functionality works fine.
Activity
[-][BUG] [TGL] WOV capture fails for the second time,[/-][+][BUG] [TGL] WOV capture fails for the second time on TGL Chrome DUT[/+]RDharageswari commentedon Mar 9, 2020
sof-tgl-max98357a-rt5682.m4.txt
RDharageswari commentedon Mar 10, 2020
WOV_Working.zip
Adding the topology patches
lbetlej commentedon Mar 12, 2020
@RDharageswari Is the issue reproduced with arecord option
-d, --duration=# Interrupt after # seconds ?
RDharageswari commentedon Mar 12, 2020
Yes i could reproduce the issue with 10 seconds also:
arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
dmesg logs: first time:
[ 2866.862857] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[ 2866.862902] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at 00000044
[ 2866.862910] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power 0
[ 2866.862953] sof-audio-pci 0000:00:1f.3: error: transition from 0 to 4 not allowed
[ 2866.862954] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -22
[ 2866.862963] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -22)
localhost ~ # arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
second time capture fails:
localhost ~ # arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
Recording WAVE 'tmp.wav' : Signed 16 bit Little Endian, Rate 16000 Hz, Stereo
arecord: set_params:1403: Unable to install hw params:
ACCESS: MMAP_INTERLEAVED
FORMAT: S16_LE
SUBFORMAT: STD
SAMPLE_BITS: 16
FRAME_BITS: 32
CHANNELS: 2
RATE: 16000
PERIOD_TIME: 999000
PERIOD_SIZE: 15984
PERIOD_BYTES: 63936
PERIODS: (4 5)
BUFFER_TIME: 3999000
BUFFER_SIZE: 63984
BUFFER_BYTES: 255936
TICK_TIME: 0
[ 2880.905186] sof-audio-pci 0000:00:1f.3: pcm: open stream 7 dir 1
[ 2880.905189] sof-audio-pci 0000:00:1f.3: period min 192 max 256000 bytes
[ 2880.905190] sof-audio-pci 0000:00:1f.3: period count 2 max 160
[ 2880.905191] sof-audio-pci 0000:00:1f.3: buffer max 1280000 bytes
[ 2880.905417] sof-audio-pci 0000:00:1f.3: pcm: hw params stream 7 dir 1
[ 2880.905421] sof-audio-pci 0000:00:1f.3: generating page table for 000000001e00a2d0 size 0x3e7c0 pages 63
[ 2880.905436] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 2880.906741] sof-audio-pci 0000:00:1f.3: error: stream reset failed
[ 2880.906743] sof-audio-pci 0000:00:1f.3: error: hdac prepare failed: ffffff92
[ 2880.906744] sof-audio-pci 0000:00:1f.3: error: platform hw params failed
[ 2880.906747] sof-audio-pci 0000:00:1f.3: ASoC: 0000:00:1f.3 hw params failed: -110
[ 2880.906749] DMIC16k: ASoC: hw_params FE failed -110
[ 2880.906752] sof-audio-pci
RDharageswari commentedon Mar 12, 2020
Yes i could reproduce the issue with 10 seconds also:
arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
dmesg logs: first time:
[ 2866.862857] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[ 2866.862902] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at 00000044
[ 2866.862910] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power 0
[ 2866.862953] sof-audio-pci 0000:00:1f.3: error: transition from 0 to 4 not allowed
[ 2866.862954] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -22
[ 2866.862963] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -22)
localhost ~ # arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
second time capture fails:
localhost ~ # arecord -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=64000 tmp.wav -vvv -d 10
Recording WAVE 'tmp.wav' : Signed 16 bit Little Endian, Rate 16000 Hz, Stereo
arecord: set_params:1403: Unable to install hw params:
ACCESS: MMAP_INTERLEAVED
FORMAT: S16_LE
SUBFORMAT: STD
SAMPLE_BITS: 16
FRAME_BITS: 32
CHANNELS: 2
RATE: 16000
PERIOD_TIME: 999000
PERIOD_SIZE: 15984
PERIOD_BYTES: 63936
PERIODS: (4 5)
BUFFER_TIME: 3999000
BUFFER_SIZE: 63984
BUFFER_BYTES: 255936
TICK_TIME: 0
[ 2880.905186] sof-audio-pci 0000:00:1f.3: pcm: open stream 7 dir 1
[ 2880.905189] sof-audio-pci 0000:00:1f.3: period min 192 max 256000 bytes
[ 2880.905190] sof-audio-pci 0000:00:1f.3: period count 2 max 160
[ 2880.905191] sof-audio-pci 0000:00:1f.3: buffer max 1280000 bytes
[ 2880.905417] sof-audio-pci 0000:00:1f.3: pcm: hw params stream 7 dir 1
[ 2880.905421] sof-audio-pci 0000:00:1f.3: generating page table for 000000001e00a2d0 size 0x3e7c0 pages 63
[ 2880.905436] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 2880.906741] sof-audio-pci 0000:00:1f.3: error: stream reset failed
[ 2880.906743] sof-audio-pci 0000:00:1f.3: error: hdac prepare failed: ffffff92
[ 2880.906744] sof-audio-pci 0000:00:1f.3: error: platform hw params failed
[ 2880.906747] sof-audio-pci 0000:00:1f.3: ASoC: 0000:00:1f.3 hw params failed: -110
[ 2880.906749] DMIC16k: ASoC: hw_params FE failed -110
[ 2880.906752] sof-audio-pci
wwittbrx commentedon Mar 13, 2020
I can't reproduce this issue on TGL RVP with slim driver tests.
Running on
https://github.com/mrajwa/sof/commits/tgl_dev_2
746cb8b965d362a99b10d140fa869da80dc9cefa
Are we running on the same FW? Also, could you provide us with the kernel source?
RDharageswari commentedon Mar 13, 2020
I am currently using the OTC repo with few changes from broonie tree:
31f37b4d5033 ASoC: SOF: Intel: hda-loader: clear the IPC ack bit after FW_PURGE done
2337f615bf53 ASoC: SOF: ipc: check ipc return value before data copy
907e9be8f1ac ASoC: SOF: pcm: skip DMA buffer pre-allocation
Firmware used was:
TGL FW memory layout changing
@Rajwa, Marcin have a simple test branch for the reference KWD HDA generic tplg in https://github.com/mrajwa/sof/tree/tgl_dev
@xiulipan Can you please help with the kernel?
mrajwa commentedon Mar 15, 2020
@RDharageswari, kernel has a problem with triggering stream. This is unknown kernel so I can't tell why is it failing, please provide link to the source.
keyonjie commentedon Mar 16, 2020
Hi @xiulipan can we try if we can reproduce this issue with Ubuntu on RVP?
xiulipan commentedon Mar 16, 2020
@keyonjie @RDharageswari @mrajwa confirmed with master(47420dc) + #2405
Kernel thesofproject/linux@0f90705
kconfig https://github.com/thesofproject/kconfig/blob/master/kconfig-sof-default.sh
dmesg
Full DMA trace log is attached.
kwd.txt
12 remaining items
RDharageswari commentedon Mar 18, 2020
Hi @mrajwa
I did check with the firmware on my kernel and still see issues.
First 2 /3 iterations go well and the moment i hit the failure..subsequent capture fails.
I am using the FW built out of https://github.com/mrajwa/sof/tree/tgl_dev_2
For the kernel i am trying to re-test with v5.4.Will update once i test.
command i use:
record -Dhw:0,7 -M -N -c 2 -f S16_LE -r 16000 --buffer-size=68000 tmp.wav -vvv
xiulipan commentedon Mar 18, 2020
@mrajwa @RDharageswari I run more times on my DUT, did not see issue like your said that failed on 3/3.
Below is my 5/5 tests
mengdonglin commentedon Mar 18, 2020
@mrajwa Can you please share a PR for master branch to support KWD on TGL?
mrajwa commentedon Mar 18, 2020
@mengdonglin, sure however we still don't know what is the reason of the issue @RDharageswari is describing.
@RDharageswari, on the beginning you said the second capture fails, now you are saying "First 2 /3 iterations go well..." so something changed recently?
The issue seems to be on kernel side not being able to change states.
I am waiting for your tests results with different kernel.
ranj063 commentedon Mar 18, 2020
@RDharageswari looking at the original logs: It looks like after you start the WoV stream, the DSP enters D0I3 but never exits back to D0I0 when you close the stream. And this is why you see that the transition from D0I3 -> D3 ( 0 to 4 in the logs) is not allowed.
[ 348.303273] sof-audio-pci 0000:00:1f.3: New DSP state 0 substate 1 --> DSP is in D0I3
[ 365.964915] sof-audio-pci 0000:00:1f.3: ipc rx: 0x50050034
[ 365.964918] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x50050034
[ 373.523923] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 7 dir 1 cmd 0
[ 373.523930] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000
[ 373.524110] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000
[ 373.524160] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x240000 successful
[ 373.524167] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000
[ 373.525255] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000
[ 373.525336] sof-audio-pci 0000:00:1f.3: pcm: free stream 7 dir 1
[ 373.525437] sof-audio-pci 0000:00:1f.3: pcm: close stream 7 dir 1
[ 373.525577] sof-audio-pci 0000:00:1f.3: received event 4 for widget DETECT12.0
[ 373.525581] sof-audio-pci 0000:00:1f.3: received event 8 for widget DETECT12.0
[ 373.525587] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000
[ 373.525727] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000
[ 373.525736] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000
[ 373.526774] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000
[ 376.026120] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[ 376.026154] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000
[ 376.026337] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000
[ 376.026432] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[ 376.026437] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[ 376.026440] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[ 376.026500] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at 00000044
[ 376.026507] sof-audio-pci 0000:00:1f.3: Turning i915 HDAC power 0
[ 376.026531] sof-audio-pci 0000:00:1f.3: error: transition from 0 to 4 not allowed --> DSP tries to enter D3 and fails
[ 376.026532] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -22
[ 376.026543] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -22)
ranj063 commentedon Mar 19, 2020
problem root caused to a missing patch in the chrome backport:
"ASoC: SOF: Intel: CNL: add set_power_state() ops" thesofproject/linux@73b51957122d
@sathya-nujella FYI
RDharageswari commentedon Mar 19, 2020
Since we work remotely i was just able to do
arecord
Ctrl+C
multiple times and verify. I couldn't still validate the end to end stack.
As of now using the board from India,will verify the complete functionality with and without S0ix tonight when someone is there at lab and update
ranj063 commentedon Mar 20, 2020
@RDharageswari can you please close this issue once you've verified with the added kernel patch?
RDharageswari commentedon Mar 20, 2020
@ranj063 , I couldnt verify the functionality lsat night due to limited board availability. Will get the board only on Monday.
xiulipan commentedon Mar 23, 2020
I have create sof-tgl-max98373-rt5682.tplg with KWD in #2405
@RDharageswari @emilchudzik could you have a try on the Chrome DUT?
I am using the latest master FW 9da1fce
and sof-dev kernel 9b5b6c2
RDharageswari commentedon Mar 24, 2020
i verified the Wov functionality with the latest master FW 9da1fce
and the missed patch "ASoC: SOF: Intel: CNL: add set_power_state() ops" thesofproject/linux@73b5195
functionality works fine.