[BUG][CML] ipc timed out for '0x30030000: GLB_TPLG_MSG: COMP_CONNECT'

[ClarexZhou]

Summary:
'ipc timed out for for'0x30030000: GLB_TPLG_MSG: COMP_CONNECT' after plug in/out headset.

To reproduce
Do headset plug in/out several times.

Actual result
error: ipc timed out for '0x30030000: GLB_TPLG_MSG: COMP_CONNECT'

Reproduce rate: 1%

Environment
Rander UCM https://github.com/RanderWang/intel-UCM  
Kernel repo：c99938c https://github.com/thesofproject/linux/tree/release/sof-v5.0
Firmware repo: 05d4e19 https://github.com/thesofproject/sof/commits/master |  
Topology: https://github.com/thesofproject/sof/commits/master . Same as above SOF repo
file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplghttps://thesofproject.github.io/latest/developer_guides/debugability/logger/index.html

dmesg

[ 1583.936866] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 1583.936870] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 1583.936946] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 1583.936951] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937070] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937074] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937165] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937170] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937274] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1583.937278] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 1584.241624] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30030000 size 16
[ 1584.241638] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 1584.241867] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 1584.241872] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 1584.241878] sof-audio-pci 0000:00:1f.3: error: failed to load route sink  control none source 
[ 1584.241881] sof-audio-pci 0000:00:1f.3: error: failed to restore pipeline after resume -110
[ 1584.241900] HDMI HDA Codec ehdaudio0D2: No connections found for pin:port 5:0
[ 1584.241909] sof-audio-pci 0000:00:1f.3: pcm: open stream 3 dir 0
[ 1584.241911] sof-audio-pci 0000:00:1f.3: error: pcm open failed to resume -22
[ 1584.241915] sof-audio-pci 0000:00:1f.3: ASoC: can't open component 0000:00:1f.3: -22
[ 1584.241919]  HDMI1: ASoC: failed to start FE -22
[ 1584.438605] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 1584.438637] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 1588.739566] HDMI HDA Codec ehdaudio0D2: No connections found for pin:port 5:0
[ 1588.739570] sof-audio-pci 0000:00:1f.3: pcm: open stream 3 dir 0
[ 1588.739571] sof-audio-pci 0000:00:1f.3: error: pcm open failed to resume -22
[ 1588.739574] sof-audio-pci 0000:00:1f.3: ASoC: can't open component 0000:00:1f.3: -22
[ 1588.739575]  HDMI1: ASoC: failed to start FE -22

ipcTimeOutAfterPlug.log
ipcTimeOutAfterPlugLogger.log

[lyakh]

A suspected triplicate of thesofproject/linux#876 and #1342

[ranj063]

@mengdonglin can this be retested now that @lyakh patch to fix the IPC race is merged?

[lgirdwood]

@mengdonglin also needs retested with trace disabled too. i.e. with @lyakh patch then with trace disabled, then both trace disabled and lyakh.

[wenqingfu]

mark as fixed by thesofproject/linux#943, please reopen if reproduced.