Message-ID: <87b3bcbb-2944-4548-a865-9ccfca2188c3@molgen.mpg.de>
Date: Thu, 4 Jul 2024 16:13:56 +0200
From: Paul Menzel <pmenzel@...gen.mpg.de>
To: Greg KH <gregkh@...uxfoundation.org>
Cc: linux-kernel@...r.kernel.org
Subject: Re: Freezing user space processes failed after 20.006 seconds
 (systemd-journal, udev-worker)

[Attach output of `dmesg`]

Am 04.07.24 um 16:11 schrieb Paul Menzel:
> Dear Linux folks,
> 
> 
> Using Linux 6.10-rc6 on the Intel Kaby Lake laptop Dell XPS 13 9360, I 
> was unable to suspend the system:
> 
> ```
> [    0.000000] Linux version 6.10.0-rc6 (build@...emianrhapsody.molgen.mpg.de) (gcc (Debian 13.3.0-1) 13.3.0, GNU ld (GNU Binutils for Debian) 2.42.50.20240625) #211 SMP PREEMPT_DYNAMIC Mon Jul  1 08:23:19 CEST 2024
> [    0.000000] Command line: BOOT_IMAGE=/vmlinuz-6.10.0-rc6 root=UUID=32e29882-d94d-4a92-9ee4-4d03002bfa29 ro quiet pci=noaer mem_sleep_default=deep log_buf_len=8M cryptomgr.notests
> […]
> [42576.003324] Freezing user space processes
> [42596.009937] Freezing user space processes failed after 20.006 seconds (2 tasks refusing to freeze, wq_busy=0):
> [42596.010034] task:systemd-journal state:D stack:0     pid:405 tgid:405   ppid:1      flags:0x00000006
> [42596.010060] Call Trace:
> [42596.010068]  <TASK>
> [42596.010082]  __schedule+0x3e8/0xb10
> [42596.010117]  schedule+0x27/0xe0
> [42596.010137]  schedule_preempt_disabled+0x15/0x20
> [42596.010157]  __mutex_lock.constprop.0+0x335/0x620
> [42596.010183]  uevent_show+0xa6/0x120
> [42596.010208]  dev_attr_show+0x19/0x50
> [42596.010225]  sysfs_kf_seq_show+0xa1/0xf0
> [42596.010248]  seq_read_iter+0x1c5/0x490
> [42596.010262]  ? security_file_permission+0x30/0x40
> [42596.010284]  vfs_read+0x289/0x360
> [42596.010312]  ksys_read+0x6f/0xf0
> [42596.010333]  do_syscall_64+0x82/0x160
> [42596.010351]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.010373]  ? do_syscall_64+0x8e/0x160
> [42596.010383]  ? do_sys_openat2+0x93/0xe0
> [42596.010404]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.010423]  ? do_syscall_64+0x8e/0x160
> [42596.010434]  ? __mod_memcg_state+0x95/0x130
> [42596.010452]  ? __memcg_slab_free_hook+0xf9/0x140
> [42596.010470]  ? kmem_cache_free+0x256/0x4b0
> [42596.010490]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.010508]  ? do_syscall_64+0x8e/0x160
> [42596.010519]  ? kmem_cache_free+0x256/0x4b0
> [42596.010536]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.010554]  ? do_syscall_64+0x8e/0x160
> [42596.010564]  ? do_syscall_64+0x8e/0x160
> [42596.010574]  ? do_syscall_64+0x8e/0x160
> [42596.010583]  ? exc_page_fault+0x81/0x190
> [42596.010602]  entry_SYSCALL_64_after_hwframe+0x4b/0x53
> [42596.010621] RIP: 0033:0x7f0883b19a5c
> [42596.010704] RSP: 002b:00007ffdb5179de0 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
> [42596.010720] RAX: ffffffffffffffda RBX: 000055d7fa3042a0 RCX: 00007f0883b19a5c
> [42596.010731] RDX: 0000000000001008 RSI: 000055d7fa3042a0 RDI: 0000000000000026
> [42596.010741] RBP: 0000000000000026 R08: 0000000000000000 R09: 0000000000000001
> [42596.010749] R10: 0000000000000003 R11: 0000000000000246 R12: 0000000000001007
> [42596.010758] R13: 0000000000001008 R14: ffffffffffffffff R15: 0000000000000002
> [42596.010777]  </TASK>
> [42596.011098] task:(udev-worker)   state:D stack:0     pid:109961 tgid:109961 ppid:426    flags:0x00000006
> [42596.011120] Call Trace:
> [42596.011126]  <TASK>
> [42596.011133]  __schedule+0x3e8/0xb10
> [42596.011158]  schedule+0x27/0xe0
> [42596.011175]  schedule_preempt_disabled+0x15/0x20
> [42596.011194]  __mutex_lock.constprop.0+0x335/0x620
> [42596.011219]  uevent_show+0xa6/0x120
> [42596.011240]  dev_attr_show+0x19/0x50
> [42596.011256]  sysfs_kf_seq_show+0xa1/0xf0
> [42596.011277]  seq_read_iter+0x1c5/0x490
> [42596.011289]  ? security_file_permission+0x30/0x40
> [42596.011307]  vfs_read+0x289/0x360
> [42596.011334]  ksys_read+0x6f/0xf0
> [42596.011355]  do_syscall_64+0x82/0x160
> [42596.011366]  ? do_readlinkat+0x105/0x140
> [42596.011384]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.011404]  ? do_syscall_64+0x8e/0x160
> [42596.011414]  ? syscall_exit_to_user_mode+0x73/0x200
> [42596.011432]  ? do_syscall_64+0x8e/0x160
> [42596.011441]  ? do_syscall_64+0x8e/0x160
> [42596.011450]  ? do_syscall_64+0x8e/0x160
> [42596.011458]  ? do_syscall_64+0x8e/0x160
> [42596.011467]  ? exc_page_fault+0x81/0x190
> [42596.011486]  entry_SYSCALL_64_after_hwframe+0x4b/0x53
> [42596.011501] RIP: 0033:0x7eff70fefa1d
> [42596.011532] RSP: 002b:00007ffcfc8777a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
> [42596.011546] RAX: ffffffffffffffda RBX: 0000561c75620fc0 RCX: 00007eff70fefa1d
> [42596.011555] RDX: 0000000000001008 RSI: 0000561c75620fc0 RDI: 0000000000000015
> [42596.011563] RBP: 0000000000000015 R08: 0000000000000000 R09: 00007eff710c7b50
> [42596.011571] R10: 0000000000000010 R11: 0000000000000246 R12: 0000000000001007
> [42596.011579] R13: 0000000000001008 R14: ffffffffffffffff R15: 0000000000000002
> [42596.011594]  </TASK>
> ```
> 
> The system came back (took some time to get GNOME’s screensaver screen 
> to show) and powering off the system seems to have worked, but the 
> journal does not contain these messages due to being impacted by the error:
> 
> ```
> […]
> Jul 04 09:03:23 abreu kernel: ACPI: EC: interrupt unblocked
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: Unable to change power state from D3hot to D0, device inaccessible
> Jul 04 09:03:23 abreu kernel: ACPI: EC: event unblocked
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: Unable to change power state from D3cold to D0, device inaccessible
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: Controller not ready at resume -19
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: PCI post-resume error -19!
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: HC died; cleaning up
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: PM: dpm_run_callback(): pci_pm_resume returns -19
> Jul 04 09:03:23 abreu kernel: xhci_hcd 0000:39:00.0: PM: failed to resume async: error -19
> Jul 04 09:03:23 abreu kernel: nvme nvme0: 4/0/0 default/read/poll queues
> Jul 04 09:03:23 abreu kernel: i915 0000:00:02.0: [drm] [ENCODER:98:DDI A/PHY A] is disabled/in DSI mode with an ungated DDI clock, gate it
> Jul 04 09:03:23 abreu kernel: i915 0000:00:02.0: [drm] [ENCODER:106:DDI B/PHY B] is disabled/in DSI mode with an ungated DDI clock, gate it
> Jul 04 09:03:23 abreu kernel: i915 0000:00:02.0: [drm] [ENCODER:117:DDI C/PHY C] is disabled/in DSI mode with an ungated DDI clock, gate it
> Jul 04 09:03:23 abreu kernel: usb 1-5: reset high-speed USB device number 4 using xhci_hcd
> Jul 04 09:03:23 abreu kernel: usb 1-3: reset full-speed USB device number 2 using xhci_hcd
> Jul 04 09:03:23 abreu kernel: usb 1-4: reset full-speed USB device number 3 using xhci_hcd
> Jul 04 09:03:23 abreu kernel: OOM killer enabled.
> Jul 04 09:03:23 abreu kernel: Restarting tasks ... done.
> Jul 04 09:03:23 abreu kernel: random: crng reseeded on system resumption
> -- Boot cd4eeb2265834de6ba3c3b5d747d9481 --
> Jul 04 09:09:36 abreu kernel: Linux version 6.10.0-rc6 (build@...emianrhapsody.molgen.mpg.de) (gcc (Debian 13.3.0-1) 13.3.0, GNU ld (GNU Binutils for Debian) 2.42.50.20240625) #211 SMP PREEMPT_DYNAMIC Mon Jul  1 08:23:19 CEST 2024
> […]
> ```
> 
> I think it is *not* a regression, but – as the logs do not contain any 
> hints – I am not sure.
> 
> 
> Kind regards,
> 
> Paul
View attachment "20240704--linux-6.10-rc6.txt" of type "text/plain" (182659 bytes)

Powered by blists - more mailing lists