Sometimes it takes 2 seconds to reboot, other times it pauses for 2 minutes before rebooting. How can I identify what causes the sporadic 2 minute delay? I’m tempted to just hit the reset button, as on the screen I can see that all filesystems were unmounted (or mounted read-only, or whatever the message is).
Hi
Maintenance, rpm database backup, purging kernels, disk maintenance…
systemd-analyze blame
systemd-analyze critical-chain
Aren’t those start-up time tasks? I’m referring to shutdown time. After all disks are unmounted, there can’t be much left to do. But it stalls for 2 minutes sometimes. Last line of “journalctl -b -1” shows “Journal stopped” but that’s where it then hangs for a couple minutes before rebooting. How can I check for any offensive processes that might not be responding well for SIGTERM at that point?
Happens to me too often, but with no repeatability. It’s typically failing to stop service(s) that never started in the first place. It’s worse when happening at shutdown time. When the low battery buzzer goes off on the UPS, data integrity can’t be risked on account of systemd foolishness. Now should mean now whether reboot or shutdown.
If it was repeatable and I could investigate on my schedule rather than on systemd’s, I’d be looking for reasons for start failures at boot time, and start failures for services triggered by boot but purposely delayed to not impede login readiness.
How often is sometimes? Does it seem to be more or most often on the reboot that follows a new kernel installation?
I would place my bet on: Btrfs …
- The systemd Btrfs maintenance services – triggered by the following timers: btrfs-balance.timer; btrfs-scrub.timer; btrfs-trim.timer …
Also, please check the File System ID values – they should be one of “Linux Native”, “Linux swap” or “EFI-System_Partition”.
- If the system was, or is, Dual Boot, there is a small possibility (due to older openSUSE versions) that, the File System ID can have a value indicating a Microsoft File System …
It can be, I have everything in ext4 and when I switch off it is instantaneous
For diagnosing shutdown I use “journalctl -b -1 -u init.scope”. Umounting can take some time, needs to wait for sync:
Feb 26 05:07:05 erlangen systemd[1]: Stopped target Local File Systems.
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /home-HDD…
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /Tumbleweed-SSD…
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /Tumbleweed-HDD…
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /boot/efi…
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /home-SSD…
Feb 26 05:07:05 erlangen systemd[1]: Unmounting /home…
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-path/pci-0000:00:17.0-scsi-0:0:0:0-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-path/pci-0000:00:17.0-ata-1-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-partuuid/410b7947-08ad-4fb7-93ea-854f63a3bf78.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/wwn-0x50014ee262d2e71e-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/scsi-SATA_WDC_WD40EZRX-22S_WD-WCC4E2FYXSNV-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/scsi-350014ee262d2e71e-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/scsi-1ATA_WDC_WD40EZRX-22SPEB0_WD-WCC4E2FYXSNV-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/scsi-0ATA_WDC_WD40EZRX-22S_WD-WCC4E2FYXSNV-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-id/ata-WDC_WD40EZRX-22SPEB0_WD-WCC4E2FYXSNV-part2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/sda2.
Feb 26 05:07:05 erlangen systemd[1]: Deactivated swap /dev/disk/by-uuid/3bfe28c8-c708-4859-9222-94b0ea4bddca.
Feb 26 05:07:05 erlangen systemd[1]: Unmounted /boot/efi.
Feb 26 05:07:05 erlangen systemd[1]: Unmounted /home-SSD.
Feb 26 05:07:05 erlangen systemd[1]: Unmounted /Tumbleweed-SSD.
Feb 26 05:07:06 erlangen systemd[1]: Unmounted /home.
Feb 26 05:07:14 erlangen systemd[1]: Unmounted /Tumbleweed-HDD.
Feb 26 05:07:15 erlangen systemd[1]: Unmounted /home-HDD.
Feb 26 05:07:15 erlangen systemd[1]: Reached target Unmount All Filesystems.
Feb 26 05:07:15 erlangen systemd[1]: Stopped target Local File Systems (Pre).
Feb 26 05:07:15 erlangen systemd[1]: Stopped Create Static Device Nodes in /dev.
Feb 26 05:07:15 erlangen systemd[1]: Stopped Remount Root and Kernel File Systems.
Feb 26 05:07:15 erlangen systemd[1]: Reached target Shutdown.
Feb 26 05:07:15 erlangen systemd[1]: Reached target Final Step.
Feb 26 05:07:15 erlangen systemd[1]: Starting Reboot…
Feb 26 05:07:15 erlangen systemd[1]: Shutting down.
Feb 26 05:07:15 erlangen systemd[1]: Hardware watchdog ‘iTCO_wdt’, version 0
Feb 26 05:07:15 erlangen systemd[1]: Set hardware watchdog to 10min.
I only use ext4, no btrfs/xfs partitions. Using systemctl, I disabled two btrfs services, and two snapper services. The following reboot was fast. I’m positive that I’ve previously disabled those services though. Maybe some particular rpm upgrade is reviving them. I’ll keep an eye out.
On Tue 26 Feb 2019 09:06:04 PM CST, xorbe wrote:
I only use ext4, no btrfs/xfs partitions. Using systemctl, I disabled
two btrfs services, and two snapper services. The following reboot was
fast. I’m positive that I’ve previously disabled those services though.
Maybe some particular rpm upgrade is reviving them. I’ll keep an eye
out.
Hi
Just to ensure they don’t get re-activate, 'mask them as well;
systemctl mask <some_service>
–
Cheers Malcolm °¿° SUSE Knowledge Partner (Linux Counter #276890)
SLES 15 | GNOME Shell 3.26.2 | 4.12.14-25.28-default
If you find this post helpful and are logged into the web interface,
please show your appreciation and click on the star below… Thanks!
So now my tumbleweed VM is pausing 2 minutes at reboot time (but my main box is fine). What the VM shows is “waiting for User Manager” each time. What is that, and why is it waiting? Same as this reddit post but it’s a VM so no nVidia driver is installed. https://www.reddit.com/r/Fedora/comments/8qgz92/user_manager_delaying_reboot/
If I can’t find the root cause, how can I lower the delay from 120 seconds to 20? 2 minutes is just obnoxious.
systemctl status user-1000.slice will display processes to be terminated appropriately. Plasma will try to save the session. It will wait until state is saved or timeout is reached. Use system settings to configure logout behavior.
Found that /etc/systemd/system.conf has several commented out options that can be configured and enabled wrt timeouts. Found another post that suggested runaway baloo (kde5 file indexer) causes this, fix with “balooctl disable”. Interestingly I already have file search disabled on the main box, not sure about the VM session, will check on that later.
That recently happened here. But it was fine after the next boot. I think that was the result of an update, and something getting slightly broken by the version mismatch between the running files and the updated files.
I had that logind shutdown delay for two users. Fortunately, the delay of the two was concurrent, not sequential.
One of the two users was me. The other user was “gdm”, which runs the GDM login manager. I very much doubt that user “gdm” was running “baloo”.
The following is a filtered record of user shutdown:
erlangen:~ # journalctl -b -1 -u user@1000.service
-- Logs begin at Mon 2019-02-11 16:20:00 CET, end at Wed 2019-03-20 13:41:56 CET. --
Mar 20 08:50:38 erlangen systemd[1]: Starting User Manager for UID 1000...
...
Mar 19 14:09:04 erlangen systemd[1]: Stopping User Manager for UID 1000...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Portal service...
Mar 19 14:09:04 erlangen systemd[1468]: Stopped target Default.
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Tracker metadata database store and lookup manager...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service...
Mar 19 14:09:04 erlangen obexd[1961]: Terminating
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service - Apple File Conduit monitor...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping sandboxed app permission store...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Accessibility services bus...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping D-Bus User Message Bus...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Save jAlbum Project Files...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping flatpak document portal service...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service - disk device monitor...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service - GNOME Online Accounts monitor...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service - Media Transfer Protocol monitor...
Mar 19 14:09:04 erlangen systemd[1468]: Stopping Virtual filesystem service - digital camera monitor...
Mar 19 14:09:04 erlangen systemd[1468]: save-jalbum-settings.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: save-jalbum-settings.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Save jAlbum Project Files.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-daemon.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-gphoto2-volume-monitor.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-gphoto2-volume-monitor.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service - digital camera monitor.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-goa-volume-monitor.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-goa-volume-monitor.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service - GNOME Online Accounts monitor.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-afc-volume-monitor.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-afc-volume-monitor.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service - Apple File Conduit monitor.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-mtp-volume-monitor.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-mtp-volume-monitor.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service - Media Transfer Protocol monitor.
Mar 19 14:09:04 erlangen systemd[1468]: xdg-permission-store.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: xdg-permission-store.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped sandboxed app permission store.
Mar 19 14:09:04 erlangen tracker-store[1732]: Received signal:15->'Terminated'
Mar 19 14:09:04 erlangen tracker-store[1732]: OK
Mar 19 14:09:04 erlangen systemd[1468]: tracker-store.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Tracker metadata database store and lookup manager.
Mar 19 14:09:04 erlangen systemd[1468]: at-spi-dbus-bus.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Accessibility services bus.
Mar 19 14:09:04 erlangen systemd[1468]: run-user-1000-doc.mount: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: run-user-1000-gvfs.mount: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: xdg-document-portal.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped flatpak document portal service.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-daemon.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service.
Mar 19 14:09:04 erlangen systemd[1468]: dbus.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped D-Bus User Message Bus.
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-udisks2-volume-monitor.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: gvfs-udisks2-volume-monitor.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Virtual filesystem service - disk device monitor.
Mar 19 14:09:04 erlangen systemd[1468]: xdg-desktop-portal.service: Main process exited, code=killed, status=15/TERM
Mar 19 14:09:04 erlangen systemd[1468]: xdg-desktop-portal.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped Portal service.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped target Basic System.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped target Timers.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped target Paths.
Mar 19 14:09:04 erlangen systemd[1468]: Stopped target Sockets.
Mar 19 14:09:04 erlangen systemd[1468]: dbus.socket: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Closed D-Bus User Message Bus Socket.
Mar 19 14:09:04 erlangen systemd[1468]: Reached target Shutdown.
Mar 19 14:09:04 erlangen systemd[1468]: systemd-exit.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1468]: Started Exit the Session.
Mar 19 14:09:04 erlangen systemd[1468]: Reached target Exit the Session.
Mar 19 14:09:04 erlangen systemd[1469]: pam_unix(systemd-user:session): session closed for user karl
Mar 19 14:09:04 erlangen systemd[1]: user@1000.service: Succeeded.
Mar 19 14:09:04 erlangen systemd[1]: Stopped User Manager for UID 1000.
erlangen:~ #
Shut down is virtually immediate. In case of delayed stopping investigate details of the unit involved.