You are not logged in.
Wondering if I could enlist someone's assistance in trying to reproduce a strange issue with journalctl: On my system (Thinkpad T-43, last full pacman -Syyu about 3 days ago) it seems that the information displayed by journalctl is peculiarly inconsistent from boot to boot, even when no underlying boot configuration conditions have changed between the boot instances.
The inconsistencies take the form of randomly missing messages from the journal output. Below is an example, obtained after doing eight essentially identical boot-then-shutdown cycles, then displaying the filtered systemd journal via
$ journalctl -a --since "2013-05-18 00:00:00" | grep Start
The output of the above pipeline was then lightly hand-edited for readability: The only edits were to visually delimit the boot sequences with "BEGIN" and and "END" notations, including sequence numbers (#1 - #8), and a few lines of vertical spacing between each boot instance. Nothing else was changed, added, or removed.
======= BEGIN BOOT #1 ======== (81 lines)
May 18 09:55:11 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 09:55:11 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 09:55:11 huh systemd[1]: Starting Syslog Socket.
May 18 09:55:11 huh systemd[1]: Starting Remote File Systems.
May 18 09:55:11 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 09:55:11 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 09:55:11 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 09:55:11 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 09:55:11 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 09:55:11 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 09:55:11 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 09:55:11 huh systemd[1]: Starting Paths.
May 18 09:55:11 huh systemd[1]: Starting Journal Socket.
May 18 09:55:11 huh systemd[1]: Starting Setup Virtual Console...
May 18 09:55:11 huh systemd[1]: Starting Load Kernel Modules...
May 18 09:55:11 huh systemd[1]: Starting Apply Kernel Variables...
May 18 09:55:11 huh systemd[1]: Starting Journal Service...
May 18 09:55:11 huh systemd[1]: Started Journal Service.
May 18 09:55:11 huh systemd[1]: Starting udev Kernel Socket.
May 18 09:55:11 huh systemd[1]: Starting udev Control Socket.
May 18 09:55:11 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 09:55:11 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 09:55:11 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 09:55:11 huh systemd[1]: Started File System Check on Root Device.
May 18 09:55:11 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 09:55:11 huh systemd[1]: Started Apply Kernel Variables.
May 18 09:55:11 huh systemd[1]: Started Create static device nodes in /dev.
May 18 09:55:11 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 09:55:11 huh systemd[1]: Started udev Coldplug all Devices.
May 18 09:55:11 huh systemd[1]: Started udev Kernel Device Manager.
May 18 09:55:11 huh systemd[1]: Starting Load Random Seed...
May 18 09:55:11 huh systemd[1]: Started Load Kernel Modules.
May 18 09:55:11 huh systemd[1]: Started Load Random Seed.
May 18 09:55:12 huh systemd[1]: Started Setup Virtual Console.
May 18 09:55:13 huh systemd[1]: Starting Sound Card.
May 18 09:55:15 huh systemd[1]: Starting Cryptography Setup for swap...
May 18 09:55:16 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 09:55:17 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 09:55:17 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 09:55:17 huh systemd[1]: Started Cryptography Setup for swap.
May 18 09:55:17 huh systemd[1]: Starting Encrypted Volumes.
May 18 09:55:18 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 09:55:18 huh systemd[1]: Starting Swap.
May 18 09:55:18 huh systemd[1]: Starting Local File Systems.
May 18 09:55:18 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 09:55:18 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 09:55:18 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 09:55:18 huh systemd[1]: Starting System Initialization.
May 18 09:55:18 huh systemd[1]: Starting D-Bus System Message Bus Socket.
May 18 09:55:18 huh systemd[1]: Starting Sockets.
May 18 09:55:18 huh systemd[1]: Starting Timers.
May 18 09:55:18 huh systemd[1]: Started SSH Key Generation.
May 18 09:55:18 huh systemd[1]: Starting OpenSSH Daemon...
May 18 09:55:18 huh systemd[1]: Started OpenSSH Daemon.
May 18 09:55:18 huh systemd[1]: Starting Hack for mimicking rc.local under systemd...
May 18 09:55:18 huh systemd[1]: Starting Virtual console mouse server...
May 18 09:55:18 huh systemd[1]: Starting ATD daemon...
May 18 09:55:18 huh systemd[1]: Starting Network Time Service...
May 18 09:55:18 huh /usr/sbin/gpm[207]: Started gpm successfully. Entered daemon mode.
May 18 09:55:19 huh systemd[1]: Starting D-Bus System Message Bus...
May 18 09:55:19 huh systemd[1]: Started D-Bus System Message Bus.
May 18 09:55:19 huh systemd[1]: Starting Login Service...
May 18 09:55:19 huh systemd[1]: Starting cryptmount startup...
May 18 09:55:19 huh systemd[1]: Started Restore Sound Card State.
May 18 09:55:19 huh systemd[1]: Started Virtual console mouse server.
May 18 09:55:19 huh systemd[1]: Started ATD daemon.
May 18 09:55:19 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 09:55:19 huh systemd[1]: Starting Permit User Sessions...
May 18 09:55:19 huh systemd[1]: Started Permit User Sessions.
May 18 09:55:19 huh systemd[1]: Starting Getty on tty3...
May 18 09:55:19 huh systemd[1]: Started Getty on tty3.
May 18 09:55:19 huh systemd[1]: Starting Getty on tty2...
May 18 09:55:19 huh systemd[1]: Started Getty on tty2.
May 18 09:55:19 huh systemd[1]: Starting Getty on tty5...
May 18 09:55:19 huh systemd[1]: Started Getty on tty5.
May 18 09:55:19 huh systemd[1]: Starting Getty on tty1...
May 18 09:55:19 huh systemd[1]: Started Getty on tty1.
May 18 09:55:34 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 09:55:34 huh systemd[1]: Starting Multi-User System.
May 18 09:55:34 huh systemd[1]: Startup finished in 3.929s (kernel) + 25.422s (userspace) = 29.351s.
======= END BOOT #1 ========
======= BEGIN BOOT #2 ======== (84 lines)
May 18 10:34:51 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 10:34:51 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 10:34:51 huh systemd[1]: Starting Syslog Socket.
May 18 10:34:51 huh systemd[1]: Starting Remote File Systems.
May 18 10:34:51 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 10:34:51 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 10:34:51 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 10:34:51 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 10:34:51 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 10:34:51 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 10:34:51 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 10:34:51 huh systemd[1]: Starting Paths.
May 18 10:34:51 huh systemd[1]: Starting Journal Socket.
May 18 10:34:51 huh systemd[1]: Starting Setup Virtual Console...
May 18 10:34:51 huh systemd[1]: Starting Load Kernel Modules...
May 18 10:34:51 huh systemd[1]: Starting Apply Kernel Variables...
May 18 10:34:51 huh systemd[1]: Starting Journal Service...
May 18 10:34:51 huh systemd[1]: Started Journal Service.
May 18 10:34:51 huh systemd[1]: Starting udev Kernel Socket.
May 18 10:34:51 huh systemd[1]: Starting udev Control Socket.
May 18 10:34:51 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 10:34:51 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 10:34:51 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 10:34:51 huh systemd[1]: Started File System Check on Root Device.
May 18 10:34:51 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 10:34:51 huh systemd[1]: Started Apply Kernel Variables.
May 18 10:34:51 huh systemd[1]: Started udev Coldplug all Devices.
May 18 10:34:51 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 10:34:51 huh systemd[1]: Starting Load Random Seed...
May 18 10:34:51 huh systemd[1]: Started Load Random Seed.
May 18 10:34:51 huh systemd[1]: Started Create static device nodes in /dev.
May 18 10:34:51 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 10:34:52 huh systemd[1]: Started Load Kernel Modules.
May 18 10:34:52 huh systemd[1]: Started udev Kernel Device Manager.
May 18 10:34:52 huh systemd[1]: Starting Local File Systems (Pre).
May 18 10:34:52 huh systemd[1]: Started Setup Virtual Console.
May 18 10:34:54 huh systemd[1]: Starting Sound Card.
May 18 10:34:55 huh systemd[1]: Starting Cryptography Setup for swap...
May 18 10:34:56 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 10:34:57 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 10:34:58 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 10:34:58 huh systemd[1]: Started Cryptography Setup for swap.
May 18 10:34:58 huh systemd[1]: Starting Encrypted Volumes.
May 18 10:34:58 huh systemd[1]: Starting Swap.
May 18 10:34:58 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 10:34:59 huh systemd[1]: Starting Local File Systems.
May 18 10:34:59 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 10:34:59 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 10:34:59 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 10:34:59 huh systemd[1]: Starting System Initialization.
May 18 10:34:59 huh systemd[1]: Starting D-Bus System Message Bus Socket.
May 18 10:34:59 huh systemd[1]: Starting Sockets.
May 18 10:34:59 huh systemd[1]: Starting Timers.
May 18 10:34:59 huh systemd[1]: Started Periodic Command Scheduler.
May 18 10:34:59 huh systemd[1]: Started SSH Key Generation.
May 18 10:34:59 huh systemd[1]: Starting OpenSSH Daemon...
May 18 10:34:59 huh systemd[1]: Started OpenSSH Daemon.
May 18 10:34:59 huh systemd[1]: Starting Hack for mimicking rc.local under systemd...
May 18 10:34:59 huh systemd[1]: Starting Virtual console mouse server...
May 18 10:34:59 huh systemd[1]: Starting ATD daemon...
May 18 10:34:59 huh systemd[1]: Starting Network Time Service...
May 18 10:34:59 huh systemd[1]: Starting D-Bus System Message Bus...
May 18 10:34:59 huh systemd[1]: Started D-Bus System Message Bus.
May 18 10:34:59 huh systemd[1]: Starting Login Service...
May 18 10:34:59 huh systemd[1]: Starting cryptmount startup...
May 18 10:34:59 huh systemd[1]: Started Restore Sound Card State.
May 18 10:34:59 huh systemd[1]: Started ATD daemon.
May 18 10:34:59 huh systemd[1]: Started Virtual console mouse server.
May 18 10:34:59 huh /usr/sbin/gpm[210]: Started gpm successfully. Entered daemon mode.
May 18 10:34:59 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 10:34:59 huh systemd[1]: Starting Permit User Sessions...
May 18 10:34:59 huh systemd[1]: Started Permit User Sessions.
May 18 10:34:59 huh systemd[1]: Starting Getty on tty3...
May 18 10:34:59 huh systemd[1]: Started Getty on tty3.
May 18 10:34:59 huh systemd[1]: Starting Getty on tty2...
May 18 10:34:59 huh systemd[1]: Started Getty on tty2.
May 18 10:34:59 huh systemd[1]: Starting Getty on tty5...
May 18 10:34:59 huh systemd[1]: Started Getty on tty5.
May 18 10:34:59 huh systemd[1]: Starting Getty on tty1...
May 18 10:34:59 huh systemd[1]: Started Getty on tty1.
May 18 10:35:14 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 10:35:14 huh systemd[1]: Starting Multi-User System.
May 18 10:35:14 huh systemd[1]: Startup finished in 3.912s (kernel) + 25.695s (userspace) = 29.607s.
======= END BOOT #2 ========
======= BEGIN BOOT #3 ======== (54 lines)
May 18 10:42:22 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 10:42:22 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 10:42:22 huh systemd[1]: Starting Syslog Socket.
May 18 10:42:22 huh systemd[1]: Starting Remote File Systems.
May 18 10:42:22 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 10:42:22 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 10:42:22 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 10:42:22 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 10:42:22 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 10:42:22 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 10:42:22 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 10:42:22 huh systemd[1]: Starting Paths.
May 18 10:42:22 huh systemd[1]: Starting Journal Socket.
May 18 10:42:22 huh systemd[1]: Starting Setup Virtual Console...
May 18 10:42:22 huh systemd[1]: Starting Load Kernel Modules...
May 18 10:42:22 huh systemd[1]: Starting Apply Kernel Variables...
May 18 10:42:22 huh systemd[1]: Starting Journal Service...
May 18 10:42:22 huh systemd[1]: Started Journal Service.
May 18 10:42:22 huh systemd[1]: Starting udev Kernel Socket.
May 18 10:42:22 huh systemd[1]: Starting udev Control Socket.
May 18 10:42:22 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 10:42:22 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 10:42:22 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 10:42:22 huh systemd[1]: Started File System Check on Root Device.
May 18 10:42:22 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 10:42:22 huh systemd[1]: Started Apply Kernel Variables.
May 18 10:42:22 huh systemd[1]: Started Create static device nodes in /dev.
May 18 10:42:22 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 10:42:22 huh systemd[1]: Starting Load Random Seed...
May 18 10:42:22 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 10:42:22 huh systemd[1]: Started udev Coldplug all Devices.
May 18 10:42:22 huh systemd[1]: Started udev Kernel Device Manager.
May 18 10:42:23 huh systemd[1]: Started Load Kernel Modules.
May 18 10:42:23 huh systemd[1]: Started Setup Virtual Console.
May 18 10:42:24 huh systemd[1]: Starting Sound Card.
May 18 10:42:26 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 10:42:27 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 10:42:28 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 10:42:28 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 10:42:29 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 10:42:29 huh systemd[1]: Starting Local File Systems.
May 18 10:42:29 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 10:42:29 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 10:42:29 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 10:42:29 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 10:42:29 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 10:42:29 huh systemd[1]: Starting Encrypted Volumes.
May 18 10:42:30 huh systemd[1]: Starting Swap.
May 18 10:42:30 huh systemd[1]: Starting System Initialization.
May 18 10:42:30 huh /usr/sbin/gpm[209]: Started gpm successfully. Entered daemon mode.
May 18 10:42:44 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 10:42:44 huh systemd[1]: Starting Multi-User System.
May 18 10:42:44 huh systemd[1]: Startup finished in 3.881s (kernel) + 25.021s (userspace) = 28.902s.
======= END BOOT #3 ========
======= BEGIN BOOT #4 ======== (56 lines)
May 18 10:54:06 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 10:54:06 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 10:54:06 huh systemd[1]: Starting Syslog Socket.
May 18 10:54:06 huh systemd[1]: Starting Remote File Systems.
May 18 10:54:06 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 10:54:06 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 10:54:06 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 10:54:06 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 10:54:06 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 10:54:06 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 10:54:06 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 10:54:06 huh systemd[1]: Starting Paths.
May 18 10:54:06 huh systemd[1]: Starting Journal Socket.
May 18 10:54:06 huh systemd[1]: Starting Setup Virtual Console...
May 18 10:54:06 huh systemd[1]: Starting Load Kernel Modules...
May 18 10:54:06 huh systemd[1]: Starting Apply Kernel Variables...
May 18 10:54:06 huh systemd[1]: Starting Journal Service...
May 18 10:54:06 huh systemd[1]: Started Journal Service.
May 18 10:54:06 huh systemd[1]: Starting udev Kernel Socket.
May 18 10:54:06 huh systemd[1]: Starting udev Control Socket.
May 18 10:54:06 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 10:54:06 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 10:54:06 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 10:54:06 huh systemd[1]: Started File System Check on Root Device.
May 18 10:54:06 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 10:54:06 huh systemd[1]: Started udev Coldplug all Devices.
May 18 10:54:06 huh systemd[1]: Started Apply Kernel Variables.
May 18 10:54:06 huh systemd[1]: Started Create static device nodes in /dev.
May 18 10:54:06 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 10:54:06 huh systemd[1]: Started udev Kernel Device Manager.
May 18 10:54:07 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 10:54:07 huh systemd[1]: Starting Local File Systems (Pre).
May 18 10:54:07 huh systemd[1]: Starting Load Random Seed...
May 18 10:54:07 huh systemd[1]: Started Load Random Seed.
May 18 10:54:07 huh systemd[1]: Started Load Kernel Modules.
May 18 10:54:08 huh systemd[1]: Started Setup Virtual Console.
May 18 10:54:10 huh systemd[1]: Starting Sound Card.
May 18 10:54:11 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 10:54:11 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 10:54:12 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 10:54:13 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 10:54:14 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 10:54:14 huh systemd[1]: Starting Local File Systems.
May 18 10:54:14 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 10:54:14 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 10:54:14 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 10:54:14 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 10:54:14 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 10:54:14 huh systemd[1]: Starting Encrypted Volumes.
May 18 10:54:14 huh systemd[1]: Starting Swap.
May 18 10:54:14 huh systemd[1]: Starting System Initialization.
May 18 10:54:15 huh /usr/sbin/gpm[207]: Started gpm successfully. Entered daemon mode.
May 18 10:54:30 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 10:54:30 huh systemd[1]: Starting Multi-User System.
May 18 10:54:30 huh systemd[1]: Startup finished in 3.877s (kernel) + 25.476s (userspace) = 29.353s.
======= END BOOT #4 ========
======= BEGIN BOOT #5 ======== (53 lines)
May 18 11:05:26 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 11:05:26 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 11:05:26 huh systemd[1]: Starting Syslog Socket.
May 18 11:05:26 huh systemd[1]: Starting Remote File Systems.
May 18 11:05:26 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 11:05:26 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 11:05:26 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 11:05:26 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 11:05:26 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 11:05:26 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 11:05:26 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 11:05:26 huh systemd[1]: Starting Paths.
May 18 11:05:26 huh systemd[1]: Starting Journal Socket.
May 18 11:05:26 huh systemd[1]: Starting Setup Virtual Console...
May 18 11:05:26 huh systemd[1]: Starting Load Kernel Modules...
May 18 11:05:26 huh systemd[1]: Starting Apply Kernel Variables...
May 18 11:05:26 huh systemd[1]: Starting Journal Service...
May 18 11:05:26 huh systemd[1]: Started Journal Service.
May 18 11:05:26 huh systemd[1]: Starting udev Kernel Socket.
May 18 11:05:26 huh systemd[1]: Starting udev Control Socket.
May 18 11:05:26 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 11:05:26 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 11:05:26 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 11:05:26 huh systemd[1]: Started File System Check on Root Device.
May 18 11:05:26 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 11:05:26 huh systemd[1]: Started Apply Kernel Variables.
May 18 11:05:26 huh systemd[1]: Started Create static device nodes in /dev.
May 18 11:05:26 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 11:05:26 huh systemd[1]: Started udev Kernel Device Manager.
May 18 11:05:26 huh systemd[1]: Started udev Coldplug all Devices.
May 18 11:05:26 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 11:05:26 huh systemd[1]: Starting Local File Systems (Pre).
May 18 11:05:26 huh systemd[1]: Started Load Random Seed.
May 18 11:05:27 huh systemd[1]: Started Setup Virtual Console.
May 18 11:05:29 huh systemd[1]: Starting Sound Card.
May 18 11:05:30 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 11:05:30 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 11:05:31 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 11:05:32 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 11:05:32 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 11:05:32 huh systemd[1]: Starting Local File Systems.
May 18 11:05:32 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 11:05:32 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 11:05:32 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 11:05:33 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 11:05:34 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 11:05:34 huh systemd[1]: Starting Encrypted Volumes.
May 18 11:05:34 huh systemd[1]: Starting Swap.
May 18 11:05:35 huh /usr/sbin/gpm[218]: Started gpm successfully. Entered daemon mode.
May 18 11:05:50 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 11:05:50 huh systemd[1]: Starting Multi-User System.
May 18 11:05:50 huh systemd[1]: Startup finished in 3.940s (kernel) + 26.540s (userspace) = 30.481s.
======= END BOOT #5 ========
======= BEGIN BOOT #6 ======== (58 lines)
May 18 11:18:13 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 11:18:13 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 11:18:13 huh systemd[1]: Starting Syslog Socket.
May 18 11:18:13 huh systemd[1]: Starting Remote File Systems.
May 18 11:18:13 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 11:18:13 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 11:18:13 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 11:18:13 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 11:18:13 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 11:18:13 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 11:18:13 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 11:18:13 huh systemd[1]: Starting Paths.
May 18 11:18:13 huh systemd[1]: Starting Journal Socket.
May 18 11:18:13 huh systemd[1]: Starting Setup Virtual Console...
May 18 11:18:13 huh systemd[1]: Starting Load Kernel Modules...
May 18 11:18:13 huh systemd[1]: Starting Apply Kernel Variables...
May 18 11:18:13 huh systemd[1]: Starting Journal Service...
May 18 11:18:13 huh systemd[1]: Started Journal Service.
May 18 11:18:13 huh systemd[1]: Starting udev Kernel Socket.
May 18 11:18:13 huh systemd[1]: Starting udev Control Socket.
May 18 11:18:13 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 11:18:13 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 11:18:13 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 11:18:13 huh systemd[1]: Started File System Check on Root Device.
May 18 11:18:13 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 11:18:13 huh systemd[1]: Started udev Coldplug all Devices.
May 18 11:18:13 huh systemd[1]: Started Apply Kernel Variables.
May 18 11:18:13 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 11:18:13 huh systemd[1]: Starting Load Random Seed...
May 18 11:18:14 huh systemd[1]: Started Create static device nodes in /dev.
May 18 11:18:14 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 11:18:14 huh systemd[1]: Started udev Kernel Device Manager.
May 18 11:18:14 huh systemd[1]: Starting Local File Systems (Pre).
May 18 11:18:14 huh systemd[1]: Started Load Random Seed.
May 18 11:18:14 huh systemd[1]: Started Load Kernel Modules.
May 18 11:18:15 huh systemd[1]: Started Setup Virtual Console.
May 18 11:18:17 huh systemd[1]: Starting Sound Card.
May 18 11:18:18 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 11:18:19 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 11:18:19 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 11:18:20 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 11:18:20 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 11:18:21 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 11:18:21 huh systemd[1]: Starting Encrypted Volumes.
May 18 11:18:21 huh systemd[1]: Starting Local File Systems.
May 18 11:18:21 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 11:18:21 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 11:18:21 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 11:18:21 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 11:18:21 huh systemd[1]: Starting Swap.
May 18 11:18:21 huh systemd[1]: Starting System Initialization.
May 18 11:18:21 huh systemd[1]: Starting D-Bus System Message Bus Socket.
May 18 11:18:21 huh systemd[1]: Starting Sockets.
May 18 11:18:21 huh /usr/sbin/gpm[210]: Started gpm successfully. Entered daemon mode.
May 18 11:18:37 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 11:18:37 huh systemd[1]: Starting Multi-User System.
May 18 11:18:37 huh systemd[1]: Startup finished in 3.895s (kernel) + 25.521s (userspace) = 29.417s.
======= END BOOT #6 ========
======= BEGIN BOOT #7 ======== (84 lines)
May 18 13:36:30 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 13:36:30 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 13:36:30 huh systemd[1]: Starting Syslog Socket.
May 18 13:36:30 huh systemd[1]: Starting Remote File Systems.
May 18 13:36:30 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 13:36:30 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 13:36:30 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 13:36:30 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 13:36:30 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 13:36:30 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 13:36:30 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 13:36:30 huh systemd[1]: Starting Paths.
May 18 13:36:30 huh systemd[1]: Starting Journal Socket.
May 18 13:36:30 huh systemd[1]: Starting Setup Virtual Console...
May 18 13:36:30 huh systemd[1]: Starting Load Kernel Modules...
May 18 13:36:30 huh systemd[1]: Starting Apply Kernel Variables...
May 18 13:36:30 huh systemd[1]: Starting Journal Service...
May 18 13:36:30 huh systemd[1]: Started Journal Service.
May 18 13:36:30 huh systemd[1]: Starting udev Kernel Socket.
May 18 13:36:30 huh systemd[1]: Starting udev Control Socket.
May 18 13:36:30 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 13:36:30 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 13:36:30 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 13:36:30 huh systemd[1]: Started File System Check on Root Device.
May 18 13:36:30 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 13:36:30 huh systemd[1]: Started Apply Kernel Variables.
May 18 13:36:30 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 13:36:30 huh systemd[1]: Started udev Coldplug all Devices.
May 18 13:36:30 huh systemd[1]: Starting Load Random Seed...
May 18 13:36:31 huh systemd[1]: Started Load Random Seed.
May 18 13:36:31 huh systemd[1]: Started Create static device nodes in /dev.
May 18 13:36:31 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 13:36:31 huh systemd[1]: Started udev Kernel Device Manager.
May 18 13:36:31 huh systemd[1]: Starting Local File Systems (Pre).
May 18 13:36:32 huh systemd[1]: Started Load Kernel Modules.
May 18 13:36:32 huh systemd[1]: Started Setup Virtual Console.
May 18 13:36:34 huh systemd[1]: Starting Sound Card.
May 18 13:36:35 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 13:36:35 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 13:36:36 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 13:36:37 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 13:36:38 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 13:36:38 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 13:36:38 huh systemd[1]: Starting Encrypted Volumes.
May 18 13:36:38 huh systemd[1]: Starting Swap.
May 18 13:36:38 huh systemd[1]: Starting Local File Systems.
May 18 13:36:38 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 13:36:38 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 13:36:38 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 13:36:38 huh systemd[1]: Starting System Initialization.
May 18 13:36:38 huh systemd[1]: Starting D-Bus System Message Bus Socket.
May 18 13:36:38 huh systemd[1]: Starting Sockets.
May 18 13:36:38 huh systemd[1]: Starting Timers.
May 18 13:36:38 huh systemd[1]: Started Periodic Command Scheduler.
May 18 13:36:38 huh systemd[1]: Started SSH Key Generation.
May 18 13:36:38 huh systemd[1]: Starting OpenSSH Daemon...
May 18 13:36:38 huh systemd[1]: Started OpenSSH Daemon.
May 18 13:36:38 huh systemd[1]: Starting Hack for mimicking rc.local under systemd...
May 18 13:36:38 huh systemd[1]: Starting Virtual console mouse server...
May 18 13:36:38 huh systemd[1]: Starting ATD daemon...
May 18 13:36:38 huh systemd[1]: Starting Network Time Service...
May 18 13:36:38 huh /usr/sbin/gpm[208]: Started gpm successfully. Entered daemon mode.
May 18 13:36:38 huh systemd[1]: Starting D-Bus System Message Bus...
May 18 13:36:38 huh systemd[1]: Started D-Bus System Message Bus.
May 18 13:36:38 huh systemd[1]: Starting Login Service...
May 18 13:36:38 huh systemd[1]: Starting cryptmount startup...
May 18 13:36:38 huh systemd[1]: Started Restore Sound Card State.
May 18 13:36:38 huh systemd[1]: Started Virtual console mouse server.
May 18 13:36:38 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 13:36:38 huh systemd[1]: Starting Permit User Sessions...
May 18 13:36:39 huh systemd[1]: Started ATD daemon.
May 18 13:36:39 huh systemd[1]: Started Permit User Sessions.
May 18 13:36:39 huh systemd[1]: Starting Getty on tty3...
May 18 13:36:39 huh systemd[1]: Started Getty on tty3.
May 18 13:36:39 huh systemd[1]: Starting Getty on tty2...
May 18 13:36:39 huh systemd[1]: Started Getty on tty2.
May 18 13:36:39 huh systemd[1]: Starting Getty on tty5...
May 18 13:36:39 huh systemd[1]: Started Getty on tty5.
May 18 13:36:39 huh systemd[1]: Starting Getty on tty1...
May 18 13:36:55 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 13:36:55 huh systemd[1]: Starting Multi-User System.
May 18 13:36:55 huh systemd[1]: Startup finished in 3.909s (kernel) + 26.540s (userspace) = 30.449s.
======= END BOOT #7 ========
======= BEGIN BOOT #8 ======== (58 lines)
May 18 13:53:38 huh systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
May 18 13:53:38 huh systemd[1]: Started Forward Password Requests to Wall Directory Watch.
May 18 13:53:38 huh systemd[1]: Starting Syslog Socket.
May 18 13:53:38 huh systemd[1]: Starting Remote File Systems.
May 18 13:53:38 huh systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
May 18 13:53:38 huh systemd[1]: Starting LVM2 metadata daemon socket.
May 18 13:53:38 huh systemd[1]: Starting Delayed Shutdown Socket.
May 18 13:53:38 huh systemd[1]: Starting Device-mapper event daemon FIFOs.
May 18 13:53:38 huh systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
May 18 13:53:38 huh systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
May 18 13:53:38 huh systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
May 18 13:53:38 huh systemd[1]: Starting Paths.
May 18 13:53:38 huh systemd[1]: Starting Journal Socket.
May 18 13:53:38 huh systemd[1]: Starting Setup Virtual Console...
May 18 13:53:38 huh systemd[1]: Starting Load Kernel Modules...
May 18 13:53:38 huh systemd[1]: Starting Apply Kernel Variables...
May 18 13:53:38 huh systemd[1]: Starting Journal Service...
May 18 13:53:38 huh systemd[1]: Started Journal Service.
May 18 13:53:38 huh systemd[1]: Starting udev Kernel Socket.
May 18 13:53:38 huh systemd[1]: Starting udev Control Socket.
May 18 13:53:38 huh systemd[1]: Starting udev Coldplug all Devices...
May 18 13:53:38 huh systemd[1]: Started Set Up Additional Binary Formats.
May 18 13:53:38 huh systemd[1]: Starting Create static device nodes in /dev...
May 18 13:53:38 huh systemd[1]: Started File System Check on Root Device.
May 18 13:53:38 huh systemd[1]: Starting Remount Root and Kernel File Systems...
May 18 13:53:38 huh systemd[1]: Started Apply Kernel Variables.
May 18 13:53:38 huh systemd[1]: Started Create static device nodes in /dev.
May 18 13:53:38 huh systemd[1]: Starting udev Kernel Device Manager...
May 18 13:53:38 huh systemd[1]: Started udev Coldplug all Devices.
May 18 13:53:38 huh systemd[1]: Started udev Kernel Device Manager.
May 18 13:53:38 huh systemd[1]: Started Remount Root and Kernel File Systems.
May 18 13:53:38 huh systemd[1]: Starting Local File Systems (Pre).
May 18 13:53:38 huh systemd[1]: Starting Load Random Seed...
May 18 13:53:38 huh systemd[1]: Started Load Random Seed.
May 18 13:53:38 huh systemd[1]: Started Load Kernel Modules.
May 18 13:53:39 huh systemd[1]: Started Setup Virtual Console.
May 18 13:53:41 huh systemd[1]: Starting Sound Card.
May 18 13:53:42 huh systemd[1]: Starting File System Check on /dev/sda1...
May 18 13:53:43 huh systemd[1]: Started File System Check on /dev/sda1.
May 18 13:53:44 huh systemd[1]: Starting Cryptography Setup for cswap...
May 18 13:53:44 huh systemd[1]: Starting File System Check on /dev/sda10...
May 18 13:53:44 huh systemd[1]: Started File System Check on /dev/sda10.
May 18 13:53:45 huh systemd[1]: Starting Local File Systems.
May 18 13:53:45 huh systemd[1]: Starting Recreate Volatile Files and Directories...
May 18 13:53:45 huh systemd[1]: Starting Trigger Flushing of Journal to Persistent Storage...
May 18 13:53:45 huh systemd[1]: Started Recreate Volatile Files and Directories.
May 18 13:53:45 huh systemd[1]: Started Trigger Flushing of Journal to Persistent Storage.
May 18 13:53:45 huh systemd[1]: Started Cryptography Setup for cswap.
May 18 13:53:45 huh systemd[1]: Starting Encrypted Volumes.
May 18 13:53:46 huh systemd[1]: Starting Swap.
May 18 13:53:46 huh systemd[1]: Starting System Initialization.
May 18 13:53:46 huh /usr/sbin/gpm[212]: Started gpm successfully. Entered daemon mode.
May 18 13:54:03 huh systemd[1]: Started Postfix Mail Transport Agent.
May 18 13:54:03 huh systemd[1]: Starting Multi-User System.
May 18 13:54:03 huh systemd[1]: Startup finished in 3.898s (kernel) + 27.260s (userspace) = 31.158s.
======= END BOOT #8 ========
The distribution of the number of "Start" messages seems to be roughly bimodal:
BOOT #1: 81 lines ("long")
BOOT #2: 84 lines ("long")
BOOT #3: 54 lines ("short")
BOOT #4: 56 lines ("short")
BOOT #5: 53 lines ("short")
BOOT #6: 58 lines ("short")
BOOT #7: 84 lines ("long")
BOOT #8: 58 lines ("short")
Naturally, there is no expectation that these instances should be line-for-line identical: Obviously time ordering differences are to be expected due to the parallelism of the systemd boot process, udev device detection asynchronism, and so on. But even totally ignoring the time-ordering differences, there are content differences which, at least to me, were unexpected. Here are some examples:
a. All instances have "Starting System Initialization" message, except #5.
b. All instances have both "Starting" and "Started" messages for the
"Load Random Seed" service, except #3 (which has only the "Starting"
message but not the "Started" message) and #5 (which has only the
"Started" message but not "Starting" message.)
c. The "Starting D-Bus System Message Bus Socket" appears only in instances
#1, #2, #6, and #7.
d. The "Starting Hack for mimicking rc.local..." appears only in instances
#1, #2, #7.
e. All instances have "Starting Local File Systems (Pre)" except #1.
f. Only the "long" instances show the numerous "Starting Getty" messages.
This is not an exhaustive list of inconsistencies, but gives the general idea.
Googling did turn up a few reports of similar-sounding issues, but the descriptions were sparse and wasn't clear if they were really the same thing. A few mentioned seeing messages displayed on the boot console which did not also appear in the journal as expected, and that is also consistent with my observations.
I would be grateful if someone with a bit of free time could try to reproduce this. If others are seeing the same sort of thing, I'll file a detailed report on the bug tracker.
Some additional observations:
I am pretty sure -- but not 100% positive -- that behavior of this sort has been occurring since Day 1 of my conversion from sysV to systemd init, which was about a month ago. At the time of conversion, I had been running systemd V202-1, and since the last pacman synch a few days ago have been running V204-1. So my guess would be that this is not something related to or introduced in the current systemd version.
TTBOMK, each of the example boot instances placed the system in the same post-boot state: All services seem to have been started normally and consistently, even those whose "Starting/Started" messages are missing from the journal output. In other words, I don't have any reason to believe that the missing messages actually are related to missing or "unusual" service initiations.
TTBOMK, all service units reported all their messages normally and consistently to the console during boot. I cannot be 100% certain of this because of course the console output vanishes once the getty starts on tty1. But I am sure at least that all of the service unit messages for item (d) above ("Hack for mimicking rc.local") did appeared on the console each time, because I was specifically looking for those messages.
Steps to reproduce are essentially as described in the first few paragraphs: Reboot several times in a row -- changing nothing between boots -- and then filter the journal as described (suitably adjusting the date parameter of course).
Anyway, sorry for the long report but wanted to be complete about it.
TIA for any help in reproducing.
Offline
Dumb question: what's TTBOMK?
CLI Paste | How To Ask Questions
Arch Linux | x86_64 | GPT | EFI boot | refind | stub loader | systemd | LVM2 on LUKS
Lenovo x270 | Intel(R) Core(TM) i5-7200U CPU @ 2.50GHz | Intel Wireless 8265/8275 | US keyboard w/ Euro | 512G NVMe INTEL SSDPEKKF512G7L
Offline
Not a dumb question; dumb of me to use obscure acronyms, sorry. "To The Best Of My Knowledge"
Offline
Free bump following closed thread: https://bbs.archlinux.org/viewtopic.php?id=164379
My Arch Linux Stuff • Forum Etiquette • Community Ethos - Arch is not for everyone
Offline
I made some comments on the systemd bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=66664#c1.
Offline
Yes, saw them, thanks. Do you want to continue the dialog here or on the FDO bugzilla? Either is fine with me, just let me know so we don't have to duplicate posts.
Offline