[SOLVED] System stuck on suspend/shutdown

keineeile · 2014-09-29 21:42:52

Hi guys,

I recently set up a new system with Arch Linux, and everything's working perfectly fine - except for one thing: When shutting the computer down, the system gets all the way to the end of the shutdown cycle and displays "Rebooting" - and just stays there, the computer doesn't turn off (even after almost an hour, no change). It does tell me just before that, that it failed to unmount /oldroot/dev, however, it claims to be ignoring that problem...? And everytime, just before it unmounts (or tries to at least) all the /oldroot/ stuff, it gets stuck shortly while trying to terminate some "tee" process (it eventually sends a SIGKILL signal and proceeds shortly after).
Could this maybe cause some problem when powering off? Because also when I try to suspend my system, the screen turns blank (with a blinking cursor in the top left), and shortly after it displays the message "Freezing of tasks failed after 20.005 seconds (3 tasks refusing to freeze, wq_busy=0)" and goes back to my desktop. Using dmesg, I found that, again, "tee" is the process causing problems. When I list all running processes, it displays 3 of these "tee" processes, and under CPU% it says "disk sleep" for all of them...

Here is an extract of dmesg that displays the suspend/freezing problem:

[ 2519.042907] Freezing user space processes ... 
[ 2539.053497] Freezing of tasks failed after 20.005 seconds (3 tasks refusing to freeze, wq_busy=0):
[ 2539.053587] tee             D 0000000000000000     0  2919      1 0x00000004
[ 2539.053593]  ffff8800a664fdc0 0000000000000000 ffff88012524f010 0000000000000000
[ 2539.053599]  ffff8800a664ffd8 0000000000000000 ffff88012524f010 ffffffff811cfefa
[ 2539.053601]  ffff88012524f010 ffff88012524f010 ffff8800a9454900 ffff880131a6f000
[ 2539.053603] Call Trace:
[ 2539.053613]  [<ffffffff811cfefa>] ? do_last.isra.36+0x1ba/0xe50
[ 2539.053617]  [<ffffffff811c4808>] ? __sb_start_write+0x58/0x110
[ 2539.053620]  [<ffffffff811c4781>] ? __sb_end_write+0x31/0x60
[ 2539.053623]  [<ffffffff8152d289>] schedule+0x29/0x70
[ 2539.053625]  [<ffffffff8152d6f6>] schedule_preempt_disabled+0x16/0x20
[ 2539.053628]  [<ffffffff8152f075>] __mutex_lock_slowpath+0xe5/0x230
[ 2539.053630]  [<ffffffff8152f1d7>] mutex_lock+0x17/0x30
[ 2539.053634]  [<ffffffff813ab548>] control_store+0x48/0xd0
[ 2539.053638]  [<ffffffff812010bc>] ? fsnotify+0x28c/0x370
[ 2539.053642]  [<ffffffff8139fee8>] dev_attr_store+0x18/0x30
[ 2539.053647]  [<ffffffff8123885a>] sysfs_kf_write+0x3a/0x50
[ 2539.053649]  [<ffffffff81237dce>] kernfs_fop_write+0xee/0x180
[ 2539.053651]  [<ffffffff811c1f97>] vfs_write+0xb7/0x200
[ 2539.053653]  [<ffffffff811c1eac>] ? vfs_read+0x13c/0x170
[ 2539.053654]  [<ffffffff811c2c09>] SyS_write+0x59/0xd0
[ 2539.053657]  [<ffffffff81531129>] system_call_fastpath+0x16/0x1b
[ 2539.053658] tee             D 0000000000000000     0  3352   2935 0x00000004
[ 2539.053660]  ffff8800857cbdc0 0000000000000000 ffff88008573b2f0 0000000000000000
[ 2539.053662]  ffff8800857cbfd8 0000000000000000 ffff88008573b2f0 ffffffff811cfefa
[ 2539.053664]  ffff88008573b2f0 ffff88008573b2f0 ffff8800a9454900 ffff8800856bc300
[ 2539.053666] Call Trace:
[ 2539.053668]  [<ffffffff811cfefa>] ? do_last.isra.36+0x1ba/0xe50
[ 2539.053674]  [<ffffffff810725b2>] ? current_fs_time+0x12/0x60
[ 2539.053675]  [<ffffffff8152d289>] schedule+0x29/0x70
[ 2539.053677]  [<ffffffff8152d6f6>] schedule_preempt_disabled+0x16/0x20
[ 2539.053679]  [<ffffffff8152f075>] __mutex_lock_slowpath+0xe5/0x230
[ 2539.053681]  [<ffffffff8152f1d7>] mutex_lock+0x17/0x30
[ 2539.053682]  [<ffffffff813ab548>] control_store+0x48/0xd0
[ 2539.053684]  [<ffffffff812010bc>] ? fsnotify+0x28c/0x370
[ 2539.053686]  [<ffffffff8139fee8>] dev_attr_store+0x18/0x30
[ 2539.053688]  [<ffffffff8123885a>] sysfs_kf_write+0x3a/0x50
[ 2539.053690]  [<ffffffff81237dce>] kernfs_fop_write+0xee/0x180
[ 2539.053692]  [<ffffffff811c1f97>] vfs_write+0xb7/0x200
[ 2539.053694]  [<ffffffff811c1eac>] ? vfs_read+0x13c/0x170
[ 2539.053695]  [<ffffffff811c2c09>] SyS_write+0x59/0xd0
[ 2539.053697]  [<ffffffff81531129>] system_call_fastpath+0x16/0x1b
[ 2539.053699] tee             D 0000000000000000     0  3806      1 0x00000004
[ 2539.053701]  ffff8800a643bdc0 0000000000000000 ffff880085739460 0000000000000000
[ 2539.053703]  ffff8800a643bfd8 0000000000000000 ffff880085739460 ffffffff811cfefa
[ 2539.053704]  ffff880085739460 ffff880085739460 ffff8800a9454900 ffff8800a4abf000
[ 2539.053706] Call Trace:
[ 2539.053708]  [<ffffffff811cfefa>] ? do_last.isra.36+0x1ba/0xe50
[ 2539.053710]  [<ffffffff810725b2>] ? current_fs_time+0x12/0x60
[ 2539.053712]  [<ffffffff8152d289>] schedule+0x29/0x70
[ 2539.053713]  [<ffffffff8152d6f6>] schedule_preempt_disabled+0x16/0x20
[ 2539.053715]  [<ffffffff8152f075>] __mutex_lock_slowpath+0xe5/0x230
[ 2539.053717]  [<ffffffff8152f1d7>] mutex_lock+0x17/0x30
[ 2539.053719]  [<ffffffff813ab548>] control_store+0x48/0xd0
[ 2539.053721]  [<ffffffff812010bc>] ? fsnotify+0x28c/0x370
[ 2539.053722]  [<ffffffff8139fee8>] dev_attr_store+0x18/0x30
[ 2539.053724]  [<ffffffff8123885a>] sysfs_kf_write+0x3a/0x50
[ 2539.053726]  [<ffffffff81237dce>] kernfs_fop_write+0xee/0x180
[ 2539.053728]  [<ffffffff811c1f97>] vfs_write+0xb7/0x200
[ 2539.053730]  [<ffffffff811c1eac>] ? vfs_read+0x13c/0x170
[ 2539.053732]  [<ffffffff811c2c09>] SyS_write+0x59/0xd0
[ 2539.053734]  [<ffffffff81531129>] system_call_fastpath+0x16/0x1b

Don't know if that's in any way related to the above problem(s), but I also have loads of such messages in dmesg:

[ 1321.983088] INFO: task kworker/u16:3:91 blocked for more than 120 seconds.
[ 1321.983096]       Not tainted 3.16.3-1-ARCH #1
[ 1321.983098] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1321.983100] kworker/u16:3   D 0000000000000000     0    91      2 0x00000000
[ 1321.983112] Workqueue: kacpi_hotplug acpi_hotplug_work_fn
[ 1321.983115]  ffff88003793baa0 0000000000000000 ffff88003764d180 0000000000000000
[ 1321.983119]  ffff88003793bfd8 0000000000000000 ffff88003764d180 000000005a1a7d0b
[ 1321.983123]  0000000000000000 0000000000000000 0000000000000000 ffffffffa0585f7d
[ 1321.983127] Call Trace:
[ 1321.983148]  [<ffffffff813a11de>] ? __dev_printk+0x3e/0x90
[ 1321.983152]  [<ffffffff813a16fc>] ? _dev_info+0x6c/0x90
[ 1321.983160]  [<ffffffff812a7fb7>] ? ___ratelimit+0x87/0x100
[ 1321.983166]  [<ffffffff8152d289>] schedule+0x29/0x70
[ 1321.983169]  [<ffffffff8152c479>] schedule_timeout+0x1b9/0x240
[ 1321.983175]  [<ffffffff8139d730>] ? vga_switcheroo_show+0x140/0x140
[ 1321.983179]  [<ffffffff8152dd3f>] wait_for_common+0xcf/0x190
[ 1321.983184]  [<ffffffff810a2ce0>] ? wake_up_process+0x50/0x50
[ 1321.983188]  [<ffffffff8152de1d>] wait_for_completion+0x1d/0x20
[ 1321.983204]  [<ffffffffa02dffc3>] snd_card_free+0x63/0x90 [snd]
[ 1321.983212]  [<ffffffffa058277a>] azx_remove+0x1a/0x20 [snd_hda_intel]
[ 1321.983216]  [<ffffffff812df88b>] pci_device_remove+0x3b/0xc0
[ 1321.983219]  [<ffffffff813a500f>] __device_release_driver+0x7f/0xf0
[ 1321.983220]  [<ffffffff813a50a3>] device_release_driver+0x23/0x30
[ 1321.983224]  [<ffffffff812d9a04>] pci_stop_bus_device+0x94/0xa0
[ 1321.983226]  [<ffffffff812d99a5>] pci_stop_bus_device+0x35/0xa0
[ 1321.983228]  [<ffffffff812d9b22>] pci_stop_and_remove_bus_device+0x12/0x20
[ 1321.983231]  [<ffffffff812f9d47>] disable_slot+0x57/0xb0
[ 1321.983233]  [<ffffffff812fa538>] acpiphp_check_bridge.part.9+0xf8/0x100
[ 1321.983235]  [<ffffffff812fb008>] acpiphp_check_host_bridge+0x78/0xc0
[ 1321.983238]  [<ffffffff813255d9>] acpi_pci_root_scan_dependent+0xe/0x12
[ 1321.983241]  [<ffffffff81321c34>] acpi_scan_bus_check+0x42/0xa2
[ 1321.983243]  [<ffffffff81321d3c>] acpi_device_hotplug+0xa8/0x408
[ 1321.983245]  [<ffffffff8131b702>] acpi_hotplug_work_fn+0x1e/0x29
[ 1321.983249]  [<ffffffff8108afa8>] process_one_work+0x168/0x450
[ 1321.983251]  [<ffffffff8108b5db>] worker_thread+0x6b/0x550
[ 1321.983253]  [<ffffffff8108b570>] ? init_pwq.part.22+0x10/0x10
[ 1321.983256]  [<ffffffff81091cea>] kthread+0xea/0x100
[ 1321.983258]  [<ffffffff81091c00>] ? kthread_create_on_node+0x1b0/0x1b0
[ 1321.983261]  [<ffffffff8153107c>] ret_from_fork+0x7c/0xb0
[ 1321.983263]  [<ffffffff81091c00>] ? kthread_create_on_node+0x1b0/0x1b0

My system:

Linux keineeile 3.16.3-1-ARCH #1 SMP PREEMPT Wed Sep 17 21:54:13 CEST 2014 x86_64 GNU/Linux

I'm using KDE as my DE, should that matter at all... I don't have laptop-mode-tools or pm-utils installed, but I do have the powerdown scripts (though they don't seem to be working right now for me - but one thing after the other).

Any help in solving this issue(s) is very much appreciated!!

Kindest Regards
keineeile

Last edited by keineeile (2014-10-01 15:59:58)

elav · 2014-09-29 23:21:15

Same situation here!! Same Desktop!!

lucke · 2014-09-30 00:00:49

Seeing tee running is a bit unexpected. It is used to fork a process' output to both a standard output and a file. Finding out why tee processes are running would be the first step.

It might be that two of them are spawned by systemd and one by something else (a process with a pid 2935 - if I'm reading the lines starting with "tee" correctly). Do you know when these processes appear (perhaps suspending creates them?) and if they disappear? I'd like to see the output of "ps ax" together with these "failed to freeze tee" messages.

keineeile · 2014-09-30 00:11:45

Hi lucke,

Thanks for the reply! They indeed only appear when attempting to suspend/shutdown. pid 2935 is the terminal, from where I issued the suspend command.

$ ps -ax | grep tee
 2919 pts/1    D      0:00 tee /sys/bus/pci/devices/0000:01:00.1/power/control
 3352 ?        D      0:00 tee /sys/bus/pci/devices/0000:01:00.1/power/control
 3806 ?        D      0:00 tee /sys/bus/pci/devices/0000:01:00.1/power/control

lucke · 2014-09-30 00:20:17

lspci should tell you what 01:00.1 is.

Are you suspending from KDE? If so, "systemctl suspend" should have the same effect. pm-utils had a lot of quirks/scripts to deal with different hardware, systemd got rid of that, but apparently it still does some userpace stuff (that is, writing something to /sys/bus/pci/devices/0000:01:00.1/power/control). Maybe journalctl would show something? "echo mem > /sys/power/state" should put the system to sleep without any userspace meddling.

keineeile · 2014-09-30 01:02:50

Well, I tried it both ways, suspending from KDE and from the command line using "systemctl suspend" and "echo mem > /sys/power/state", it all produces the same result.

However, I think I have stumbled upon something in lspci:

# lspci | grep 01:00.1
pcilib: Cannot open /sys/bus/pci/devices/0000:01:00.1/config
lspci: Unable to read the standard configuration space header of device 0000:01:00.1

There exists a device 01:00.0, though. This is my discrete radeon graphics card. Maybe it's connected to the following (?):
My laptop comes with an Intel graphics chip and a radeon graphics card. I want to use the Intel chip for powersaving and for having a cooler laptop. However, the DynPwr feature of the newest kernel (I think it was introduced in 3.15?) doesn't seem to work for me, my laptop just gets really hot. Plus the system kept freezing randomly (in such a way that I had to force turn off the laptop), which according to what I found online had something to do with NetworkManager and my radeon graphics card (I don't really understand how that's possible though). So what I did: In Grub I added "radeon.runpm=0" to the kernel line and upon logging in to KDE, I automatically execute:

echo OFF > /sys/kernel/debug/vgaswitcheroo/switch
sleep 2
systemctl start NetworkManager

Since then I have no troubles with my laptop overheating and my system isn't freezing anymore. Since I did all that right as I set up a new system, I'm not completely sure if that's related to the laptop not suspending/shutting down anymore or not (I'll go ahead now and try reversing it and see if it works then)...

Oh, and I'm unable to remove the three "tee" processes in any way. I can't kill them, terminate them, nothing, they simply stay there...

Last edited by keineeile (2014-09-30 01:03:36)

keineeile · 2014-09-30 01:12:56

Ha, removing "radeon.runpm=0" from the kernel line before booting works! Now I can suspend without any problems. Well, I'll keep it running for a little to see if the "DynPwr" feature of the kernel maybe actually decided to work for some reason and to see if my system freezes at some point again...

However, I'm wondering, why would disabling runpm cause that much headaches?

keineeile · 2014-10-01 15:59:41

Okay, so, enabling runpm (or rather: not disabling it) caused my laptop to heat up to on average 20°C more than before (plus it was louder), so simply leaving it enabled didn't really solve it for me.

I then tried what I found here in the wiki: https://wiki.archlinux.org/index.php/AT … management (runpm needs to be ENABLED for this to work)

# echo battery > /sys/class/drm/card0/device/power_dpm_state
# echo low > /sys/class/drm/card0/device/power_dpm_force_performance_level

Looking at /sys/kernel/debug/vgaswitcheroo/switch after running this, the state of the discrete card was stated as "DynOff", so it seemed to work - I thought. Cause this apparently causes the same issue as disabling runpm: I wasn't able to suspend or shutdown my system, it got stuck somehow trying to access the switched-off graphics card.

However, after some more digging around in the wiki, I found this solution https://wiki.archlinux.org/index.php/Hy … screte_GPU
1) Installed acpi_call
2) automatically load the module at boot
3) added the systemd tempfile
-> AND IT WORKS: The discrete card is now "disappeared" (e.g. there's no /sys/kernel/debug/vgaswitcheroo folder anymore), my laptop is quiet and cool as before, and (most importantly) I can suspend and shutdown without any troubles! Yay!

Thanks a million, lucke, for your help in troubleshooting! I hope, this solution helps you, too, elav!

Cheers!

Arch Linux

#1 2014-09-29 21:42:52

[SOLVED] System stuck on suspend/shutdown

#2 2014-09-29 23:21:15

Re: [SOLVED] System stuck on suspend/shutdown

#3 2014-09-30 00:00:49

Re: [SOLVED] System stuck on suspend/shutdown

#4 2014-09-30 00:11:45

Re: [SOLVED] System stuck on suspend/shutdown

#5 2014-09-30 00:20:17

Re: [SOLVED] System stuck on suspend/shutdown

#6 2014-09-30 01:02:50

Re: [SOLVED] System stuck on suspend/shutdown

#7 2014-09-30 01:12:56

Re: [SOLVED] System stuck on suspend/shutdown

#8 2014-10-01 15:59:41

Re: [SOLVED] System stuck on suspend/shutdown

Board footer