Skip to content

[TEST] Fix suspend/resume with SoundWire - #1314

Closed
plbossart wants to merge 4 commits into
thesofproject:integration/soundwire-intelfrom
plbossart:integration/soundwire-20191014
Closed

plbossart wants to merge 4 commits into
thesofproject:integration/soundwire-intelfrom
plbossart:integration/soundwire-20191014

Conversation

@plbossart

Copy link
Copy Markdown
Member

This PR is based on @bardliao 's fix/soundwire-suspend-aplay-resume branch, but with minor differences

A) we always deprepare on trigger_suspend.
B) we don't test for the stream state in the .prepare callback, but instead use a status flag.

I believe this is more future-proof, testing the stream state may be problematic when we move to the multi-cpu DAIs.

I can resume playback and solve issue #1311 with this PR, but I still have IO timeout issues that are likely due to the codec state machine. logs attached
dmesg_io_timeouts.log

Note that the last commit is just to help visualize the transitions, it'll be removed when we agree on the solution.

The state machine is incorrect, we need to be able to go from
STREAM_DEPREPARED to STREAM_PREPARED, e.g. to deal with underflows or
suspend/resume, where the .prepare() callback is called after a
.trigger (STOP/SUSPEND).

Add checks for prepare, enable, disable, deprepared to make sure the
client is notified of illegal state machine transitions.

Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
ALSA does not have a deprepare step, and calling
sdw_deprepare_stream() in the .hw_free step raises all kinds of
issues, e.g. with aplay not resuming after system suspend since the
stream is already configured.

It's just better to call sdw_deprepare_stream() for all transfer
stops, and require that the .prepare() callback be used to reconfigure
the stream.

Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Comment thread drivers/soundwire/intel.c Resolved
@plbossart

plbossart commented Oct 14, 2019 via email

Copy link
Copy Markdown
Member Author

bardliao and others added 2 commits October 14, 2019 15:42
…tion

The .prepare() callback is invoked for underflows or during the system
resume transition. In the latter case, the context for the ALH PDIs is
lost, and the DSP is not initialized properly either.

Keep track of the TRIGGER_SUSPEND transition with a boolean flag, and
use it during the .prepare step to check if the ALH PDIs need to be
reconfigured.

Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com>
Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
@plbossart
plbossart force-pushed the integration/soundwire-20191014 branch from b715326 to 43c19f4 Compare October 14, 2019 20:45
@plbossart
plbossart requested a review from ranj063 October 14, 2019 20:46
@bardliao

Copy link
Copy Markdown
Collaborator

@plbossart .prepare will not be trigger on SNDRV_PCM_TRIGGER_PAUSE_PUSH/SNDRV_PCM_TRIGGER_PAUSE_RELEASE cycle. So, if we call sdw_deprepare_stream() in the SNDRV_PCM_TRIGGER_PAUSE_PUSH case, the stream status will be DEPREPARED and we will see sdw_enable_stream: SDW0 Pin2-Playback: inconsistent state state 5 when SNDRV_PCM_TRIGGER_PAUSE_RELEASE is triggered.
We can test it with aplay -Dhw:0,0 test.wav -vv -i command, and press SPACE key to pulse/release it.

error log

[ 1117.779554] SDW0-Playback: ASoC: trigger BE SDW0-Playback cmd 4
[ 1117.779558] intel-sdw sdw-master-0: intel_trigger: SDW0 Pin2: start
[ 1117.779560] sdw_enable_stream: SDW0 Pin2-Playback: start
[ 1117.779569] sdw_enable_stream: SDW0 Pin2-Playback: inconsistent state state 5
[ 1117.779570] sdw_enable_stream: SDW0 Pin2-Playback: done
[ 1117.779572] intel-sdw sdw-master-0: intel_trigger trigger 4 failed: -22
[ 1117.779574] intel-sdw sdw-master-0: intel_trigger: SDW0 Pin2: done
[ 1117.779575] SDW0-Playback: ASoC: trigger BE failed -22

The other reason why it is better to do deprepare in hw_free() is that disable -> enable is enough and we don't need to do disable -> deprepare -> prepare -> enable in the pulse/resume case.
What do you think?

Comment thread drivers/soundwire/intel.c
params_data.link_id = link_id;
params_data.alh_stream_id = alh_stream_id;

sdw->hw_params = hw_params;

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

@bardliao why not move "sdw->hw_params = hw_params;" to intel_hw_params, like

sdw->pdi = pdi;
sdw->hw_params = hw_params;

I know: intel_params_stream is invoked in intel_prepare, but this line of code do nothing for this case.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

@RanderWang Good suggestion. Thanks.

@YvonneYang2

Copy link
Copy Markdown

Test it on icl rt700 rvp and icl 3-in-1 rvp with this PR, found two regressions as below:

  1. system boot up with pulse audio on, soundwire pm status is always active, and dmesg log shows:
Dmesg
[    5.177508] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[    5.177614] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[    5.177616] intel-sdw sdw-master-0: bps not matching, stream:]���
[    5.177618] intel-sdw sdw-master-0: add master to stream failed:-22
[    5.177619] intel-sdw sdw-master-0: intel_hw_params: SDW0 Pin2: done
[    5.177620] intel-sdw sdw-master-0: ASoC: can't set SDW0 Pin2 hw params: -22
[    5.177625] BUG: unable to handle page fault for address: fffffffffffffff0
[    5.177626] #PF: supervisor read access in kernel mode
[    5.177627] #PF: error_code(0x0000) - not-present page
[    5.177627] PGD 42c60c067 P4D 42c60c067 PUD 42c60e067 PMD 0 
[    5.177630] Oops: 0000 [#1] SMP NOPTI
[    5.177632] CPU: 5 PID: 724 Comm: pulseaudio Not tainted 5.4.0-rc2-sdw-validation-20191015-sdw-0-bd65652 #rc2
[    5.177633] Hardware name: Intel Corporation Ice Lake Client Platform/IceLake U DDR4 SODIMM PD RVP TLC, BIOS ICLSFWR1.R00.3121.A00.1903190527 03/19/2019
[    5.177637] RIP: 0010:sdw_slave_port_release.isra.7+0x6d/0xf0 [soundwire_bus]
[    5.177638] Code: de 48 8b 54 24 08 48 8b 42 18 4c 8d 6a 18 49 39 c5 4c 8d 78 f0 75 0f eb 67 49 8b 47 10 49 39 c5 4c 8d 78 f0 74 5a 48 8b 04 24 <49> 39 07 75 ea 49 8b 4f 20 49 8d 5f 20 48 8b 01 48 39 cb 48 8d 79
[    5.177639] RSP: 0018:ffffaba440bf39c8 EFLAGS: 00010286
[    5.177641] RAX: ffff8a621a0a4400 RBX: ffff8a621a0a4400 RCX: 0000000000000000
[    5.177641] RDX: ffff8a621c7de248 RSI: ffff8a62172e0920 RDI: ffff8a621a0a4400
[    5.177642] RBP: dead000000000122 R08: 0000000000000ada R09: 000000000000004f
[    5.177643] R10: 0000000000000004 R11: ffffaba440bf3760 R12: dead000000000100
[    5.177644] R13: ffff8a621c7de260 R14: 0000000000000000 R15: fffffffffffffff0
[    5.177645] FS:  00007faa911e1500(0000) GS:ffff8a621ff40000(0000) knlGS:0000000000000000
[    5.177646] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    5.177647] CR2: fffffffffffffff0 CR3: 0000000497a2a001 CR4: 0000000000760ee0
[    5.177648] PKRU: 55555554
[    5.177648] Call Trace:
[    5.177652]  sdw_stream_remove_slave+0x23/0x50 [soundwire_bus]
[    5.177655]  rt711_pcm_hw_free+0x2c/0x40 [snd_soc_rt711]
[    5.177660]  soc_pcm_hw_params+0x442/0x630 [snd_soc_core]
[    5.177665]  dpcm_be_dai_hw_params+0x19c/0x2e0 [snd_soc_core]
[    5.177668]  dpcm_fe_dai_hw_params+0xbf/0x1b0 [snd_soc_core]
[    5.177672]  snd_pcm_hw_params+0x224/0x5d0 [snd_pcm]
[    5.177675]  ? _cond_resched+0x10/0x40
[    5.177677]  ? __kmalloc_track_caller+0x185/0x200
[    5.177679]  snd_pcm_common_ioctl+0x19e/0xc90 [snd_pcm]
[    5.177681]  snd_pcm_ioctl+0x25/0x30 [snd_pcm]
[    5.177683]  do_vfs_ioctl+0x9f/0x620
[    5.177685]  ksys_ioctl+0x6b/0x80
[    5.177686]  __x64_sys_ioctl+0x11/0x20
[    5.177687]  do_syscall_64+0x43/0x120
[    5.177689]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    5.177691] RIP: 0033:0x7faa8f2e25d7
[    5.177692] Code: b3 66 90 48 8b 05 b1 48 2d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 81 48 2d 00 f7 d8 64 89 01 48
[    5.177693] RSP: 002b:00007ffde1957488 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[    5.177694] RAX: ffffffffffffffda RBX: 0000559c126bce10 RCX: 00007faa8f2e25d7
[    5.177694] RDX: 00007ffde1957590 RSI: 00000000c2604111 RDI: 0000000000000020
[    5.177695] RBP: 00007ffde1957590 R08: 0000559c126bd080 R09: 0000000000000010
[    5.177696] R10: 0000000000000001 R11: 0000000000000246 R12: 0000559c126bce80
[    5.177696] R13: 00007ffde19574b4 R14: 00007ffde1957e23 R15: 00007ffde1957590
[    5.177698] Modules linked in: snd_soc_sdw_rt711_rt1308_rt715 snd_soc_rt700 snd_soc_rt711 snd_soc_rt1308_sdw snd_soc_rt715 snd_soc_hdac_hdmi regmap_sdw snd_soc_dmic snd_sof_pci snd_sof_intel_hda_common soundwire_intel_init soundwire_intel soundwire_generic_allocation soundwire_cadence snd_intel_nhlt snd_sof_intel_hda snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_hda_ext_core snd_hda_core soundwire_bus snd_soc_core snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq x86_pkg_temp_thermal snd_seq_device snd_timer intel_powerclamp snd asix usbnet soundcore iwlwifi mei_me mei intel_lpss_pci intel_lpss mfd_core processor_thermal_device int340x_thermal_zone intel_soc_dts_iosf int3400_thermal acpi_thermal_rel efivarfs i915 i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sdhci_pci xhci_pci sysimgblt fb_sys_fops cqhci sdhci xhci_hcd drm
[    5.177714] CR2: fffffffffffffff0
[    5.177716] ---[ end trace 469d85a34b6a7b8b ]---
[    5.177717] RIP: 0010:sdw_slave_port_release.isra.7+0x6d/0xf0 [soundwire_bus]
[    5.177718] Code: de 48 8b 54 24 08 48 8b 42 18 4c 8d 6a 18 49 39 c5 4c 8d 78 f0 75 0f eb 67 49 8b 47 10 49 39 c5 4c 8d 78 f0 74 5a 48 8b 04 24 <49> 39 07 75 ea 49 8b 4f 20 49 8d 5f 20 48 8b 01 48 39 cb 48 8d 79
[    5.177719] RSP: 0018:ffffaba440bf39c8 EFLAGS: 00010286
[    5.177720] RAX: ffff8a621a0a4400 RBX: ffff8a621a0a4400 RCX: 0000000000000000
[    5.177721] RDX: ffff8a621c7de248 RSI: ffff8a62172e0920 RDI: ffff8a621a0a4400
[    5.177722] RBP: dead000000000122 R08: 0000000000000ada R09: 000000000000004f
[    5.177723] R10: 0000000000000004 R11: ffffaba440bf3760 R12: dead000000000100
[    5.177724] R13: ffff8a621c7de260 R14: 0000000000000000 R15: fffffffffffffff0
[    5.177725] FS:  00007faa911e1500(0000) GS:ffff8a621ff40000(0000) knlGS:0000000000000000
[    5.177725] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    5.177726] CR2: fffffffffffffff0 CR3: 0000000497a2a001 CR4: 0000000000760ee0
[    5.177727] PKRU: 55555554
[    5.405183] rfkill: input handler disabled
[    5.579448] IPv6: ADDRCONF(NETDEV_CHANGE): enx000ec6c686f2: link becomes ready
[    5.582061] asix 3-8.1:1.0 enx000ec6c686f2: link up, 100Mbps, full-duplex, lpa 0x41E1
[    5.693531] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[    5.693556] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[    7.424035] intel-sdw sdw-master-2: intel_suspend_runtime start
[    7.424109] intel-sdw sdw-master-2: intel_suspend_runtime done
[    8.908383] intel-sdw sdw-master-1: intel_suspend_runtime start
[    8.908458] intel-sdw sdw-master-1: intel_suspend_runtime done
[    8.908468] intel-sdw sdw-master-3: intel_suspend_runtime start
[    8.908574] intel-sdw sdw-master-3: intel_suspend_runtime done
[  613.456817] asix 3-8.1:1.0 enx000ec6c686f2: link up, 100Mbps, full-duplex, lpa 0x41E1

dmesg.log

  1. Boot up with pulse audio off, regression 1 are gone. But
    a. Aplay --> S3--> resume --> pass. No I/O error occurred. aplay can resume normally.
    b. Aplay 0,0/2/3 --> pause --> resume --> fail console shows "pause/release error: Invalid argument"
Dmesg
[  883.698874] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[  883.698884]  SDW0-Playback: ASoC: trigger BE SDW0-Playback cmd 4
[  883.698891] intel-sdw sdw-master-0: intel_trigger: SDW0 Pin2: start
[  883.698898] sdw_enable_stream: SDW0 Pin2-Playback: start
[  883.698902] sdw_enable_stream: SDW0 Pin2-Playback: inconsistent state state 5
[  883.698904] sdw_enable_stream: SDW0 Pin2-Playback: done
[  883.698908] intel-sdw sdw-master-0: intel_trigger trigger 4 failed: -22
[  883.698910] intel-sdw sdw-master-0: intel_trigger: SDW0 Pin2: done
[  883.698913]  SDW0-Playback: ASoC: trigger BE failed -22
[  883.698918]  SDW0-speakers: ASoC: pre trigger FE SDW0-speakers cmd 3
[  883.698924] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 3
[  883.698930] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[  883.699104] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[  883.699557] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[  883.699614]  SDW0-speakers: ASoC: pre trigger FE SDW0-speakers cmd 4
[  883.699619] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 4
[  883.700158] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x2014001e successful
[  883.700165] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[  883.700337] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE

pause_dmesg.log
pause_logger.log

Test it on CML RT700 RVP with this PR, system can boot up successfully with PA on, but also can reproduce regression 2 with PA on.

Test recipe:
Firmware: 40bf5e0 https://github.com/thesofproject/sof/commits/master
Kernel: 19df577 https://github.com/thesofproject/linux/tree/integration/soundwire-latest + PR1314

@bardliao bardliao left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

@plbossart QA and I found some issues with this PR. Here are some comments. I also did the modification on https://github.com/bardliao/linux/commits/integration/soundwire-20191015. The test result is so far so good.

Comment thread drivers/soundwire/intel.c
case SNDRV_PCM_TRIGGER_PAUSE_PUSH:
case SNDRV_PCM_TRIGGER_SUSPEND:
dev_err(dai->dev, "%s: %s: suspend\n", __func__, dai->name);
dma->suspend_reinitialize = true;

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

@plbossart SNDRV_PCM_TRIGGER_SUSPEND is not always triggered. For example. SNDRV_PCM_TRIGGER_SUSPEND will not be triggered If we do aplay -> pulse -> suspend -> resume -> release. However, we have to reinitialize in this case since the system is suspended. So my suggestion is to set it in intel_suspend().

Comment thread drivers/soundwire/intel.c
ret = sdw_disable_stream(dma->stream);

if (!ret) {
err = sdw_deprepare_stream(dma->stream);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

I still think it is better to call sdw_deprepare_stream() in .hw_free(). I saw intel_prepare() is trigger twice without intel_trigger() when pulseaudio is enabled.


sdw_acquire_bus_lock(stream);

if (stream->state != SDW_STREAM_DISABLED) {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

SDW_STREAM_PREPARED is also valid here, right? We may do prepare -> deprepare without enabling/disabling.

Comment thread drivers/soundwire/intel.c
dma->suspend_reinitialize = false;
}

ret = sdw_prepare_stream(dma->stream);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

If we call sdw_deprepare_stream() in .hw_free(), intel_prepare() may be called on stream->state = DISABLED. We don't need to call sdw_deprepare_stream(), but we should return 0 in such case.

@bardliao

Copy link
Copy Markdown
Collaborator

Test it on icl rt700 rvp and icl 3-in-1 rvp with this PR, found two regressions as below:

  1. system boot up with pulse audio on, soundwire pm status is always active, and dmesg log shows:

Dmesg
dmesg.log

  1. Boot up with pulse audio off, regression 1 are gone. But
    a. Aplay --> S3--> resume --> pass. No I/O error occurred. aplay can resume normally.
    b. Aplay 0,0/2/3 --> pause --> resume --> fail console shows "pause/release error: Invalid argument"

Dmesg
pause_dmesg.log
pause_logger.log

Test it on CML RT700 RVP with this PR, system can boot up successfully with PA on, but also can reproduce regression 2 with PA on.

Test recipe:
Firmware: 40bf5e0 https://github.com/thesofproject/sof/commits/master
Kernel: 19df577 https://github.com/thesofproject/linux/tree/integration/soundwire-latest + PR1314

@YvonneYang2 Could you retest it with https://github.com/bardliao/linux/tree/integration/soundwire-20191015 tomorrow?

@plbossart

Copy link
Copy Markdown
Member Author

@plbossart .prepare will not be trigger on SNDRV_PCM_TRIGGER_PAUSE_PUSH/SNDRV_PCM_TRIGGER_PAUSE_RELEASE cycle. So, if we call sdw_deprepare_stream() in the SNDRV_PCM_TRIGGER_PAUSE_PUSH case, the stream status will be DEPREPARED and we will see sdw_enable_stream: SDW0 Pin2-Playback: inconsistent state state 5 when SNDRV_PCM_TRIGGER_PAUSE_RELEASE is triggered.
We can test it with aplay -Dhw:0,0 test.wav -vv -i command, and press SPACE key to pulse/release it.

error log
The other reason why it is better to do deprepare in hw_free() is that disable -> enable is enough and we don't need to do disable -> deprepare -> prepare -> enable in the pulse/resume case.
What do you think?

ok for the pause_push/pause_release. Although in practice we shouldn't support PAUSE but that's a separate story.

If we take your logic, then we have a similar flaw on unneeded transitions. When you resume, why would we de-prepare then reprepare. What we need to do is apply the existing settings and reconfigure the bus directly.

@plbossart

Copy link
Copy Markdown
Member Author

replaced by #1320

@plbossart plbossart closed this Oct 15, 2019
ujfalusi pushed a commit to ujfalusi/sof-linux that referenced this pull request Apr 4, 2023
Patch series "migrate_pages: fix deadlock in batched synchronous
migration", v2.

Two deadlock bugs were reported for the migrate_pages() batching series. 
Thanks Hugh and Pengfei.  Analysis shows that if we have locked some other
folios except the one we are migrating, it's not safe in general to wait
synchronously, for example, to wait the writeback to complete or wait to
lock the buffer head.

So 1/3 fixes the deadlock in a simple way, where the batching support for
the synchronous migration is disabled.  The change is straightforward and
easy to be understood.  While 3/3 re-introduce the batching for
synchronous migration via trying to migrate asynchronously in batch
optimistically, then fall back to migrate synchronously one by one for
fail-to-migrate folios.  Test shows that this can restore the TLB flushing
batching performance for synchronous migration effectively.


This patch (of 3):

Two deadlock bugs were reported for the migrate_pages() batching series. 
Thanks Hugh and Pengfei!  For example, in the following deadlock trace
snippet,

 INFO: task kworker/u4:0:9 blocked for more than 147 seconds.
       Not tainted 6.2.0-rc4-kvm+ thesofproject#1314
 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
 task:kworker/u4:0    state:D stack:0     pid:9     ppid:2      flags:0x00004000
 Workqueue: loop4 loop_rootcg_workfn
 Call Trace:
  <TASK>
  __schedule+0x43b/0xd00
  schedule+0x6a/0xf0
  io_schedule+0x4a/0x80
  folio_wait_bit_common+0x1b5/0x4e0
  ? __pfx_wake_page_function+0x10/0x10
  __filemap_get_folio+0x73d/0x770
  shmem_get_folio_gfp+0x1fd/0xc80
  shmem_write_begin+0x91/0x220
  generic_perform_write+0x10e/0x2e0
  __generic_file_write_iter+0x17e/0x290
  ? generic_write_checks+0x12b/0x1a0
  generic_file_write_iter+0x97/0x180
  ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
  do_iter_readv_writev+0x13c/0x210
  ? __sanitizer_cov_trace_const_cmp4+0x1a/0x20
  do_iter_write+0xf6/0x330
  vfs_iter_write+0x46/0x70
  loop_process_work+0x723/0xfe0
  loop_rootcg_workfn+0x28/0x40
  process_one_work+0x3cc/0x8d0
  worker_thread+0x66/0x630
  ? __pfx_worker_thread+0x10/0x10
  kthread+0x153/0x190
  ? __pfx_kthread+0x10/0x10
  ret_from_fork+0x29/0x50
  </TASK>

 INFO: task repro:1023 blocked for more than 147 seconds.
       Not tainted 6.2.0-rc4-kvm+ thesofproject#1314
 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
 task:repro           state:D stack:0     pid:1023  ppid:360    flags:0x00004004
 Call Trace:
  <TASK>
  __schedule+0x43b/0xd00
  schedule+0x6a/0xf0
  io_schedule+0x4a/0x80
  folio_wait_bit_common+0x1b5/0x4e0
  ? compaction_alloc+0x77/0x1150
  ? __pfx_wake_page_function+0x10/0x10
  folio_wait_bit+0x30/0x40
  folio_wait_writeback+0x2e/0x1e0
  migrate_pages_batch+0x555/0x1ac0
  ? __pfx_compaction_alloc+0x10/0x10
  ? __pfx_compaction_free+0x10/0x10
  ? __this_cpu_preempt_check+0x17/0x20
  ? lock_is_held_type+0xe6/0x140
  migrate_pages+0x100e/0x1180
  ? __pfx_compaction_free+0x10/0x10
  ? __pfx_compaction_alloc+0x10/0x10
  compact_zone+0xe10/0x1b50
  ? lock_is_held_type+0xe6/0x140
  ? check_preemption_disabled+0x80/0xf0
  compact_node+0xa3/0x100
  ? __sanitizer_cov_trace_const_cmp8+0x1c/0x30
  ? _find_first_bit+0x7b/0x90
  sysctl_compaction_handler+0x5d/0xb0
  proc_sys_call_handler+0x29d/0x420
  proc_sys_write+0x2b/0x40
  vfs_write+0x3a3/0x780
  ksys_write+0xb7/0x180
  __x64_sys_write+0x26/0x30
  do_syscall_64+0x3b/0x90
  entry_SYSCALL_64_after_hwframe+0x72/0xdc
 RIP: 0033:0x7f3a2471f59d
 RSP: 002b:00007ffe567f7288 EFLAGS: 00000217 ORIG_RAX: 0000000000000001
 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f3a2471f59d
 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
 RBP: 00007ffe567f72a0 R08: 0000000000000010 R09: 0000000000000010
 R10: 0000000000000010 R11: 0000000000000217 R12: 00000000004012e0
 R13: 00007ffe567f73e0 R14: 0000000000000000 R15: 0000000000000000
  </TASK>

The page migration task has held the lock of the shmem folio A, and is
waiting the writeback of the folio B of the file system on the loop block
device to complete.  While the loop worker task which writes back the
folio B is waiting to lock the shmem folio A, because the folio A backs
the folio B in the loop device.  Thus deadlock is triggered.

In general, if we have locked some other folios except the one we are
migrating, it's not safe to wait synchronously, for example, to wait the
writeback to complete or wait to lock the buffer head.

To fix the deadlock, in this patch, we avoid to batch the page migration
except for MIGRATE_ASYNC mode.  In MIGRATE_ASYNC mode, synchronous waiting
is avoided.

The fix can be improved further.  We will do that as soon as possible.

Link: https://lkml.kernel.org/r/20230303030155.160983-1-ying.huang@intel.com
Link: https://lore.kernel.org/linux-mm/87a6c8c-c5c1-67dc-1e32-eb30831d6e3d@google.com/
Link: https://lore.kernel.org/linux-mm/874jrg7kke.fsf@yhuang6-desk2.ccr.corp.intel.com/
Link: https://lore.kernel.org/linux-mm/20230227110614.dngdub2j3exr6dfp@quack3/
Link: https://lkml.kernel.org/r/20230303030155.160983-2-ying.huang@intel.com
Fixes: 5dfab10 ("migrate_pages: batch _unmap and _move")
Signed-off-by: "Huang, Ying" <ying.huang@intel.com>
Reported-by: Hugh Dickins <hughd@google.com>
Reported-by: "Xu, Pengfei" <pengfei.xu@intel.com>
Cc: Jan Kara <jack@suse.cz>
Cc: Baolin Wang <baolin.wang@linux.alibaba.com>
Cc: Christoph Hellwig <hch@lst.de>
Cc: Stefan Roesch <shr@devkernel.io>
Cc: Tejun Heo <tj@kernel.org>
Cc: Xin Hao <xhao@linux.alibaba.com>
Cc: Zi Yan <ziy@nvidia.com>
Cc: Yang Shi <shy828301@gmail.com>
Cc: Matthew Wilcox <willy@infradead.org>
Cc: Mike Kravetz <mike.kravetz@oracle.com>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants