Arch Linux

j33205

Member

Registered: 2015-06-28

Posts: 38

Yet Another Powering Off Issue

Hello. I've done some quick searches for similar problems. I found a few but none applicable to my specific issue so I present here.

I upgraded the whole system this past weekend (among which I believe were the Nvidia prop drivers, Xorg, and others). After which I am now unable to completely power down the system without issue. I'm running Openbox via Xorg and I use the Nvidia proprietary drivers as mentioned. I usually poweroff/reboot through a GUI I made that calls the "poweroff" and "reboot" commands but I've tried manually using "systemctl poweroff" and "telinit 0" with the same issue.

Normally when I poweroff I get 1 or 2 tty messages on the progress of the shutdown that usually go so fast that I can't read them but are noticeable, and the whole poweroff is pretty instantaneous. Now when I try to poweroff, I don't get any messages and Arch immediately stops my display such that the monitor flags a "no signal" and shuts off, BUT my rig stays powered on (fans, keyboard lights, etc.) and I have no control. Sometimes if I wait long enough (the last I tried it took 2 minutes) it will eventually power all the way down.

This is the output of "journalctl -r" (so in reverse) from the point of reboot invocation to the eventual shutdown:

-- Reboot --
Nov 24 16:28:58 ArchDotLinux systemd-journald[183]: Journal stopped
Nov 24 16:28:58 ArchDotLinux systemd[1]: Set hardware watchdog to 10min.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Hardware watchdog 'iTCO_wdt', version 0
Nov 24 16:28:58 ArchDotLinux systemd[1]: Shutting down.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Starting Reboot...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Reached target Final Step.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Reached target Shutdown.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Create Static Device Nodes in /dev.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Remount Root and Kernel File Systems.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Local File Systems (Pre).
Nov 24 16:28:58 ArchDotLinux systemd[1]: Reached target Unmount All Filesystems.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Unmounted /home/dot/LocalDot.
Nov 24 16:28:58 ArchDotLinux ntfs-3g[292]: Unmounting /dev/sdb1 (LocalDot)
Nov 24 16:28:58 ArchDotLinux systemd[1]: Unmounted /run/user/1000.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Failed unmounting Temporary Directory.
Nov 24 16:28:58 ArchDotLinux systemd[1]: tmp.mount: Mount process exited, code=exited status=32
Nov 24 16:28:58 ArchDotLinux umount[29634]: use the device is found by lsof(8) or fuser(1).)
Nov 24 16:28:58 ArchDotLinux umount[29634]: (In some cases useful info about processes that
Nov 24 16:28:58 ArchDotLinux umount[29634]: umount: /tmp: target is busy
Nov 24 16:28:58 ArchDotLinux systemd[1]: Unmounting Temporary Directory...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Unmounting /run/user/1000...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Unmounting /home/dot/LocalDot...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Local File Systems.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Create Volatile Files and Directories.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Network Time Synchronization.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Update UTMP about System Boot/Shutdown.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Load/Save Random Seed.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Removed slice User and Session Slice.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Forward Password Requests to Wall Directory Watch.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Paths.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Slices.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Setup Virtual Console.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Apply Kernel Variables.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopping Update UTMP about System Boot/Shutdown...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Encrypted Volumes.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Swap.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopping Network Time Synchronization...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopping Load/Save Random Seed...
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target System Initialization.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Closed D-Bus System Message Bus Socket.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Sockets.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped target Basic System.
Nov 24 16:28:58 ArchDotLinux systemd[1]: Stopped Login Service.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopped target Remote File Systems.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopped Permit User Sessions.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Removed slice user-1000.slice.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopping Login Service...
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopping Permit User Sessions...
Nov 24 16:28:57 ArchDotLinux systemd[1]: session-c1.scope: Unit entered failed state.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopped Session c1 of user dot.
Nov 24 16:28:57 ArchDotLinux systemd[1]: session-c1.scope: Still around after SIGKILL. Ignoring.
Nov 24 16:27:27 ArchDotLinux systemd[1]: session-c1.scope: Stopping timed out. Killing.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: Failed with result 'timeout'.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: Unit entered failed state.
Nov 24 16:27:27 ArchDotLinux systemd[1]: Stopped User Manager for UID 1000.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: State 'stop-sigterm' timed out. Killing.
Nov 24 16:27:27 ArchDotLinux systemd[333]: dbus.service: State 'stop-final-sigterm' timed out. Killing.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Removed slice user-1000.slice.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopping Login Service...
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopping Permit User Sessions...
Nov 24 16:28:57 ArchDotLinux systemd[1]: session-c1.scope: Unit entered failed state.
Nov 24 16:28:57 ArchDotLinux systemd[1]: Stopped Session c1 of user dot.
Nov 24 16:28:57 ArchDotLinux systemd[1]: session-c1.scope: Still around after SIGKILL. Ignoring.
Nov 24 16:27:27 ArchDotLinux systemd[1]: session-c1.scope: Stopping timed out. Killing.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: Failed with result 'timeout'.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: Unit entered failed state.
Nov 24 16:27:27 ArchDotLinux systemd[1]: Stopped User Manager for UID 1000.
Nov 24 16:27:27 ArchDotLinux systemd[1]: user@1000.service: State 'stop-sigterm' timed out. Killing.
Nov 24 16:27:27 ArchDotLinux systemd[333]: dbus.service: State 'stop-final-sigterm' timed out. Killing.
Nov 24 16:25:59 ArchDotLinux kernel: nvidia-modeset: ERROR: GPU:0: Idling EVO timed out: 0x0000957d:0:0:0x00004000
Nov 24 16:25:58 ArchDotLinux systemd[1]: Removed slice system-dhcpcd.slice.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped dhcpcd on enp0s25.
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: waiting for pid 419 to exit
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: sending signal TERM to pid 419
Nov 24 16:25:58 ArchDotLinux dhcpcd[419]: dhcpcd exited
Nov 24 16:25:58 ArchDotLinux dhcpcd[419]: enp0s25: removing interface
Nov 24 16:25:58 ArchDotLinux dhcpcd[419]: received SIGTERM, stopping
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: waiting for pid 419 to exit
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: sending signal TERM to pid 419
Nov 24 16:25:58 ArchDotLinux systemd[1]: Removed slice system-getty.slice.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopping dhcpcd on enp0s25...
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped target Network.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped SSH Key Generation.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Save/Restore Sound Card State.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Started Generate shutdown-ramfs.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Authorization Manager.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Daemon for power management.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped OpenSSH Daemon.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Getty on tty1.
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: ==> Build complete.
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: -> Running build hook: [sd-shutdown]
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: ==> Starting build: none
Nov 24 16:25:57 ArchDotLinux systemd[333]: Stopped target Default.
Nov 24 16:25:57 ArchDotLinux systemd[333]: Stopping D-Bus User Message Bus...
Nov 24 16:25:58 ArchDotLinux org.a11y.atspi.Registry[477]: after 8385 requests (8385 known processed) with 0 events remaining.
Nov 24 16:25:57 ArchDotLinux org.a11y.atspi.Registry[477]: XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped D-Bus System Message Bus.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target System Time Synchronized.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily verification of password and group files.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Getty on tty1...
Nov 24 16:25:57 ArchDotLinux systemd-logind[302]: Failed to abandon session scope: Transport endpoint is not connected
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping OpenSSH Daemon...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily rotation of log files.
Nov 24 16:25:57 ArchDotLinux sshd[420]: Received signal 15; terminating.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Save/Restore Sound Card State...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping D-Bus System Message Bus...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Starting Generate shutdown-ramfs...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping User Manager for UID 1000...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Daemon for power management...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily man-db cache update.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Login Prompts.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped D-Bus System Message Bus.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target System Time Synchronized.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily verification of password and group files.
Nov 24 16:25:58 ArchDotLinux dhcpcd[419]: received SIGTERM, stopping
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: waiting for pid 419 to exit
Nov 24 16:25:58 ArchDotLinux dhcpcd[29594]: sending signal TERM to pid 419
Nov 24 16:25:58 ArchDotLinux systemd[1]: Removed slice system-getty.slice.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopping dhcpcd on enp0s25...
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped target Network.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped SSH Key Generation.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Save/Restore Sound Card State.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Started Generate shutdown-ramfs.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Authorization Manager.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Daemon for power management.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped OpenSSH Daemon.
Nov 24 16:25:58 ArchDotLinux systemd[1]: Stopped Getty on tty1.
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: ==> Build complete.
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: -> Running build hook: [sd-shutdown]
Nov 24 16:25:58 ArchDotLinux mkinitcpio[29543]: ==> Starting build: none
Nov 24 16:25:57 ArchDotLinux systemd[333]: Stopped target Default.
Nov 24 16:25:57 ArchDotLinux systemd[333]: Stopping D-Bus User Message Bus...
Nov 24 16:25:58 ArchDotLinux org.a11y.atspi.Registry[477]: after 8385 requests (8385 known processed) with 0 events remaining.
Nov 24 16:25:57 ArchDotLinux org.a11y.atspi.Registry[477]: XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped D-Bus System Message Bus.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target System Time Synchronized.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily verification of password and group files.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Getty on tty1...
Nov 24 16:25:57 ArchDotLinux systemd-logind[302]: Failed to abandon session scope: Transport endpoint is not connected
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping OpenSSH Daemon...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily rotation of log files.
Nov 24 16:25:57 ArchDotLinux sshd[420]: Received signal 15; terminating.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Save/Restore Sound Card State...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping D-Bus System Message Bus...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Starting Generate shutdown-ramfs...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping User Manager for UID 1000...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Daemon for power management...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped Daily man-db cache update.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Login Prompts.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Multi-User System.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Sound Card.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Authorization Manager...
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopping Session c1 of user dot.
Nov 24 16:25:57 ArchDotLinux login[308]: pam_unix(login:session): session closed for user dot
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Graphical Interface.
Nov 24 16:25:57 ArchDotLinux systemd[1]: Stopped target Timers.
Nov 24 16:25:57 ArchDotLinux systemd-logind[302]: System is rebooting.
Nov 24 16:25:57 ArchDotLinux polkitd[29533]: Acquired the name org.freedesktop.PolicyKit1 on the system bus
Nov 24 16:25:57 ArchDotLinux systemd[1]: Started Authorization Manager.
Nov 24 16:25:57 ArchDotLinux dbus[299]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Nov 24 16:25:57 ArchDotLinux polkitd[29533]: Finished loading, compiling and executing 1 rules
Nov 24 16:25:57 ArchDotLinux polkitd[29533]: Loading rules from directory /usr/share/polkit-1/rules.d
Nov 24 16:25:57 ArchDotLinux polkitd[29533]: Loading rules from directory /etc/polkit-1/rules.d
Nov 24 16:25:57 ArchDotLinux polkitd[29533]: Started polkitd version 0.113
Nov 24 16:25:57 ArchDotLinux systemd[1]: Starting Authorization Manager...
Nov 24 16:25:57 ArchDotLinux dbus[299]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service'

Note the errors on lines 16, 61, 84, & 91. Related to "session scope", X server, Nvidia, and unmounting TempDir.

I'm not sure where to go from here so any help is appreciated. If any other logs or such things might help let me know.

boban_dj

Member

Registered: 2015-03-17

Posts: 150

Re: Yet Another Powering Off Issue

Hi,
I think this is the same issue. If you read down the thread.
https://bbs.archlinux.org/viewtopic.php?id=203112

mexus

Member

Registered: 2015-11-28

Posts: 14

Re: Yet Another Powering Off Issue

Hi,
Do you experience any issues with switching between text/graphical ttys? Like here: https://bbs.archlinux.org/viewtopic.php?id=205613

boban_dj

Member

Registered: 2015-03-17

Posts: 150

Re: Yet Another Powering Off Issue

@mexus, I have not had any issues switching, but only sometimes strange shutdown 'sessions'. This was also after recent frequent updates.
Before that anytime I shutdown, it just shuts down immediate.

j33205

Member

Registered: 2015-06-28

Posts: 38

Re: Yet Another Powering Off Issue

@boban_dj, I skimmed through that post and I'm not sure it's the same issue but I might go through it again later and try some stuff. It seems that in that thread there's a lot of talk about the 90s delay on shutdown. I believe this the one where it displays and error and a count down timer for 90s, I've had this issue before (unrelated to this topic) but is not my current issue. Mine blanks my screen and waits a random amount of time to shutdown, one time one minute another it was 6 minutes. I also think I get the same journalctl errors and warnings that I list above each time.

@mexus, sounds like similar problems, similar symptoms anyway. Ok so didn't know this till now when I tried but I too am having tty/graphical UI problems. I auto-login getty@tty1 and it also runs startx automatically so tty1 has Xorg running by default.

This is what I tried in terms of some diagnostics. With Xorg on tty1 I switched to tty2 and tty3 and logged in fine but when I tried to get back to tty1 where Xorg was the system basically froze, blank screen and no control. I could still SSH in so I rebooted from there (still took a while to actually power down). Once back in I tried killing Xorg from tty2 and going back to tty1 same thing happened. Once back in I killed the Xorg session locally on tty1 and then tried switching back and forth from tty1 to tty2, no problems. Tried rebooting from tty1 with no Xorg, no problems, normal immediate shutdown. It seems that without Xorg I do not have problems and with it I do...If i need to do anything other than actually using Xorg.

I haven't tired anything in the way of solutions and rolling back doesn't seem to be the answer so I'm holding off on that one.

EDIT: should be "without Xorg I DO NOT have problems and with it I do"

Last edited by j33205 (2015-12-30 00:12:06)

boban_dj

Member

Registered: 2015-03-17

Posts: 150

Re: Yet Another Powering Off Issue

Hi,
Maybe you can try with another WM,  xfce4 and see if same happens with blank screen.

mexus

Member

Registered: 2015-11-28

Posts: 14

Re: Yet Another Powering Off Issue

@j33205,
I still don't have any progress
BTW, looks like the issue is not happening to everyone, only to chosen ones)) maybe it's related somehow to a specifig videocard? Mine is GTX 570, what's yours?

j33205

Member

Registered: 2015-06-28

Posts: 38

Re: Yet Another Powering Off Issue

@boban_dj,  You mean as opposed to Openbox? I guess I'll try some others see what happens.

@mexus,  No progress here either, at this point I'm kinda just waiting for a new systemd update and crossing my fingers. My GPU is the GTX 960, seems unrelated though NVIDIA did flag for some reason.

boban_dj

Member

Registered: 2015-03-17

Posts: 150

Re: Yet Another Powering Off Issue

From reading your logs again, it might be a problem with the nvidia driver. Did you install the nvidia driver with pacman?
My machines have nvidia cards (nvs440,Quadro FX 4800). Installed as stated from the nvidia arch wiki . From my experience with 'blank screen' problems,
and this line in your log skips 1:30sec:

Nov 24 16:25:59 ArchDotLinux kernel: nvidia-modeset: ERROR: GPU:0: Idling EVO timed out: 0x0000957d:0:0:0x00004000

Maybe reinstall all the drivers going carefully through the nvidia arch wiki is what I would try. Also post output:

lspci -k | grep -A 2 -E "(VGA|3D)"

j33205

Member

Registered: 2015-06-28

Posts: 38

Re: Yet Another Powering Off Issue

Yes I did install the NVIDIA driver with pacman following the wiki. I didn't have this problem for months having the same software and hardware the entire time so I wonder what prompted it to start happening after that particular barrage of updates. I will give reinstallation of NVIDIA drivers a try when I have some time next week and report back.

Also here is the output to lspci:

01:00.0 VGA compatible controller: NVIDIA Corporation GM206 [GeForce GTX 960] (rev a1)
	Subsystem: eVga.com. Corp. Device 2966
	Kernel driver in use: nvidia

EDIT:
Forgot to mention that I tried a different WM really quick, only did one, XFCE4. Installed, restarted session with xfce instead of Openbox, and immediately (without opening any other programs) tried powering down using the xfce menu. Had the same exact problem.

Last edited by j33205 (2015-12-30 17:07:16)