Edit: I couldn't find out why this weird effect happens, but I found the culprit of the actual problem (slow bootup) to be the same as described here:

I will still leave this open as the question remains.


I'm trying to analyze the startup time of a friend whose laptop "suddenly" became slower.

dmesg shows me this:

[ 2.348642] usb 1-8: New USB device found, idVendor=0bda, idProduct=0129 [ 2.348644] usb 1-8: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 2.348645] usb 1-8: Product: USB2.0-CRW [ 2.348646] usb 1-8: Manufacturer: Generic [ 2.348648] usb 1-8: SerialNumber: 20100201396000000 [ 2.352517] usbcore: registered new interface driver rtsx_usb [ 2.844331] [drm] RC6 on [ 34.760930] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) [ 34.933397] ip_tables: (C) 2000-2006 Netfilter Core Team [ 35.006893] systemd[1]: systemd 237 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) 

which also confirms manual measurements and the output of systemd-analyze saying that the laptop spends roughly 35 secs in the kernel for bootup, the remaining ~12 secs in user are due to a unit waiting for NetworkManager getting online -- but they do not matter here. Anyhow, with an SSD the laptop shouldn't spend so long booting up, especially not for mounting the filesystem.

I also ran journalctl -k which should give the same output, but I get:

Aug 30 21:13:45 laptop kernel: usb 1-8: New USB device found, idVendor=0bda, idProduct=0129 Aug 30 21:13:45 laptop kernel: usb 1-8: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 30 21:13:45 laptop kernel: usb 1-8: Product: USB2.0-CRW Aug 30 21:13:45 laptop kernel: usb 1-8: Manufacturer: Generic Aug 30 21:13:45 laptop kernel: usb 1-8: SerialNumber: 20100201396000000 Aug 30 21:13:45 laptop kernel: usbcore: registered new interface driver rtsx_usb Aug 30 21:13:45 laptop kernel: [drm] RC6 on Aug 30 21:13:45 laptop kernel: EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) Aug 30 21:13:45 laptop kernel: ip_tables: (C) 2000-2006 Netfilter Core Team Aug 30 21:13:45 laptop systemd[1]: systemd 237 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) 

... so there's no such time gap from journalctls perspective.

I have no idea where this time difference might come from.

1 Answer

To get the same timestamp format as dmesg with journalctl, try

journalctl -o short-monotonic -b 

Example output with journalctl

... [ 1.003458] marvin kernel: usb usb1: New USB device found, idVendor=1d6b, idProduct=0002 [ 1.003460] marvin kernel: usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.003461] marvin kernel: usb usb1: Product: xHCI Host Controller [ 1.003462] marvin kernel: usb usb1: Manufacturer: Linux 4.15.0-33-generic xhci-hcd [ 1.003463] marvin kernel: usb usb1: SerialNumber: 0000:00:14.0 [ 1.003596] marvin kernel: hub 1-0:1.0: USB hub found [ 1.003611] marvin kernel: hub 1-0:1.0: 16 ports detected [ 1.004505] marvin kernel: xhci_hcd 0000:00:14.0: xHCI Host Controller [ 1.004507] marvin kernel: xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2 [ 1.004510] marvin kernel: xhci_hcd 0000:00:14.0: Host supports USB 3.0 SuperSpeed [ 1.004533] marvin kernel: usb usb2: New USB device found, idVendor=1d6b, idProduct=0003 [ 1.004535] marvin kernel: usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.004536] marvin kernel: usb usb2: Product: xHCI Host Controller [ 1.004537] marvin kernel: usb usb2: Manufacturer: Linux 4.15.0-33-generic xhci-hcd [ 1.004538] marvin kernel: usb usb2: SerialNumber: 0000:00:14.0 ... 

Compared to the same output from dmesg

... [ 1.003458] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002 [ 1.003460] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.003461] usb usb1: Product: xHCI Host Controller [ 1.003462] usb usb1: Manufacturer: Linux 4.15.0-33-generic xhci-hcd [ 1.003463] usb usb1: SerialNumber: 0000:00:14.0 [ 1.003596] hub 1-0:1.0: USB hub found [ 1.003611] hub 1-0:1.0: 16 ports detected [ 1.004505] xhci_hcd 0000:00:14.0: xHCI Host Controller [ 1.004507] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2 [ 1.004510] xhci_hcd 0000:00:14.0: Host supports USB 3.0 SuperSpeed [ 1.004533] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003 [ 1.004535] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.004536] usb usb2: Product: xHCI Host Controller [ 1.004537] usb usb2: Manufacturer: Linux 4.15.0-33-generic xhci-hcd [ 1.004538] usb usb2: SerialNumber: 0000:00:14.0 ... 
1

Your Answer

Sign up or log in

Sign up using Google Sign up using Facebook Sign up using Email and Password

Post as a guest

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy