[solved] boot time between diffrent kernels

Kernels & Hardware, configuring network, installing services

[solved] boot time between diffrent kernels

Postby milomak » 2020-04-17 19:52

i'm having a distinct difference in boot times between 2 kernels.

So this is the gold standard at the moment (5.2.0-21.2-liquorix-amd64)
Code: Select all
mac ~ # systemd-analyze
Startup finished in 38.197s (kernel) + 18.085s (userspace) = 56.283s
graphical.target reached after 18.076s in userspace
mac ~ # uname -r
5.2.0-21.2-liquorix-amd64
mac ~ # systemd-analyze blame
14.895s lm-sensors.service                             
12.269s vboxadd.service                               
10.351s NetworkManager-wait-online.service             
 3.579s sabnzbdplus.service                           
 2.028s tvheadend.service                             
 1.803s systemd-udev-settle.service                   
 1.708s plymouth-quit-wait.service                     
 1.355s nmbd.service                                   
 1.212s accounts-daemon.service                       
 1.095s exim4.service                                 
 1.012s udisks2.service                               
  982ms upower.service                                 
  797ms dev-sdc2.device                               
  631ms systemd-logind.service                         
  628ms avahi-daemon.service                           
  627ms bluetooth.service                             
  613ms polkit.service                                 
  580ms NetworkManager.service                         
  577ms iio-sensor-proxy.service                       
  571ms lightdm.service                               
  533ms systemd-journald.service                       
  518ms ModemManager.service                           
  512ms wpa_supplicant.service                         
  502ms smbd.service                                   
  496ms user@1000.service                             
  494ms systemd-journal-flush.service                 
  489ms mnt-win.mount                                 
  441ms e2scrub_reap.service                           
  432ms virtualbox.service                             
  395ms loadcpufreq.service                           
  299ms systemd-resolved.service                       
  259ms rc-local.service                               
  236ms ntp.service                                   
  234ms pulseaudio-enable-autospawn.service           
  229ms rsyslog.service                               
  187ms ssh.service                                   
  162ms alsa-restore.service                           
  143ms keyboard-setup.service                         
  142ms pppd-dns.service                               
  140ms systemd-rfkill.service                         
  139ms colord.service                                 
  134ms live-tools.service                             
  124ms atd.service                                   
  105ms dev-hugepages.mount                           
  105ms dev-mqueue.mount                               
  104ms run-rpc_pipefs.mount                           
  104ms sys-kernel-debug.mount                         
  103ms sys-kernel-tracing.mount                       
   99ms systemd-udev-trigger.service                   
   96ms systemd-udevd.service                         
   87ms boot-efi.mount                                 
   65ms binfmt-support.service                         
   64ms systemd-modules-load.service                   
   55ms systemd-backlight@backlight:acpi_video0.service
   52ms tmp.mount                                     
   50ms systemd-tmpfiles-setup.service                 
   50ms kmod-static-nodes.service                     
   48ms plymouth-start.service                         
   46ms hddtemp.service                               
   46ms cpufrequtils.service                           
   45ms systemd-user-sessions.service                 
   45ms systemd-backlight@backlight:amdgpu_bl0.service
   36ms systemd-sysusers.service                       
   35ms rpcbind.service                               
   34ms systemd-remount-fs.service                     
   27ms console-setup.service                         
   27ms deluged.service                               
   27ms plymouth-read-write.service                   
   26ms nfs-config.service                             
   25ms systemd-tmpfiles-setup-dev.service             
   18ms systemd-random-seed.service                   
   18ms systemd-update-utmp.service                   
   15ms proc-sys-fs-binfmt_misc.mount                 
   15ms apt-listbugs.service                           
   13ms user-runtime-dir@1000.service                 
    8ms vboxadd-service.service                       
    8ms systemd-update-utmp-runlevel.service           
    6ms systemd-sysctl.service                         
    2ms sys-fs-fuse-connections.mount                 
    1ms vsftpd.service                                 
    1ms sys-kernel-config.mount


not sure what is happening with 5.6.0-3.slh.1-aptosid-amd64 though on the same system

Code: Select all
mac ~ # systemd-analyze     
Startup finished in 2min 8.592s (kernel) + 44.643s (userspace) = 2min 53.235s
graphical.target reached after 44.635s in userspace
mac ~ # uname -r             
5.6.0-3.slh.1-aptosid-amd64
mac ~ # systemd-analyze blame
41.955s lm-sensors.service                             
10.580s NetworkManager-wait-online.service             
 9.095s vboxadd.service                               
 1.697s tvheadend.service                             
 1.613s systemd-udev-settle.service                   
 1.590s sabnzbdplus.service                           
  866ms accounts-daemon.service                       
  777ms udisks2.service                               
  618ms dev-sdc2.device                               
  527ms upower.service                                 
  494ms systemd-journal-flush.service                 
  433ms mnt-win.mount                                 
  410ms nmbd.service                                   
  402ms polkit.service                                 
  378ms bluetooth.service                             
  377ms avahi-daemon.service                           
  373ms NetworkManager.service                         
  361ms systemd-logind.service                         
  357ms wpa_supplicant.service                         
  341ms systemd-journald.service                       
  329ms loadcpufreq.service                           
  321ms systemd-resolved.service                       
  315ms exim4.service                                 
  284ms ModemManager.service                           
  246ms user@1000.service                             
  230ms e2scrub_reap.service                           
  203ms rsyslog.service                               
  197ms ntp.service                                   
  191ms pulseaudio-enable-autospawn.service           
  167ms lightdm.service                               
  149ms ssh.service                                   
  131ms systemd-rfkill.service                         
  127ms smbd.service                                   
  118ms colord.service                                 
   93ms keyboard-setup.service                         
   83ms virtualbox.service                             
   75ms systemd-modules-load.service                   
   69ms systemd-udev-trigger.service                   
   66ms systemd-udevd.service                         
   53ms boot-efi.mount                                 
   48ms binfmt-support.service                         
   47ms run-rpc_pipefs.mount                           
   40ms pppd-dns.service                               
   36ms systemd-sysusers.service                       
   32ms systemd-tmpfiles-setup.service                 
   30ms rpcbind.service                               
   30ms cpufrequtils.service                           
   29ms systemd-random-seed.service                   
   28ms deluged.service                               
   27ms plymouth-read-write.service                   
   27ms atd.service                                   
   25ms plymouth-start.service                         
   25ms systemd-tmpfiles-setup-dev.service             
   24ms alsa-restore.service                           
   23ms live-tools.service                             
   22ms dev-hugepages.mount                           
   22ms dev-mqueue.mount                               
   21ms sys-kernel-debug.mount                         
   20ms systemd-update-utmp.service                   
   19ms user-runtime-dir@1000.service                 
   18ms hddtemp.service                               
   17ms tmp.mount                                     
   16ms kmod-static-nodes.service                     
   16ms systemd-backlight@backlight:acpi_video0.service
   14ms rc-local.service                               
   14ms vboxadd-service.service                       
   13ms systemd-remount-fs.service                     
   11ms proc-sys-fs-binfmt_misc.mount                 
   11ms systemd-user-sessions.service                 
    9ms console-setup.service                         
    9ms systemd-sysctl.service                         
    6ms systemd-backlight@backlight:amdgpu_bl0.service
    6ms systemd-update-utmp-runlevel.service           
    5ms nfs-config.service                             
    2ms sys-fs-fuse-connections.mount                 
    1ms plymouth-quit-wait.service                     
    1ms vsftpd.service


removed lm-sensors
Code: Select all
mac ~ # systemd-analyze           
Startup finished in 2min 8.558s (kernel) + 15.187s (userspace) = 2min 23.745s
graphical.target reached after 15.176s in userspace
mac ~ # uname -r                 
5.6.0-3.slh.1-aptosid-amd64
mac ~ # systemd-analyze blame     
10.052s NetworkManager-wait-online.service             
 9.048s vboxadd.service                               
 2.363s sabnzbdplus.service                           
 1.500s systemd-udev-settle.service                   
 1.199s tvheadend.service                             
  721ms accounts-daemon.service                       
  665ms udisks2.service                               
  599ms dev-sdc2.device                               
  572ms systemd-journal-flush.service                 
  559ms user@1000.service                             
  521ms upower.service                                 
  493ms nmbd.service                                   
  471ms mnt-win.mount                                 
  381ms ModemManager.service                           
  379ms polkit.service                                 
  366ms avahi-daemon.service                           
  365ms bluetooth.service                             
  363ms NetworkManager.service                         
  351ms systemd-logind.service                         
  349ms wpa_supplicant.service                         
  323ms systemd-journald.service                       
  313ms exim4.service                                 
  295ms loadcpufreq.service                           
  271ms systemd-resolved.service                       
  176ms rsyslog.service                               
  174ms lightdm.service                               
  170ms pulseaudio-enable-autospawn.service           
  168ms smbd.service                                   
  167ms e2scrub_reap.service                           
  148ms ntp.service                                   
  121ms colord.service                                 
  111ms ssh.service                                   
   92ms virtualbox.service                             
   88ms keyboard-setup.service                         
   82ms systemd-udev-trigger.service                   
   67ms systemd-udevd.service                         
   58ms systemd-modules-load.service                   
   54ms plymouth-read-write.service                   
   48ms boot-efi.mount                                 
   46ms systemd-rfkill.service                         
   45ms binfmt-support.service                         
   42ms run-rpc_pipefs.mount                           
   39ms atd.service                                   
   38ms pppd-dns.service                               
   31ms systemd-tmpfiles-setup.service                 
   29ms systemd-sysusers.service                       
   28ms systemd-random-seed.service                   
   26ms user-runtime-dir@1000.service                 
   25ms systemd-tmpfiles-setup-dev.service             
   25ms cpufrequtils.service                           
   24ms plymouth-start.service                         
   23ms hddtemp.service                               
   22ms dev-hugepages.mount                           
   21ms dev-mqueue.mount                               
   21ms alsa-restore.service                           
   20ms sys-kernel-debug.mount                         
   19ms live-tools.service                             
   18ms deluged.service                               
   17ms systemd-backlight@backlight:acpi_video0.service
   17ms tmp.mount                                     
   16ms kmod-static-nodes.service                     
   15ms rc-local.service                               
   14ms systemd-backlight@backlight:amdgpu_bl0.service
   13ms systemd-sysctl.service                         
   12ms console-setup.service                         
   12ms rpcbind.service                               
   11ms systemd-remount-fs.service                     
    9ms systemd-update-utmp-runlevel.service           
    9ms systemd-update-utmp.service                   
    8ms nfs-config.service                             
    7ms proc-sys-fs-binfmt_misc.mount                 
    7ms systemd-user-sessions.service                 
    7ms vboxadd-service.service                       
    3ms sys-fs-fuse-connections.mount                 
    3ms plymouth-quit-wait.service                     
    1ms vsftpd.service


is there a way i can export the data to a spreadsheet?

edit - added amdgpu.ppfeaturemask=0 to the kernel command line in grub. it now looks like this
# cat /proc/cmdline
Code: Select all
audit=0 intel_pstate=disable  BOOT_IMAGE=/boot/vmlinuz-5.8.0-13.1-liquorix-amd64 root=UUID=ffb7a55f-29e2-458a-b932-88be2f161cf3 ro initrd=/install/gtk/initrd.gz nointremap quiet splash amdgpu.ppfeaturemask=0 amdgpu.audio=1 radeon.cik_support=0 radeon.si_support=0 amdgpu.cik_support=1 amdgpu.si_support=1 amdgpu.dpm=1 amdgpu.dc=1 fsck.mode=force fsck.repair=yes


there were a number of
Code: Select all
amdgpu: [powerplay] failed to send message [x] ret is 0

messages and adding that parameter removed them and now the system boots in less than a minute
Last edited by milomak on 2020-10-08 09:42, edited 2 times in total.
Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10
Laptop: Lenovo ideapad Y700-15ISK [nVidia Optimus] (64-bit) - Sid, Win10, Solus
Kodi Box: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid
milomak
 
Posts: 2072
Joined: 2009-06-09 22:20

Re: boot time between diffrent kernels

Postby arzgi » 2020-04-17 20:15

milomak wrote:is there a way i can export the data to a spreadsheet?


Sure. For example in LibreOffice calc, paste special, space as separator. I had to do some handwork, because it shifted ms one cell to right.
arzgi
 
Posts: 668
Joined: 2008-02-21 17:03
Location: Finland

Re: boot time between diffrent kernels

Postby milomak » 2020-04-17 20:51

arzgi wrote:
milomak wrote:is there a way i can export the data to a spreadsheet?


Sure. For example in LibreOffice calc, paste special, space as separator. I had to do some handwork, because it shifted ms one cell to right.

i see i can but it seems the second thing is not recognised

but nonetheless. how can the same system have such differences?
Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10
Laptop: Lenovo ideapad Y700-15ISK [nVidia Optimus] (64-bit) - Sid, Win10, Solus
Kodi Box: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid
milomak
 
Posts: 2072
Joined: 2009-06-09 22:20

Re: boot time between diffrent kernels

Postby reinob » 2020-04-18 08:22

milomak wrote:
arzgi wrote:
milomak wrote:is there a way i can export the data to a spreadsheet?


Sure. For example in LibreOffice calc, paste special, space as separator. I had to do some handwork, because it shifted ms one cell to right.

i see i can but it seems the second thing is not recognised

but nonetheless. how can the same system have such differences?


Try:
Code: Select all
# systemctl status lm-sensors.service


For some reason, it's taking much longer (14.895s vs 41.955s).
You could just "journalctl -b" and see what happened during boot.
reinob
 
Posts: 847
Joined: 2014-06-30 11:42

Re: boot time between diffrent kernels

Postby Head_on_a_Stick » 2020-04-18 10:57

milomak wrote:how can the same system have such differences?

Regressions.

Use this to analyse the user space component of the boot time:
Code: Select all
systemd-analyze plot > boot.svg

Then open boot.svg in your browser.

There's no way to analyse the kernel component though (AFAIK). Have you applied any funky kernel parameters? That slows down my kernel boot time significantly.
Black Lives Matter

Debian buster-backports ISO image: for new hardware support
User avatar
Head_on_a_Stick
 
Posts: 12744
Joined: 2014-06-01 17:46
Location: /dev/chair

Re: boot time between diffrent kernels

Postby milomak » 2020-04-19 19:34

boott.svg

both kernels are aptosid so it's possible there are funky parameters.
Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10
Laptop: Lenovo ideapad Y700-15ISK [nVidia Optimus] (64-bit) - Sid, Win10, Solus
Kodi Box: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid
milomak
 
Posts: 2072
Joined: 2009-06-09 22:20

Re: boot time between diffrent kernels

Postby Head_on_a_Stick » 2020-04-20 11:51

What happens if you use the stock Debian kernel?
Black Lives Matter

Debian buster-backports ISO image: for new hardware support
User avatar
Head_on_a_Stick
 
Posts: 12744
Joined: 2014-06-01 17:46
Location: /dev/chair

Re: boot time between diffrent kernels

Postby milomak » 2020-04-20 16:57

Head_on_a_Stick wrote:What happens if you use the stock Debian kernel?


similar issue
Code: Select all
mac ~ # systemd-analyze
Startup finished in 2min 5.812s (kernel) + 17.903s (userspace) = 2min 23.716s
graphical.target reached after 17.736s in userspace
mac ~ # uname -a
Linux mac 5.5.0-1-amd64 #1 SMP Debian 5.5.13-2 (2020-03-30) x86_64 GNU/Linux
mac ~ # systemd-analyze blame
10.831s NetworkManager-wait-online.service             
 9.837s vboxadd.service                               
 2.408s sabnzbdplus.service                           
 2.027s apparmor.service                               
 1.941s systemd-udev-settle.service                   
 1.636s tvheadend.service                             
 1.093s udisks2.service                               
  903ms upower.service                                 
  845ms dev-sdc2.device                               
  804ms systemd-journal-flush.service                 
  770ms accounts-daemon.service                       
  598ms mnt-win.mount                                 
  527ms systemd-logind.service                         
  523ms systemd-journald.service                       
  489ms systemd-resolved.service                       
  446ms user@1000.service                             
  444ms nmbd.service                                   
  400ms polkit.service                                 
  381ms bluetooth.service                             
  380ms avahi-daemon.service                           
  375ms NetworkManager.service                         
  359ms iio-sensor-proxy.service                       
  342ms loadcpufreq.service                           
  330ms wpa_supplicant.service                         
  330ms exim4.service                                 
  286ms ModemManager.service                           
  259ms e2scrub_reap.service                           
  223ms colord.service                                 
  212ms lightdm.service                               
  211ms smbd.service                                   
  186ms systemd-pstore.service                         
  177ms phpsessionclean.service                       
  159ms rsyslog.service                               
  158ms ntp.service                                   
  152ms pulseaudio-enable-autospawn.service           
  106ms ssh.service                                   
  103ms virtualbox.service                             
   91ms keyboard-setup.service                         
   90ms systemd-udevd.service                         
   88ms cpufrequtils.service                           
   84ms binfmt-support.service                         
   82ms rpcbind.service                               
   82ms systemd-udev-trigger.service                   
   74ms systemd-modules-load.service                   
   66ms plymouth-start.service                         
   60ms alsa-restore.service                           
   57ms plymouth-read-write.service                   
   53ms atd.service                                   
   51ms boot-efi.mount                                 
   48ms run-rpc_pipefs.mount                           
   45ms systemd-update-utmp.service                   
   44ms systemd-tmpfiles-clean.service                 
   41ms systemd-tmpfiles-setup-dev.service             
   38ms deluged.service                               
   38ms proc-sys-fs-binfmt_misc.mount                 
   36ms systemd-tmpfiles-setup.service                 
   36ms systemd-rfkill.service                         
   28ms systemd-backlight@backlight:acpi_video0.service
   28ms dev-hugepages.mount                           
   27ms user-runtime-dir@1000.service                 
   27ms dev-mqueue.mount                               
   26ms sys-kernel-debug.mount                         
   26ms sys-kernel-tracing.mount                       
   25ms hddtemp.service                               
   25ms systemd-sysusers.service                       
   23ms live-tools.service                             
   22ms systemd-backlight@backlight:amdgpu_bl0.service
   20ms systemd-update-utmp-runlevel.service           
   20ms console-setup.service                         
   20ms nfs-config.service                             
   18ms pppd-dns.service                               
   18ms systemd-remount-fs.service                     
   18ms tmp.mount                                     
   17ms kmod-static-nodes.service                     
   15ms systemd-random-seed.service                   
   15ms rc-local.service                               
   11ms systemd-sysctl.service                         
    8ms systemd-user-sessions.service                 
    8ms apt-listbugs.service                           
    7ms vboxadd-service.service                       
    3ms vsftpd.service                                 
    3ms sys-fs-fuse-connections.mount                 
    1ms plymouth-quit-wait.service


i ran dmesg and noticed a lot of red attributable to rcu
Code: Select all
# dmesg | grep rcu
[   49.395546] rcu: INFO: rcu_sched self-detected stall on CPU
[   49.395561] rcu:     0-....: (5250 ticks this GP) idle=69a/1/0x4000000000000002 softirq=7081/7081 fqs=2560
[   49.395627]  rcu_dump_cpu_stacks+0x8f/0xbd
[   49.395628]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[  164.199559] rcu: INFO: rcu_sched self-detected stall on CPU
[  164.199562] rcu:     2-....: (5250 ticks this GP) idle=d6e/1/0x4000000000000002 softirq=31839/31839 fqs=2566
[  164.199598]  rcu_dump_cpu_stacks+0x8f/0xbd
[  164.199600]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[  190.487569] rcu: INFO: rcu_sched self-detected stall on CPU
[  190.487572] rcu:     3-....: (5249 ticks this GP) idle=172/1/0x4000000000000002 softirq=42506/42506 fqs=2624
[  190.487608]  rcu_dump_cpu_stacks+0x8f/0xbd
[  190.487610]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[  195.671614] rcu: INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 3-... } 5711 jiffies s: 213 root: 0x8/.
[  195.671617] rcu: blocking rcu_node structures:
[ 6125.893261] rcu: INFO: rcu_sched self-detected stall on CPU
[ 6125.893264] rcu:     0-....: (5250 ticks this GP) idle=7a6/1/0x4000000000000002 softirq=487163/487163 fqs=2457
[ 6125.893297]  rcu_dump_cpu_stacks+0x8f/0xbd
[ 6125.893299]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[ 6663.864785] rcu: INFO: rcu_sched self-detected stall on CPU
[ 6663.864789] rcu:     3-....: (5249 ticks this GP) idle=cb2/1/0x4000000000000002 softirq=537581/537581 fqs=2619
[ 6663.864831]  rcu_dump_cpu_stacks+0x8f/0xbd
[ 6663.864832]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[ 7843.103707] rcu: INFO: rcu_sched self-detected stall on CPU
[ 7843.103710] rcu:     2-....: (5250 ticks this GP) idle=fe2/1/0x4000000000000002 softirq=609031/609031 fqs=2509
[ 7843.103746]  rcu_dump_cpu_stacks+0x8f/0xbd
[ 7843.103748]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[ 9798.353489] rcu: INFO: rcu_sched self-detected stall on CPU
[ 9798.353507] rcu:     0-....: (5250 ticks this GP) idle=25e/1/0x4000000000000002 softirq=677581/677581 fqs=2397
[ 9798.353524]  rcu_dump_cpu_stacks+0x8f/0xbd
[ 9798.353526]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[11509.291480] rcu: INFO: rcu_sched self-detected stall on CPU
[11509.291483] rcu:     2-....: (5249 ticks this GP) idle=56e/1/0x4000000000000002 softirq=833016/833025 fqs=2623
[11509.291519]  rcu_dump_cpu_stacks+0x8f/0xbd
[11509.291521]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
[12285.342566] rcu: INFO: rcu_sched self-detected stall on CPU
[12285.342569] rcu:     2-....: (5249 ticks this GP) idle=07a/1/0x4000000000000002 softirq=865044/865044 fqs=2618
[12285.342605]  rcu_dump_cpu_stacks+0x8f/0xbd
[12285.342606]  rcu_sched_clock_irq.cold+0x1b2/0x3ab
Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10
Laptop: Lenovo ideapad Y700-15ISK [nVidia Optimus] (64-bit) - Sid, Win10, Solus
Kodi Box: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid
milomak
 
Posts: 2072
Joined: 2009-06-09 22:20

Re: boot time between diffrent kernels

Postby milomak » 2020-04-24 17:41

Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10
Laptop: Lenovo ideapad Y700-15ISK [nVidia Optimus] (64-bit) - Sid, Win10, Solus
Kodi Box: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid
milomak
 
Posts: 2072
Joined: 2009-06-09 22:20


Return to System configuration

Who is online

Users browsing this forum: No registered users and 20 guests

fashionable