Slow boot - analysis... (SOLVED)

Questions about Grub, UEFI,the liveCD and the installer
Forum rules
Before you post please read how to get help
Post Reply
User avatar
tenfoot
Level 5
Level 5
Posts: 901
Joined: Sun Jun 03, 2007 4:12 am
Location: Waipapa, Bay of Islands, New Zealand

Slow boot - analysis... (SOLVED)

Post by tenfoot » Fri Aug 03, 2018 4:14 pm

Using LMv19.0 Mate

Was previously using v18.3 Mate and boot times were only seconds. Now boot time is over a minute. I realise that other members have even slower boot times but I would like to know the reason for the change, and I have followed xenopeek's suggesting and used the systemd analyse commands, which returned the following:

Code: Select all

zed@zed-System-Product-Name:~$ systemd-analyze time
Startup finished in 38.927s (kernel) + 24.234s (userspace) = 1min 3.161s
graphical.target reached after 2.440s in userspace
zed@zed-System-Product-Name:~$ systemd-analyze --no-pager blame
         21.784s apt-daily.service
          9.045s fstrim.service
          7.282s configure-printer@usb-001-004.service
           662ms udisks2.service
           655ms apt-daily-upgrade.service
           626ms dev-sda1.device
           571ms lightdm.service
           568ms plymouth-quit-wait.service
           549ms NetworkManager.service
           449ms upower.service
           335ms ModemManager.service
           326ms user@1000.service
           318ms networkd-dispatcher.service
           262ms apparmor.service
           257ms networking.service
           251ms ubuntu-system-adjustments.service
           243ms accounts-daemon.service
           229ms systemd-journal-flush.service
           223ms alsa-restore.service
           171ms systemd-resolved.service
           166ms polkit.service
           162ms thermald.service
           161ms systemd-udevd.service
           149ms systemd-modules-load.service
           141ms colord.service
           134ms lvm2-monitor.service
           133ms keyboard-setup.service
           109ms systemd-fsck@dev-disk-by\x2duuid-70783429\x2dbd9d\x2d467f\x2dad32\x2d682fd3768c93.service
           108ms systemd-timesyncd.service
           102ms systemd-udev-trigger.service
           100ms grub-common.service
            84ms systemd-logind.service
            84ms wpa_supplicant.service
            80ms avahi-daemon.service
            76ms systemd-journald.service
            76ms speech-dispatcher.service
            75ms gpu-manager.service
            68ms apport.service
            65ms hddtemp.service
            64ms dns-clean.service
            62ms setvtrgb.service
            52ms media-zed-Data.mount
            51ms systemd-sysctl.service
            49ms systemd-tmpfiles-setup-dev.service
            49ms packagekit.service
            42ms systemd-tmpfiles-setup.service
            41ms rsyslog.service
            32ms flatpak-system-helper.service
            31ms lm-sensors.service
            30ms pppd-dns.service
            28ms kerneloops.service
            25ms dev-disk-by\x2duuid-0dc73dea\x2db3e1\x2d48b8\x2d8291\x2d8155df8bf954.swap
            21ms dev-hugepages.mount
            21ms sys-kernel-debug.mount
            20ms ntp.service
            19ms blk-availability.service
            15ms plymouth-start.service
            14ms systemd-user-sessions.service
            14ms ufw.service
            13ms kmod-static-nodes.service
            13ms plymouth-read-write.service
            13ms dev-mqueue.mount
            11ms systemd-update-utmp.service
            10ms systemd-remount-fs.service
            10ms ureadahead-stop.service
            10ms systemd-random-seed.service
             8ms console-setup.service
             5ms systemd-update-utmp-runlevel.service
             4ms rtkit-daemon.service
             4ms openvpn.service
             3ms sys-fs-fuse-connections.mount
             2ms sys-kernel-config.mount
zed@zed-System-Product-Name:~$ systemd-analyze plot > plot.svg
zed@zed-System-Product-Name:~$ journalctl --no-pager -b -p3
-- Logs begin at Mon 2018-07-02 13:38:54 NZST, end at Sat 2018-08-04 08:01:00 NZST. --
Aug 04 07:56:49 zed-System-Product-Name kernel: usb 1-2.4: string descriptor 0 read error: -22
Aug 04 07:56:49 zed-System-Product-Name kernel: sd 6:0:0:0: [sdc] No Caching mode page found
Aug 04 07:56:49 zed-System-Product-Name kernel: sd 6:0:0:0: [sdc] Assuming drive cache: write through
Aug 04 07:56:52 zed-System-Product-Name ntpd[952]: error resolving pool 0.ubuntu.pool.ntp.org: Name or service not known (-2)
Aug 04 07:56:53 zed-System-Product-Name ntpd[952]: error resolving pool 1.ubuntu.pool.ntp.org: Name or service not known (-2)
Aug 04 07:56:54 zed-System-Product-Name ntpd[952]: error resolving pool 2.ubuntu.pool.ntp.org: Name or service not known (-2)
Aug 04 07:56:55 zed-System-Product-Name ntpd[952]: error resolving pool 3.ubuntu.pool.ntp.org: Name or service not known (-2)
Aug 04 07:56:56 zed-System-Product-Name hp[1447]: io/hpmud/pp.c 627: unable to read device-id ret=-1
Aug 04 07:56:56 zed-System-Product-Name /hpfax[1450]: [1450]: error: Failed to create /var/spool/cups/tmp/.hplip
Aug 04 07:56:56 zed-System-Product-Name ntpd[952]: bind(23) AF_INET6 fe80::268e:e072:931:474%2#123 flags 0x11 failed: Cannot assign requested address
Aug 04 07:56:56 zed-System-Product-Name ntpd[952]: unable to create socket on enp2s0 (4) for fe80::268e:e072:931:474%2#123
Aug 04 07:56:56 zed-System-Product-Name ntpd[952]: error resolving pool ntp.ubuntu.com: Name or service not known (-2)
Aug 04 07:56:56 zed-System-Product-Name /hpfax[1450]: io/hpmud/pp.c 627: unable to read device-id ret=-1
Aug 04 07:56:58 zed-System-Product-Name colord-sane[972]: io/hpmud/pp.c 627: unable to read device-id ret=-1
Aug 04 07:56:59 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:56:59 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:00 zed-System-Product-Name ntpdate[1581]: the NTP socket is in use, exiting
Aug 04 07:57:00 zed-System-Product-Name pulseaudio[1769]: [pulseaudio] pid.c: Daemon already running.
Aug 04 07:57:00 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:57:00 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:01 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:57:01 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:02 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:57:02 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:03 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:57:03 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:04 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: bulk xfer timed out, retrying ...
Aug 04 07:57:04 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: tried reading 4096 bytes, actually read 0 bytes
Aug 04 07:57:04 zed-System-Product-Name ippusbxd[1514]: <1383356160>Error: USB timed out, giving up waiting for more data
Aug 04 07:57:26 zed-System-Product-Name pulseaudio[1641]: [pulseaudio] bluez5-util.c: GetManagedObjects() failed: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
zed@zed-System-Product-Name:~$ 
Is any member able to give me any hints on what is wrong, .please?
Last edited by tenfoot on Fri Aug 10, 2018 2:48 am, edited 1 time in total.
tenfoot
Death does not send a letter giving three week' notice. It arrives when you are eating raspberry sweets (Lars Mytting - The Sixteen Trees on the Somme)

User avatar
thx-1138
Level 6
Level 6
Posts: 1255
Joined: Fri Mar 10, 2017 12:15 pm
Location: Athens, Greece

Re: Slow boot - analysis...

Post by thx-1138 » Fri Aug 03, 2018 4:32 pm

39 secs on kernel is...very excessive even on the slowest hardware i can think of -
...you're not by any chance on kernel 4.15.0-24? (if yes, try 4.15.0-29)

...also, is that a clean install or an upgrade? if clean install,
did you maybe changed some value in the BIOS before installing, and forgot resetting it back to what it was?

Edit: ...last but not least, any proprietary graphics driver like NVidia that might need re-installing via Driver Manager first?

User avatar
richyrich
Level 19
Level 19
Posts: 9027
Joined: Mon May 04, 2009 8:31 pm

Re: Slow boot - analysis...

Post by richyrich » Fri Aug 03, 2018 5:06 pm

Right at the bottom of your analysis, I see 22 seconds looking for a pulseaudio/bluetooth device . . ? :?

User avatar
greerd
Level 5
Level 5
Posts: 986
Joined: Sat Jul 31, 2010 10:58 am
Location: Nova Scotia, Canada

Re: Slow boot - analysis...

Post by greerd » Fri Aug 03, 2018 5:16 pm

Also, you might want to take a look at plot.svg, the file created from your second command. You'll probably have to zoom a fair bit and scroll around to be able to read the plot.

User avatar
tenfoot
Level 5
Level 5
Posts: 901
Joined: Sun Jun 03, 2007 4:12 am
Location: Waipapa, Bay of Islands, New Zealand

Re: Slow boot - analysis...

Post by tenfoot » Sat Aug 04, 2018 5:11 pm

Thank you thx-1138, richyrich and greerd for your prompt replies.
thx-1138

39 secs on kernel is...very excessive even on the slowest hardware i can think of -
...you're not by any chance on kernel 4.15.0-24? (if yes, try 4.15.0-29)
Active kernel is 4.15.0-29
...also, is that a clean install or an upgrade? if clean install,
did you maybe changed some value in the BIOS before installing, and forgot resetting it back to what it was?
Complete clean install
Edit: ...last but not least, any proprietary graphics driver like NVidia that might need re-installing via Driver Manager first?
Was using the nouveau driver, as when I installed the 309 driver the computer would not boot. However, I installed it a few moments ago and restarted the computer. It still would not boot, as all I got was a flashing cursor of white, red, green and blue. Restarted again, while holding the Shift key down and the computer booted in rapid time. Now, how do I get a normal boot without pressing and holding the Shift key while booting, please?
richyrich » 04 Aug 2018, 09:06
Right at the bottom of your analysis, I see 22 seconds looking for a pulseaudio/bluetooth device . . ? :?
No bluetooth adapters installed. Bluetooth OBEX Agent and Bluberry tray icon unselected in Startup Application Preferences as a "belts and braces" approach.
greerd » 04 Aug 2018, 09:16
Also, you might want to take a look at plot.svg, the file created from your second command. You'll probably have to zoom a fair bit and scroll around to be able to read the plot.

At the start of the readout we have: Startup finished in 5.481s (kernel) + 22.56s2 (userspace) = 28.044sgraphical.target reached after 1.802s in userspace

The times returned - other than those in milliseconds are:

configure-printer@usb-001-004.service (7.282s)

apt-daily.service (20.351s)
tenfoot
Death does not send a letter giving three week' notice. It arrives when you are eating raspberry sweets (Lars Mytting - The Sixteen Trees on the Somme)

User avatar
greerd
Level 5
Level 5
Posts: 986
Joined: Sat Jul 31, 2010 10:58 am
Location: Nova Scotia, Canada

Re: Slow boot - analysis...

Post by greerd » Sun Aug 05, 2018 9:52 am

As far as the video card goes, did you look at the documentation?

As far as apt-daily.service, according to this site the service shouldn't be run at boot and should be run some time later. Check the first answer for a workaround and bug reference.

User avatar
tenfoot
Level 5
Level 5
Posts: 901
Joined: Sun Jun 03, 2007 4:12 am
Location: Waipapa, Bay of Islands, New Zealand

Re: Slow boot - analysis...

Post by tenfoot » Sun Aug 05, 2018 5:09 pm

greerd wrote:
Sun Aug 05, 2018 9:52 am
As far as the video card goes, did you look at the documentation?

No, I hadn't read the documentation. My bad :oops: However, see below.
As far as apt-daily.service, according to this site the service shouldn't be run at boot and should be run some time later. Check the first answer for a workaround and bug reference.
Did as you suggested and everything is now normal - even with the latest nVidia driver :D

Thank you for your patience in staying with me. It is much appreciated.
tenfoot
Death does not send a letter giving three week' notice. It arrives when you are eating raspberry sweets (Lars Mytting - The Sixteen Trees on the Somme)

User avatar
greerd
Level 5
Level 5
Posts: 986
Joined: Sat Jul 31, 2010 10:58 am
Location: Nova Scotia, Canada

Re: Slow boot - analysis...

Post by greerd » Sun Aug 05, 2018 6:19 pm

Your're welcome, glad its sorted!

Post Reply

Return to “Installation & Boot”