Scheduled Maintenance: We are aware of an issue with Google, AOL, and Yahoo services as email providers which are blocking new registrations. We are trying to fix the issue and we have several internal and external support tickets in process to resolve the issue. Please see: viewtopic.php?t=158230

 

 

 

[solved] boot time between diffrent kernels

Linux Kernel, Network, and Services configuration.
Post Reply
Message
Author
milomak
Posts: 2168
Joined: 2009-06-09 22:20
Been thanked: 2 times

[solved] boot time between diffrent kernels

#1 Post by milomak »

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, Arch Linux, Gentoo, Solus
Laptop: hp 250 G8 i3 11th Gen - Sid
Kodi: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid

arzgi
Posts: 1194
Joined: 2008-02-21 17:03
Location: Finland
Been thanked: 31 times

Re: boot time between diffrent kernels

#2 Post by arzgi »

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.

milomak
Posts: 2168
Joined: 2009-06-09 22:20
Been thanked: 2 times

Re: boot time between diffrent kernels

#3 Post by milomak »

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, Arch Linux, Gentoo, Solus
Laptop: hp 250 G8 i3 11th Gen - Sid
Kodi: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid

reinob
Posts: 1196
Joined: 2014-06-30 11:42
Has thanked: 99 times
Been thanked: 47 times

Re: boot time between diffrent kernels

#4 Post by reinob »

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.

User avatar
Head_on_a_Stick
Posts: 14114
Joined: 2014-06-01 17:46
Location: London, England
Has thanked: 81 times
Been thanked: 133 times

Re: boot time between diffrent kernels

#5 Post by Head_on_a_Stick »

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.
deadbang

milomak
Posts: 2168
Joined: 2009-06-09 22:20
Been thanked: 2 times

Re: boot time between diffrent kernels

#6 Post by milomak »

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, Arch Linux, Gentoo, Solus
Laptop: hp 250 G8 i3 11th Gen - Sid
Kodi: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid

User avatar
Head_on_a_Stick
Posts: 14114
Joined: 2014-06-01 17:46
Location: London, England
Has thanked: 81 times
Been thanked: 133 times

Re: boot time between diffrent kernels

#7 Post by Head_on_a_Stick »

What happens if you use the stock Debian kernel?
deadbang

milomak
Posts: 2168
Joined: 2009-06-09 22:20
Been thanked: 2 times

Re: boot time between diffrent kernels

#8 Post by milomak »

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, Arch Linux, Gentoo, Solus
Laptop: hp 250 G8 i3 11th Gen - Sid
Kodi: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid

milomak
Posts: 2168
Joined: 2009-06-09 22:20
Been thanked: 2 times

Re: boot time between diffrent kernels

#9 Post by milomak »

Desktop: A320M-A PRO MAX, AMD Ryzen 5 3600, GALAX GeForce RTX™ 2060 Super EX (1-Click OC) - Sid, Win10, Arch Linux, Gentoo, Solus
Laptop: hp 250 G8 i3 11th Gen - Sid
Kodi: AMD Athlon 5150 APU w/Radeon HD 8400 - Sid

Post Reply