Skip to content

mixin-mixout: fix a firmware exception - #6133

Merged
lgirdwood merged 1 commit into
thesofproject:mainfrom
lyakh:mixin
Aug 12, 2022
Merged

mixin-mixout: fix a firmware exception#6133
lgirdwood merged 1 commit into
thesofproject:mainfrom
lyakh:mixin

Conversation

@lyakh

@lyakhlyakh commented Aug 11, 2022

Copy link
Copy Markdown
Collaborator

find_mixout_source_info() can return NULL, always check return value before dereferencing.

Partially fixes#6118 - no more firmware crash, but the error has to be fixed too.

@lyakh
mixin-mixout: fix a firmware exception
08cb2b4
find_mixout_source_info() can return NULL, always check return value
before dereferencing.
Signed-off-by: Guennadi Liakhovetski <guennadi.liakhovetski@linux.intel.com>
@lyakh
lyakh requested review from serhiy-katsyuba-intel and removed request for dbaluta, lbetlej, lgirdwood, mmaka1 and plbossartAugust 12, 2022 06:25
@ujfalusi

ujfalusi commented Aug 12, 2022

Copy link
Copy Markdown
Contributor

It is fixing the firmware crash, but the playback just stall as the error is not propagating back to host for some reason.

@ujfalusiujfalusi mentioned this pull request Aug 12, 2022
Closed
@lyakh

lyakh commented Aug 12, 2022

Copy link
Copy Markdown
CollaboratorAuthor

@mwasko@marcinszkudlinski@ktrzcinx you probably want to pull this and I'll try to fix the underlying binding problem too

@lyakh

lyakh commented Aug 12, 2022

Copy link
Copy Markdown
CollaboratorAuthor

It is fixing the firmware crash, but the playback just stall as the error is not propagating back to host for some reason.

@ujfalusi with this version or with a modified one with continue instead of return? With this version the error is propagating for me:

Aug 12 15:22:57 sof-UPX-TGL01 kernel: [1347] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13020003|0x0: GLB_SET_PIPELINE_STATE
Aug 12 15:22:57 sof-UPX-TGL01 kernel: [1319] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000006|0x0: GLB_SET_PIPELINE_STATE
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 6 - Unknown error while processing the request
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x13020003|0x0
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_dai_trigger on Analog CPU DAI: -22
Aug 12 15:22:57 sof-UPX-TGL01 kernel: HDA Analog: ASoC: dpcm_be_dai_trigger() failed at Analog Playback and Capture (-22)
Aug 12 15:22:57 sof-UPX-TGL01 kernel: HDA Analog: ASoC: trigger FE cmd: 0 failed: -22

lgirdwood
lgirdwood approved these changes Aug 12, 2022
View reviewed changes

@lgirdwoodlgirdwood left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@mwasko@marcinszkudlinski fyi - you may need this fix.

@lgirdwood
lgirdwood merged commit 167e62d into thesofproject:mainAug 12, 2022
@lyakh
lyakh deleted the mixin branch August 12, 2022 14:34
@ujfalusi

ujfalusi commented Aug 15, 2022

Copy link
Copy Markdown
Contributor

It is fixing the firmware crash, but the playback just stall as the error is not propagating back to host for some reason.

@ujfalusi with this version or with a modified one with continue instead of return? With this version the error is propagating for me:

Aug 12 15:22:57 sof-UPX-TGL01 kernel: [1347] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13020003|0x0: GLB_SET_PIPELINE_STATE
Aug 12 15:22:57 sof-UPX-TGL01 kernel: [1319] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000006|0x0: GLB_SET_PIPELINE_STATE
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 6 - Unknown error while processing the request
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x13020003|0x0
Aug 12 15:22:57 sof-UPX-TGL01 kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_dai_trigger on Analog CPU DAI: -22
Aug 12 15:22:57 sof-UPX-TGL01 kernel: HDA Analog: ASoC: dpcm_be_dai_trigger() failed at Analog Playback and Capture (-22)
Aug 12 15:22:57 sof-UPX-TGL01 kernel: HDA Analog: ASoC: trigger FE cmd: 0 failed: -22

@lyakh, this version (re-tested SOF HEAD):

aplay -i -Dplughw:0,0 /home/sof/work/samples/came_back_haunted_48K_24bit.wav
[ 46.889907] snd_sof:sof_pcm_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[ 46.890247] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: FW Poll Status: reg[0x160]=0x14001e successful
[ 46.890249] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 1 state 3
[ 46.890251] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13010003|0x0: GLB_SET_PIPELINE_STATE
[ 46.890324] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 46.890331] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13010003|0x0: GLB_SET_PIPELINE_STATE
[ 46.890333] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 1 state 4
[ 46.890335] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13010004|0x0: GLB_SET_PIPELINE_STATE
[ 46.890822] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 46.890827] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13010004|0x0: GLB_SET_PIPELINE_STATE
[ 46.890828] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 2 state 3
[ 46.890829] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13020003|0x0: GLB_SET_PIPELINE_STATE
[ 46.890892] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 46.890896] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13020003|0x0: GLB_SET_PIPELINE_STATE
[ 46.890897] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 2 state 4
[ 46.890898] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13020004|0x0: GLB_SET_PIPELINE_STATE
[ 46.891783] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000000|0x0: GLB_SET_PIPELINE_STATE
[ 46.891796] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x13020004|0x0: GLB_SET_PIPELINE_STATE
[ 46.891849] snd_sof_intel_hda_common:ipc4_hda_dai_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: cmd=1 dai Analog CPU DAI direction 0

Using cavs-mixin-mixout-hda.tplg on upx-i11:

aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: sofhdadsp [sof-hda-dsp], device 0: HDA Analog (*) []
Subdevices: 0/1
Subdevice #0: subdevice #0
card 0: sofhdadsp [sof-hda-dsp], device 5: HDMI1 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofhdadsp [sof-hda-dsp], device 6: HDMI2 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: sofhdadsp [sof-hda-dsp], device 7: HDMI3 (*) []
Subdevices: 1/1
Subdevice #0: subdevice #0

@ujfalusi

ujfalusi commented Aug 15, 2022

Copy link
Copy Markdown
Contributor

But when terminating aplay I see that IPCs are failing:

[ 593.140210] snd_sof_intel_hda_common:ipc4_hda_dai_trigger: sof-audio-pci-intel-tgl 0000:00:1f.3: cmd=0 dai Analog CPU DAI direction 0
[ 593.140218] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 2 state 3
[ 593.140226] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13020003|0x0: GLB_SET_PIPELINE_STATE
[ 593.150708] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000006|0x0: GLB_SET_PIPELINE_STATE
[ 593.150714] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 6 - Unknown error while processing the request
[ 593.150732] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x13020003|0x0
[ 593.150736] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at soc_dai_trigger on Analog CPU DAI: -22
[ 593.150740] HDA Analog: ASoC: dpcm_be_dai_trigger() failed at Analog Playback and Capture (-22)
[ 593.150743] HDA Analog: ASoC: trigger FE cmd: 0 failed: -22
[ 593.150999] snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 0 dir 0
[ 593.151004] snd_sof:sof_ipc4_set_pipeline_state: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc4 set pipeline 1 state 3
[ 593.151008] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x13010003|0x0: GLB_SET_PIPELINE_STATE
[ 593.161404] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x33000006|0x0: GLB_SET_PIPELINE_STATE
[ 593.161409] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 6 - Unknown error while processing the request
[ 593.161424] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x13010003|0x0
[ 593.161428] sof-audio-pci-intel-tgl 0000:00:1f.3: failed to pause pipeline 1
[ 593.161449] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules copier.host.1.1 -> gain.1.1
[ 593.161454] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46000004|0x6: MOD_UNBIND
[ 593.161536] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x6: MOD_UNBIND
[ 593.161551] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000004|0x6: MOD_UNBIND
[ 593.161558] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.host.1.1 freed
[ 593.161560] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules gain.1.1 -> mixin.1.1
[ 593.161564] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46000006|0x2: MOD_UNBIND
[ 593.161639] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x2: MOD_UNBIND
[ 593.161652] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000006|0x2: MOD_UNBIND
[ 593.161656] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.1.1 freed
[ 593.161658] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules mixin.1.1 -> mixout.2.1
[ 593.161662] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46000002|0x3: MOD_UNBIND
[ 593.161752] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x3: MOD_UNBIND
[ 593.161766] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000002|0x3: MOD_UNBIND
[ 593.161772] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x12010000|0x0: GLB_DELETE_PIPELINE
[ 593.161918] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x3200000c|0x0: GLB_DELETE_PIPELINE
[ 593.161921] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 12 - Required resource is in invalid state
[ 593.161934] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x12010000|0x0
[ 593.161936] sof-audio-pci-intel-tgl 0000:00:1f.3: failed to free pipeline widget pipeline.1
[ 593.161938] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules mixout.2.1 -> gain.2.1
[ 593.161944] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46000003|0x10006: MOD_UNBIND
[ 593.162022] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x10006: MOD_UNBIND
[ 593.162035] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000003|0x10006: MOD_UNBIND
[ 593.162039] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget mixout.2.1 freed
[ 593.162041] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules gain.2.1 -> copier.HDA.2.1
[ 593.162044] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x46010006|0x10004: MOD_UNBIND
[ 593.162122] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x10004: MOD_UNBIND
[ 593.162135] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46010006|0x10004: MOD_UNBIND
[ 593.162138] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.2.1 freed
[ 593.162142] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x12020000|0x0: GLB_DELETE_PIPELINE
[ 593.162311] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x3200000c|0x0: GLB_DELETE_PIPELINE
[ 593.162315] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 12 - Required resource is in invalid state
[ 593.162333] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x12020000|0x0
[ 593.162337] sof-audio-pci-intel-tgl 0000:00:1f.3: failed to free pipeline widget pipeline.2
[ 593.162341] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to free connected widgets
[ 593.162362] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_free on 0000:00:1f.3: -22
[ 593.162508] snd_hda_codec:__snd_hda_codec_cleanup_stream: snd_hda_codec_realtek ehdaudio0D0: hda_codec_cleanup_stream: NID=0x2
[ 593.162522] snd_sof:sof_pcm_close: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 0 dir 0
[ 595.672446] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx : 0x47000000|0x0: MOD_SET_DX [data size: 8]
[ 595.672555] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x67000004|0x0: MOD_SET_DX
[ 595.672557] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 4 - The system or resource is busy
[ 595.672575] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x47000000|0x0
[ 595.672576] sof-audio-pci-intel-tgl 0000:00:1f.3: ctx_save IPC error during suspend: -16

The FW log contains this:

:00:00.000,000] <inf> dma_intel_adsp_gpdma: intel_adsp_gpdma_init: dma dma@7d000 initialized
[00:00:00.000,000] <inf> dma_intel_adsp_gpdma: intel_adsp_gpdma_init: dma dma@7c000 initialized
*** Booting Zephyr OS build zephyr-v3.1.0-3042-g8e55e59c5917 ***
[00:00:00.000,000] <inf> main: SOF on intel_adsp_cavs25
543981 zephyr_ll_scheduler_init(): unsupported domain 2
[00:00:00.000,000] <inf> main: SOF initialized
559470 zephyr_ll_scheduler_init(): unsupported domain 2
7068327 failed to find dai comp or sink pipeline not running.
7070832 failed to find dai comp or sink pipeline not running.
7107788 No source info
7108391 pipeline_copy(): ret = -22, start->comp.id = 131072, dir = 1
7109079 pipeline_task(): xrun recovery failed! pipeline is stopped.
7145078 No source info
7145662 pipeline_copy(): ret = -22, start->comp.id = 262145, dir = 1
7146351 pipeline_task(): xrun recovery failed! pipeline is stopped.
20983454173 failed to wait schedule thread
20983454974 ipc4: failed to send delayed reply
20983866358 failed to wait schedule thread
20983866950 ipc4: failed to send delayed reply
20983885024 ipc_comp_free(): comp id: 262144 state is 5 cannot be freed
20983885775 ipc_pipeline_free(): module free () failed
20983886393 ipc4: 0 failed err 12
20983899417 ipc_comp_free(): comp id: 196608 state is 5 cannot be freed
20983900153 ipc_pipeline_free(): module free () failed
20983900766 ipc4: 0 failed err 12
21080293771 some pipelines are still active
21080294582 ipc4: 1 failed err 4

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@dbalutadbalutadbaluta approved these changes
@lgirdwoodlgirdwoodlgirdwood approved these changes
@serhiy-katsyuba-intelserhiy-katsyuba-intelserhiy-katsyuba-intel approved these changes

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

[BUG][IPC4] ipc timed out for 0x13020004|0x0 GLB_SET_PIPELINE_STATE on TGLU_UP_HDA_IPC4ZPH

5 participants

@lyakh@ujfalusi@dbaluta@lgirdwood@serhiy-katsyuba-intel