Re: [alsa-devel] [BUG] bdw-rt5650 DSP boot timeout

28 Aug 2019

On Tue, Aug 27, 2019 at 5:53 AM Gustaw Lewandowski
gustaw.lewandowski@linux.intel.com wrote:
...
On 8/22/19 5:29 PM, Cezary Rojewski wrote:
...
On 2019-08-20 04:11, Jie, Yang wrote:
...
...
-----Original Message-----
From: Rojewski, Cezary
Sent: Tuesday, August 20, 2019 2:09 AM
To: Jie, Yang yang.jie@intel.com; Jon Flatley
jflat@chromium.org; Pierre-
Louis Bossart pierre-louis.bossart@linux.intel.com
Cc: benzh@chromium.org; alsa-devel@alsa-project.org; Jie Yang
yang.jie@linux.intel.com; Ranjani Sridharan
ranjani.sridharan@linux.intel.com; cujomalainey@chromium.org
Subject: Re: [alsa-devel] [BUG] bdw-rt5650 DSP boot timeout
On 2019-08-19 04:33, Jie, Yang wrote:
...
...
-----Original Message-----
From: Jon Flatley [mailto:jflat@chromium.org]
Sent: Thursday, August 15, 2019 5:25 AM
To: Pierre-Louis Bossart pierre-louis.bossart@linux.intel.com
Cc: Jon Flatley jflat@chromium.org; Jie, Yang yang.jie@intel.com;
benzh@chromium.org; alsa-devel@alsa-project.org; Ranjani Sridharan
ranjani.sridharan@linux.intel.com; cujomalainey@chromium.org; Jie
Yang yang.jie@linux.intel.com
Subject: Re: [alsa-devel] [BUG] bdw-rt5650 DSP boot timeout
On Wed, Aug 14, 2019 at 1:51 PM Pierre-Louis Bossart <pierre-
louis.bossart@linux.intel.com> wrote:
>
>
>> There seems to be an issue when suspending the ALC5650. I think the
>> nondeterministic behavior I was seeing just had to do with whether
>> or not the DSP had yet suspended.
>>
>> I reverted commit 0d2135ecadb0 ("ASoC: Intel: Work around to fix HW
>> D3 potential crash issue") and things started working, including
>> suspend/resume of the DSP. Any ideas for why this may be? I would
>> like to resolve this so I can finish upstreaming the bdw-rt5650
>> machine driver.
>
> Copying Keyon in case he remembers the context.
>
> Reverting a 5yr-old commit with all sorts of clock/power-related
> fixes looks brave, and it's not clear why this would work with the
> rt5677 and not with 5650.
No idea, I was just diffing the register writes looking for
sources of
discrepancy.
...
...
The Chromium OS 3.14 kernel tree that Buddy uses doesn't have this
patch, so I figured what's the worst that could happen?
Hi Jon, sorry about just noticing this thread.
  From the dmesg log, the issue happens at runtime suspend/resume
but not
in boot, am I right(you can disable runtime PM for the device to
confirm that)?
...
My points here are:

the commit 0d2135ecadb0 was suggested by FW team to W/A D3

potential crash issue.
...

it was verified with rt286(Broadwell.c, e.g. Dell XPS) from our

side
only(and may have been checked with rt5677 by Chrome team).
...

please follow sequence in broadwell.c if issue happen at boot time.

If happened at runtime PM from DSP side, we should see it with all
kinds of
machine driver.
...
Could you performing more test and debugging to see what it real
happen
there?
...

we have no reason to remove the commit directly, except

correcting if
some lines are proved wrong. And, as Pierre mentioned, SOF driver is
preferred, as there is no new development effort to support SST
haswell/Broadwell driver here(no platform, no developer, :-( ).
...
Thanks,
~Keyon>
Got to disagree with the last one - no platform, no developer.
We are setting up some BDW/ HSW here to join our happy SKL+ family
in CI.
This is because of /common cleanups which will engulf aDSP project
(hsw/byt) obviously.
Yes, that's true, good to hear that you will add it to CI.
...
These will be tested against the exact same BAT scope as other ADSP
devices.
Code here looks much better, at least compared to /skylake - ain't a
high
threshold though.. Given how outdated all SKL+ fw binaries are (on
upstream
repo) it might even come down simply to fw upgrade.
Most of FW peps who took part in that project are already out.
Although,
found one or two who are willing to help : )
I remember Pawel Piskorski and Marcin Barlik helped me from the FW
side(including explaining about the S0<->S3 sequence), please contact
me offline if needed, I will try to drag for some mails which I got 5
years back.
Thanks,
~Keyon
Please do not name people on official list unless you are 100% sure
about their engagement in linux solutions, which for both individuals
you have listed, is no longer the case. Any recommendations? - you can
provide internally.
Anyway, I've contacted Marcin and once he is available, we will review
the patch together. Note, that I'm a IGK dweller too, so it's highly
probable whomever you had in mind I've either already met or drank a
beer with.
Czarek
...
...
And yes, I'm setting them up with rt286 too. There are some rt56XX
but I'm
unsure if rt5650 is amount them.
Still got some problems with ACPI, but soon two new faces should be
greeting
audio CI bonfire..
Czarek
...
...
>
> Are you using the latest upstream firmware btw? Or the one which
> shipped with the initial device (which could be an issue if the
> protocol
changed).
The firmware I'm loading is: `FW info: type 01, - version: 00.00,
build 77, source commit id: 876ac6906f31a43b6772b23c7c983ce9dcb18a1`.
Hashes the same as the upstream binary.
I don't have a specified codec for testing so I tried with rt286. I was
not able to reproduce this issue. Could you collect logs(dmesg) with
enabled debug like below for S3 or enabled debug during build for
resting reboot scenario?
Sure thing, thanks for taking a look. Here are the verbose logs for
runtime suspend, followed by a failed resume invoked by a volume
change in alsamixer:
[   31.199071] haswell-pcm-audio haswell-pcm-audio: audio dsp runtime suspend
[   31.199074]  System PCM: ASoC: pop wq checking: Playback status:
inactive waiting: yes
[   31.213871] haswell-pcm-audio haswell-pcm-audio: Item[0]
offset[48a890] - size[770e] - source[1]
[   31.221392] haswell-pcm-audio haswell-pcm-audio: Item[1]
offset[491fa0] - size[3c00] - source[1]
[   31.231038] haswell-pcm-audio haswell-pcm-audio: Item[2] offset[0]
- size[2821d] - source[0]
[   31.239561] haswell-pcm-audio haswell-pcm-audio: Item[3]
offset[484000] - size[246c] - source[0]
[   31.248320] haswell-pcm-audio haswell-pcm-audio: Item[4]
offset[486470] - size[750] - source[0]
[   31.256958] haswell-pcm-audio haswell-pcm-audio: Item[5]
offset[486bc0] - size[3cc8] - source[1]
[   31.265866] haswell-pcm-audio haswell-pcm-audio: ipc: got 6 entry
numbers for state 3
[   31.273080] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0xfff8a890 dest 0x7898a890 size 30480
[   31.284532] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   31.289114] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0xfff91fa0 dest 0x78991fa0 size 15360
[   31.299841] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   31.304423] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0xfff86bc0 dest 0x78986bc0 size 15560
[   31.314922] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   31.319610] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:13 at offset 0x68000
[   31.327990] haswell-pcm-audio haswell-pcm-audio: block freed 1:13
at offset 0x68000
[   31.335168] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:12 at offset 0x60000
[   31.343612] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:11 at offset 0x58000
[   31.352013] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:10 at offset 0x50000
[   31.359324] haswell-pcm-audio haswell-pcm-audio: block freed 1:12
at offset 0x60000
[   31.367615] haswell-pcm-audio haswell-pcm-audio: block freed 1:11
at offset 0x58000
[   31.374813] haswell-pcm-audio haswell-pcm-audio: block freed 1:10
at offset 0x50000
[   31.383127] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:9 at offset 0x48000
[   31.390545] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:8 at offset 0x40000
[   31.398998] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:7 at offset 0x38000
[   31.407451] haswell-pcm-audio haswell-pcm-audio: block freed 1:9 at
offset 0x48000
[   31.414662] haswell-pcm-audio haswell-pcm-audio: block freed 1:8 at
offset 0x40000
[   31.421798] haswell-pcm-audio haswell-pcm-audio: block freed 1:7 at
offset 0x38000
[   31.430126] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:6 at offset 0x30000
[   31.437414] haswell-pcm-audio haswell-pcm-audio: block freed 1:6 at
offset 0x30000
[   31.445635] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:5 at offset 0x28000
[   31.453023] haswell-pcm-audio haswell-pcm-audio: block freed 1:5 at
offset 0x28000
[   31.461213] haswell-pcm-audio haswell-pcm-audio: unloading firmware
[   31.467042] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:19 at offset 0x98000
[   31.475473] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:18 at offset 0x90000
[   31.483918] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:17 at offset 0x88000
[   31.491349] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:16 at offset 0x80000
[   31.499747] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:5 at offset 0xc8000
[   31.507051] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:4 at offset 0xc0000
[   31.515467] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:3 at offset 0xb8000
[   31.523840] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:2 at offset 0xb0000
[   31.531165] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:1 at offset 0xa8000
[   31.539648] haswell-pcm-audio haswell-pcm-audio:  disabled block
0:0 at offset 0xa0000
[   31.547066] haswell-pcm-audio haswell-pcm-audio: block freed 1:19
at offset 0x98000
[   31.555378] haswell-pcm-audio haswell-pcm-audio: block freed 1:18
at offset 0x90000
[   31.562625] haswell-pcm-audio haswell-pcm-audio: block freed 1:17
at offset 0x88000
[   31.570883] haswell-pcm-audio haswell-pcm-audio: block freed 1:16
at offset 0x80000
[   31.578273] haswell-pcm-audio haswell-pcm-audio: block freed 0:5 at
offset 0xc8000
[   31.585505] haswell-pcm-audio haswell-pcm-audio: block freed 0:4 at
offset 0xc0000
[   31.593690] haswell-pcm-audio haswell-pcm-audio: block freed 0:3 at
offset 0xb8000
[   31.600950] haswell-pcm-audio haswell-pcm-audio: block freed 0:2 at
offset 0xb0000
[   31.608174] haswell-pcm-audio haswell-pcm-audio: block freed 0:1 at
offset 0xa8000
[   31.616392] haswell-pcm-audio haswell-pcm-audio: block freed 0:0 at
offset 0xa0000
[   31.623651] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:15 at offset 0x78000
[   31.632020] haswell-pcm-audio haswell-pcm-audio:  disabled block
1:14 at offset 0x70000
[   31.640378] haswell-pcm-audio haswell-pcm-audio: block freed 1:15
at offset 0x78000
[   31.647331] haswell-pcm-audio haswell-pcm-audio: block freed 1:14
at offset 0x70000
[   31.655610] haswell-pcm-audio haswell-pcm-audio: HSW_PM dsp runtime suspend
[   31.662756] haswell-pcm-audio haswell-pcm-audio: HSW_PM dsp runtime
suspend exit
[   46.620599] haswell-pcm-audio haswell-pcm-audio: loading audio DSP....
[   46.626523] haswell-pcm-audio haswell-pcm-audio: HSW_PM dsp runtime resume
[   46.644108] haswell-pcm-audio haswell-pcm-audio: HSW_PM dsp runtime
resume exit
[   46.650309] haswell-pcm-audio haswell-pcm-audio: reloading firmware
[   46.657168] haswell-pcm-audio haswell-pcm-audio: header
size=0x3f8c0 modules=0x8 fmt=0xfe size=32
[   46.665766] haswell-pcm-audio haswell-pcm-audio: new module sign
0x$SST\xe0\xf7\x03 size 0x3f7e0 blocks 0xf type 0x0
[   46.675554] haswell-pcm-audio haswell-pcm-audio:  entrypoint 0x0
[   46.681254] haswell-pcm-audio haswell-pcm-audio:  persistent 0x0 scratch 0x0
[   46.688267] haswell-pcm-audio haswell-pcm-audio: module block 0
type 0x0 size 0x10c ==> ram ffff9e2e83000000 offset 0x0
[   46.699535] haswell-pcm-audio haswell-pcm-audio: block request
0x10c bytes at offset 0xa0000 type 0
[   46.708128] haswell-pcm-audio haswell-pcm-audio: block allocated
0:0 at offset 0xa0000
[   46.716458] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:0
at offset 0xa0000
[   46.724754] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x7884004c dest 0xfffa0000 size 268
[   46.733332] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.739020] haswell-pcm-audio haswell-pcm-audio: module block 1
type 0x0 size 0x16c ==> ram ffff9e2e83000000 offset 0x400
[   46.750188] haswell-pcm-audio haswell-pcm-audio: block request
0x16c bytes at offset 0xa0400 type 0
[   46.758830] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840168 dest 0xfffa0400 size 364
[   46.767417] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.773078] haswell-pcm-audio haswell-pcm-audio: module block 2
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x584
[   46.784201] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa0584 type 0
[   46.793740] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x788402e4 dest 0xfffa0584 size 8
[   46.802155] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.807807] haswell-pcm-audio haswell-pcm-audio: module block 3
type 0x0 size 0x4 ==> ram ffff9e2e83000000 offset 0x5bc
[   46.818967] haswell-pcm-audio haswell-pcm-audio: block request 0x4
bytes at offset 0xa05bc type 0
[   46.827488] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x788402fc dest 0xfffa05bc size 4
[   46.835933] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.841564] haswell-pcm-audio haswell-pcm-audio: module block 4
type 0x0 size 0x18 ==> ram ffff9e2e83000000 offset 0x5c0
[   46.852731] haswell-pcm-audio haswell-pcm-audio: block request 0x18
bytes at offset 0xa05c0 type 0
[   46.861296] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840310 dest 0xfffa05c0 size 24
[   46.870764] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.876392] haswell-pcm-audio haswell-pcm-audio: module block 5
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x5fc
[   46.887515] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa05fc type 0
[   46.896036] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840338 dest 0xfffa05fc size 8
[   46.904714] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.910414] haswell-pcm-audio haswell-pcm-audio: module block 6
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x640
[   46.921485] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa0640 type 0
[   46.930032] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840350 dest 0xfffa0640 size 8
[   46.938512] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.944220] haswell-pcm-audio haswell-pcm-audio: module block 7
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x67c
[   46.955296] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa067c type 0
[   46.963832] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840368 dest 0xfffa067c size 8
[   46.972307] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   46.978997] haswell-pcm-audio haswell-pcm-audio: module block 8
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x6b8
[   46.989033] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa06b8 type 0
[   46.998595] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840380 dest 0xfffa06b8 size 8
[   47.007021] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.012683] haswell-pcm-audio haswell-pcm-audio: module block 9
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x6f4
[   47.023859] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa06f4 type 0
[   47.032373] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78840398 dest 0xfffa06f4 size 8
[   47.040819] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.046459] haswell-pcm-audio haswell-pcm-audio: module block 10
type 0x0 size 0x8 ==> ram ffff9e2e83000000 offset 0x730
[   47.057604] haswell-pcm-audio haswell-pcm-audio: block request 0x8
bytes at offset 0xa0730 type 0
[   47.067175] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x788403b0 dest 0xfffa0730 size 8
[   47.075556] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.081219] haswell-pcm-audio haswell-pcm-audio: module block 11
type 0x0 size 0x4 ==> ram ffff9e2e83000000 offset 0x76c
[   47.092354] haswell-pcm-audio haswell-pcm-audio: block request 0x4
bytes at offset 0xa076c type 0
[   47.100916] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x788403c8 dest 0xfffa076c size 4
[   47.109348] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.114985] haswell-pcm-audio haswell-pcm-audio: module block 12
type 0x0 size 0x27a78 ==> ram ffff9e2e83000000 offset 0x7a8
[   47.126184] haswell-pcm-audio haswell-pcm-audio: block request
0x27a78 bytes at offset 0xa07a8 type 0
[   47.135920] haswell-pcm-audio haswell-pcm-audio: block allocated
0:1 at offset 0xa8000
[   47.144179] haswell-pcm-audio haswell-pcm-audio: block allocated
0:2 at offset 0xb0000
[   47.151399] haswell-pcm-audio haswell-pcm-audio: block allocated
0:3 at offset 0xb8000
[   47.159674] haswell-pcm-audio haswell-pcm-audio: block allocated
0:4 at offset 0xc0000
[   47.168081] haswell-pcm-audio haswell-pcm-audio: block allocated
0:5 at offset 0xc8000
[   47.175318] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:5
at offset 0xc8000
[   47.183609] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:4
at offset 0xc0000
[   47.191876] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:3
at offset 0xb8000
[   47.199170] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:2
at offset 0xb0000
[   47.207478] haswell-pcm-audio haswell-pcm-audio:  enabled block 0:1
at offset 0xa8000
[   47.214755] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x788403dc dest 0xfffa07a8 size 162424
[   47.230081] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.234656] haswell-pcm-audio haswell-pcm-audio: module block 13
type 0x1 size 0x16ba8 ==> ram ffff9e2e83000000 offset 0x84000
[   47.245946] haswell-pcm-audio haswell-pcm-audio: block request
0x16ba8 bytes at offset 0x84000 type 1
[   47.255645] haswell-pcm-audio haswell-pcm-audio: block allocated
1:17 at offset 0x88000
[   47.263956] haswell-pcm-audio haswell-pcm-audio: block allocated
1:18 at offset 0x90000
[   47.272197] haswell-pcm-audio haswell-pcm-audio: block allocated
1:19 at offset 0x98000
[   47.279482] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:19 at offset 0x98000
[   47.287816] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:18 at offset 0x90000
[   47.296113] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:17 at offset 0x88000
[   47.303481] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:16 at offset 0x80000
[   47.311817] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78867e64 dest 0xfff84000 size 93096
[   47.323545] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.328119] haswell-pcm-audio haswell-pcm-audio: module block 14
type 0x1 size 0xe00 ==> ram ffff9e2e83000000 offset 0x9abb0
[   47.339397] haswell-pcm-audio haswell-pcm-audio: block request
0xe00 bytes at offset 0x9abb0 type 1
[   47.349018] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x7887ea1c dest 0xfff9abb0 size 3584
[   47.357597] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.363255] haswell-pcm-audio haswell-pcm-audio: new module sign
0x$SST size 0x0 blocks 0x0 type 0xd
[   47.372935] haswell-pcm-audio haswell-pcm-audio:  entrypoint 0x0
[   47.378643] haswell-pcm-audio haswell-pcm-audio:  persistent
0x16800 scratch 0xdc00
[   47.385780] haswell-pcm-audio haswell-pcm-audio: new module sign
0x$SST size 0x0 blocks 0x0 type 0xb
[   47.395420] haswell-pcm-audio haswell-pcm-audio:  entrypoint 0x0
[   47.401135] haswell-pcm-audio haswell-pcm-audio:  persistent 0x3800
scratch 0x0
[   47.409266] haswell-pcm-audio haswell-pcm-audio: new module sign
0x$SST size 0x0 blocks 0x0 type 0xa
[   47.417922] haswell-pcm-audio haswell-pcm-audio:  entrypoint 0x0
[   47.423617] haswell-pcm-audio haswell-pcm-audio:  persistent 0x4000
scratch 0x0
[   47.431742] haswell-pcm-audio haswell-pcm-audio: new module sign
0x$SST size 0x0 blocks 0x0 type 0xc
[   47.440366] haswell-pcm-audio haswell-pcm-audio:  entrypoint 0x0
[   47.447127] haswell-pcm-audio haswell-pcm-audio:  persistent 0x3000
scratch 0x0
[   47.454274] haswell-pcm-audio haswell-pcm-audio: module 12 scratch
req 0x0 bytes
[   47.461376] haswell-pcm-audio haswell-pcm-audio: module 10 scratch
req 0x0 bytes
[   47.468433] haswell-pcm-audio haswell-pcm-audio: module 11 scratch
req 0x0 bytes
[   47.476576] haswell-pcm-audio haswell-pcm-audio: module 13 scratch
req 0xdc00 bytes
[   47.483771] haswell-pcm-audio haswell-pcm-audio: module 0 scratch
req 0x0 bytes
[   47.490854] haswell-pcm-audio haswell-pcm-audio: scratch buffer
required is 0xdc00 bytes
[   47.499248] haswell-pcm-audio haswell-pcm-audio: allocating scratch blocks
[   47.506228] haswell-pcm-audio haswell-pcm-audio: block request
0xdc00 bytes type 1 at 0xffff0a10
[   47.515784] haswell-pcm-audio haswell-pcm-audio: block allocated
1:15 at offset 0x78000
[   47.523046] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:15 at offset 0x78000
[   47.531470] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:14 at offset 0x70000
[   47.539814] haswell-pcm-audio haswell-pcm-audio: persistent fixed
block request 0x3800 bytes type 1 offset 0x68000
[   47.549754] haswell-pcm-audio haswell-pcm-audio: block allocated
1:13 at offset 0x68000
[   47.558081] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:13 at offset 0x68000
[   47.565419] haswell-pcm-audio haswell-pcm-audio: runtime id 11
created for module 11
[   47.573707] haswell-pcm-audio haswell-pcm-audio: persistent fixed
block request 0x16800 bytes type 1 offset 0x50000
[   47.583680] haswell-pcm-audio haswell-pcm-audio: block allocated
1:11 at offset 0x58000
[   47.591932] haswell-pcm-audio haswell-pcm-audio: block allocated
1:12 at offset 0x60000
[   47.600249] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:12 at offset 0x60000
[   47.607598] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:11 at offset 0x58000
[   47.615918] haswell-pcm-audio haswell-pcm-audio:  enabled block
1:10 at offset 0x50000
[   47.624385] haswell-pcm-audio haswell-pcm-audio: runtime id 13
created for module 13
[   47.631604] haswell-pcm-audio haswell-pcm-audio: persistent fixed
block request 0x16800 bytes type 1 offset 0x38000
[   47.642587] haswell-pcm-audio haswell-pcm-audio: block allocated
1:8 at offset 0x40000
[   47.649916] haswell-pcm-audio haswell-pcm-audio: block allocated
1:9 at offset 0x48000
[   47.658208] haswell-pcm-audio haswell-pcm-audio:  enabled block 1:9
at offset 0x48000
[   47.666537] haswell-pcm-audio haswell-pcm-audio:  enabled block 1:8
at offset 0x40000
[   47.673771] haswell-pcm-audio haswell-pcm-audio:  enabled block 1:7
at offset 0x38000
[   47.682049] haswell-pcm-audio haswell-pcm-audio: runtime id 13
created for module 13
[   47.689239] haswell-pcm-audio haswell-pcm-audio: persistent fixed
block request 0x3000 bytes type 1 offset 0x30000
[   47.700471] haswell-pcm-audio haswell-pcm-audio: block allocated
1:6 at offset 0x30000
[   47.707726] haswell-pcm-audio haswell-pcm-audio:  enabled block 1:6
at offset 0x30000
[   47.716058] haswell-pcm-audio haswell-pcm-audio: runtime id 12
created for module 12
[   47.723207] haswell-pcm-audio haswell-pcm-audio: persistent fixed
block request 0x4000 bytes type 1 offset 0x28000
[   47.734246] haswell-pcm-audio haswell-pcm-audio: block allocated
1:5 at offset 0x28000
[   47.741490] haswell-pcm-audio haswell-pcm-audio:  enabled block 1:5
at offset 0x28000
[   47.749799] haswell-pcm-audio haswell-pcm-audio: runtime id 10
created for module 10
[   47.758050] haswell-pcm-audio haswell-pcm-audio: audio dsp runtime resume
[   47.763959] haswell-pcm-audio haswell-pcm-audio: restoring audio DSP....
[   47.770944] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x7898a890 dest 0xfff8a890 size 30480
[   47.781581] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.786154] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78991fa0 dest 0xfff91fa0 size 15360
[   47.796266] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   47.800849] haswell-pcm-audio haswell-pcm-audio: DMA: src:
0x78986bc0 dest 0xfff86bc0 size 15560
[   47.810971] haswell-pcm-audio haswell-pcm-audio: DMA: callback
[   48.119068] haswell-pcm-audio haswell-pcm-audio: error: audio DSP
boot timeout IPCD 0x0 IPCX 0x0
[   49.535060] haswell-pcm-audio haswell-pcm-audio: ipc: --message
timeout-- ipcx 0x86371000 isr 0x00000000 ipcd 0x00000000 imrx
0x7fff0000
[   49.546866] haswell-pcm-audio haswell-pcm-audio: error: set mixer
volume failed
[   49.553979] haswell-pcm-audio haswell-pcm-audio: ipc_tx_msgs dsp busy
[   49.855054] haswell-pcm-audio haswell-pcm-audio: ipc: --message
timeout-- ipcx 0x86371000 isr 0x00000000 ipcd 0x00000000 imrx
0x7fff0000
[   49.868456] haswell-pcm-audio haswell-pcm-audio: error: set mixer
volume failed
[   49.874794] haswell-pcm-audio haswell-pcm-audio: ipc_tx_msgs dsp busy
[   50.183057] haswell-pcm-audio haswell-pcm-audio: ipc: --message
timeout-- ipcx 0x86371000 isr 0x00000000 ipcd 0x00000000 imrx
0x7fff0000
[   50.194886] haswell-pcm-audio haswell-pcm-audio: error: set mixer
volume failed
...
echo -n 'module  snd* +p' |  dd of=/sys/kernel/debug/dynamic_debug/control
Since enabling debug decreases problem occurrence ratio please also
check below change:

--- a/sound/soc/intel/haswell/sst-haswell-ipc.c
+++ b/sound/soc/intel/haswell/sst-haswell-ipc.c
@@ -81,7 +81,7 @@
/* IPC message timeout (msecs) */
  #define IPC_TIMEOUT_MSECS      300
-#define IPC_BOOT_MSECS         200
+#define IPC_BOOT_MSECS         300
Gustaw

    