LMDE 201403 Cinnamon 64bit bootup slow ? [SOLVED]

[ron_h]

I have LMDE 201403 Cinnamon 64bit, LM16 and Windows XP SP3 installed on my system, all on the same 160GB hard drive in 3 different partitions (ext4 for LMDE and LM16, NTFS for Win XP). I have autologon for the user set in each system. Whilst I have not done actual timings, it seems to me LMDE is noticeably slower to bootup (that is, get to the Desktop screen) than LM16 or Win XP. Subjectively LM16 and Win XP take a similar amount of time. Can anyone suggest why that might be ? Or is this 'normal' ? Or where I might look for evidence of what is causing it if this is not 'normal' ?

I can live with LMDE being slower, but I thought it was worth asking.

By the way, shutdown seems to take a similar amount of time for all 3 systems to get to the PC powering off. LMDE is certainly not (subjectively) slower.

I am unlikely to use the LM16 system again, and don't expect to use Win XP much anymore. LMDE is the system I expect to use most of the time.

Ron

[wayne128]

Can anyone suggest why that might be ? Or is this 'normal' ? Or where I might look for evidence of what is causing it if this is not 'normal' ?

No, it is not normal to have LMDE 'much slower to boot'.

You probably need to troubleshoot to see what is delaying ..
Perhaps a good start is to check with dmesg for both LM16 and LMDE to compare them.

another thing you could consider is, get the Debian Wheezy, install into another small partition, then compare boot with dmesg.

dmesg would provide a time stamp for the boot event..

something like this, I capture only last few lines just to show you how it would look like.

[ 9.476766] RPC: Registered tcp transport module.
[ 9.476767] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 9.501816] FS-Cache: Loaded
[ 9.527738] FS-Cache: Netfs 'nfs' registered for caching
[ 9.552681] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[ 12.848169] Bluetooth: Core ver 2.17
[ 12.848194] NET: Registered protocol family 31
[ 12.848195] Bluetooth: HCI device and connection manager initialized
[ 12.848206] Bluetooth: HCI socket layer initialized
[ 12.848208] Bluetooth: L2CAP socket layer initialized
[ 12.848212] Bluetooth: SCO socket layer initialized
[ 12.864838] Bluetooth: RFCOMM TTY layer initialized
[ 12.864848] Bluetooth: RFCOMM socket layer initialized
[ 12.864853] Bluetooth: RFCOMM ver 1.11
[ 13.061170] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 13.061173] Bluetooth: BNEP filters: protocol multicast
[ 13.061183] Bluetooth: BNEP socket layer initialized
[ 14.526366] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
[ 14.628073] e1000e 0000:00:19.0: irq 46 for MSI/MSI-X
[ 14.628192] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 16.090415] systemd-logind[2514]: New seat seat0.
[ 16.099222] systemd-logind[2514]: Watching system buttons on /dev/input/event5 (Power Button)
[ 16.099299] systemd-logind[2514]: Watching system buttons on /dev/input/event11 (Video Bus)
[ 16.099372] systemd-logind[2514]: Watching system buttons on /dev/input/event4 (Power Button)
[ 16.100143] systemd-logind[2514]: New session 1 of user wayne.
[ 16.100235] systemd-logind[2514]: Linked /tmp/.X11-unix/X0 to /run/user/1000/X11-display.
[ 17.516891] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
[ 17.517024] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

[ron_h]

Right, I have looked at dmesg files. I assume the first field in the file is elapsed seconds and the last record in the file therefore shows the total : for LM16 this is appx 23 seconds, for LMDE it is appx 49 seconds. So there is a big difference.

The dmesg files are about 48KB in size in each system and I don't know what to look for - are there any dmesg log file analysis programs around ? Or hints/tips what sort of problems to look for ? I am a complete newbie with Linux - starting less than a week ago. I have played with Windows for years, however.

Ron

[wayne128]

The dmesg files are about 48KB in size in each system and I don't know what to look for - are there any dmesg log file analysis programs around ? Or hints/tips what sort of problems to look for ? I am a complete newbie with Linux - starting less than a week ago. I have played with Windows for years, however.

Ron

I usually just do a quick scan on dmesg and look for a big jump in time stamp..
those big jumps could indicate some unusual behaviours, such as waiting for some device to get ready..

or look for error messages,
you can type this to display just those error messages,

dmesg | grep error

my example is:

wayne@debianjessiealpha:~$ dmesg | grep error
[ 0.248248] ACPI: Marking method _OSC as Serialized because of AE_ALREADY_EXISTS error
[ 8.368936] EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro
wayne@debianjessiealpha:~$

[ron_h]

Ahah ! There is certainly one big jump in timestamps, from 5 to 35 seconds, but I have no idea what the WARNING at 35 seconds means. However (to me) it seems to be information more for the LMDE developers not for an end user

There is one occurrence of the word 'errors' at 36.8 seconds, but (to me) it doesn't seem to be of much import.

[ 5.684547] input: HDA Intel Front Headphone as /devices/pci0000:00/0000:00:1b.0/sound/card0/input5
[ 5.684619] input: HDA Intel Line Out as /devices/pci0000:00/0000:00:1b.0/sound/card0/input6
[ 5.684672] input: HDA Intel Line as /devices/pci0000:00/0000:00:1b.0/sound/card0/input7
[ 5.684722] input: HDA Intel Rear Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input8
[ 5.684772] input: HDA Intel Front Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input9
[ 35.269148] WARNING! power/level is deprecated; use power/control instead
[ 35.329148] usblp 2-2:1.0: usblp1: USB Bidirectional printer dev 2 if 0 alt 0 proto 2 vid 0x03F0 pid 0x1704
[ 35.329180] usbcore: registered new interface driver usblp
[ 36.453301] Adding 2085884k swap on /dev/sda6. Priority:-1 extents:1 across:2085884k
[ 36.500516] EXT4-fs (sda7): re-mounted. Opts: (null)
[ 36.801685] EXT4-fs (sda7): re-mounted. Opts: errors=remount-ro
[ 37.486413] fuse init (API version 7.22)

Since the last couple of lines before the jump in timestamps refer to a mike, I will pull the plug for the mike and see what happens when I reboot. Then maybe try a different mike.

Ron

[ron_h]

Made no difference with the mike disconnected. Still a jump in timestamps from 5 to 35 seconds.

Ron

[wayne128]

I just installed LMDE201403 cin and took a look at the dmesg to compare with yours.

Here is what I have, around similar time stamp:

6.533619] snd_hda_intel 0000:00:1b.0: irq 50 for MSI/MSI-X
[ 6.626854] input: HDA Intel Front Headphone as /devices/pci0000:00/0000:00:1b.0/sound/card0/input9
[ 6.626955] input: HDA Intel Line Out as /devices/pci0000:00/0000:00:1b.0/sound/card0/input10
[ 6.627031] input: HDA Intel Line as /devices/pci0000:00/0000:00:1b.0/sound/card0/input11
[ 6.627109] input: HDA Intel Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input12
[ 10.569854] Adding 4300796k swap on /dev/sda2. Priority:-1 extents:1 across:4300796k
[ 10.617828] EXT4-fs (sda9): re-mounted. Opts: (null)
[ 10.770445] EXT4-fs (sda9): re-mounted. Opts: errors=remount-ro
[ 11.439661] fuse init (API version 7.22)
[ 16.498189] input: ACPI Virtual Keyboard Device as /devices/virtual/input/input13
[ 18.221850] Bluetooth: Core ver 2.16
[ 18.221871] NET: Registered protocol family 31
[ 18.221873] Bluetooth: HCI device and connection manager initialized
[ 18.221881] Bluetooth: HCI socket layer initialized
[ 18.221883] Bluetooth: L2CAP socket layer initialized
[ 18.221888] Bluetooth: SCO socket layer initialized
[ 18.266666] Bluetooth: RFCOMM TTY layer initialized

So it seems to complete the input HDA checking... similar to yours
then a 4 seconds jump to Adding swap and root file system...

from your dmesg:

[ 5.684772] input: HDA Intel Front Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input9
[ 35.269148] WARNING! power/level is deprecated; use power/control instead
[ 35.329148] usblp 2-2:1.0: usblp1: USB Bidirectional printer dev 2 if 0 alt 0 proto 2 vid 0x03F0 pid 0x1704
[ 35.329180] usbcore: registered new interface driver usblp
[ 36.453301] Adding 2085884k swap on /dev/sda6. Priority:-1 extents:1 across:2085884k

Yours has a 30 seconds jump to usblp.... USB Bidirectional printer..

Something is taking too long on that.. perhaps some kernel bugs / usb bugs or
setup related to usb printer?


I suggest you do this just to experiment:
Power down, pull out the USB cable of the USB printer..
then do a reboot, check to see any difference on boot time .

[ron_h]

Wow, that certainly made a difference. Many thanks.

[ 5.405791] input: HDA Intel Front Headphone as /devices/pci0000:00/0000:00:1b.0/sound/card0/input5
[ 5.405863] input: HDA Intel Line Out as /devices/pci0000:00/0000:00:1b.0/sound/card0/input6
[ 5.405916] input: HDA Intel Line as /devices/pci0000:00/0000:00:1b.0/sound/card0/input7
[ 5.405968] input: HDA Intel Rear Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input8
[ 5.406022] input: HDA Intel Front Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input9
[ 8.340952] Adding 2085884k swap on /dev/sda6. Priority:-1 extents:1 across:2085884k
[ 8.386858] EXT4-fs (sda7): re-mounted. Opts: (null)
[ 8.678330] EXT4-fs (sda7): re-mounted. Opts: errors=remount-ro
[ 9.440671] fuse init (API version 7.22)

From 30 seconds to 3 seconds ! With a total time of 24.25 seconds instead of 49 seconds.

I don't actually need that printer most of the time as my default printer is a network printer, so I'll leave it the USB cable unplugged.

Ron

[wayne128]

Ron,
I am glad that you have it solved.
Enjoy.