My system boots really slowly.

English Install/Boot/Login
1

Hi everyone,

I am using openSUSE on a Lenovo Thinkpad T430s, and I am not satisfied with the boot-up time.

> systemd-analyze
Startup finished in 14493ms (kernel) + 45956ms (userspace) = 60450ms

> systemd-analyze blame
25971ms systemd-remount-fs.service
11252ms systemd-readahead-replay.service
4525ms systemd-vconsole-setup.service
2370ms systemd-udev-root-symlink.service
…

So I see that the services systemd-remount-fs.service and systemd-readahead-replay.service take up half of the overall time.
When I google for systemd-remount-fs.service, I find forum posts where people show the output of ‘systemd-analyse blame’
from their systems, and usually that service takes only a few seconds to load.
I would appreciate if you could give me a suggestion where I should look for a solution to this.
If more information about my system is needed, I can provide it.

2

Yup, we need more info :smiley:

openSUSE version, 32/64bit, desktop used.
Plus all that you can provide us with re. hardware, enabled services etc.

3

Hey,
thanks for the quick answer.

openSUSE 12.3 64bit
Gnome 3.6
Intel i5 2.60 GHz
8GB RAM

Where would I find the enabled services? As in, which command will list them in the format that you require?

4

I was referring to apache etc. But I get this is on a stock install? The services mentioned should never take that long. On my SSD the remount-fs service only takes 6ms. I’m sorry, atm I don’t have a clue, but others will drop in.

5

Wow, 6ms. I don’t have an SSD, but still … I would be happy with 6 seconds.

6

On Thu 09 May 2013 01:56:02 PM CDT, Knurpht wrote:

Neukoellner;2555291 Wrote:
> Hey,
> thanks for the quick answer.
>
> openSUSE 12.3 64bit
> Gnome 3.6
> Intel i5 2.60 GHz
> 8GB RAM
>
> Where would I find the enabled services? As in, which command will
> list them in the format that you require?

I was referring to apache etc. But I get this is on a stock install?
The services mentioned should never take that long. On my SSD the
remount-fs service only takes 6ms. I’m sorry, atm I don’t have a clue,
but others will drop in.

Hi
Same here my boot times are 8.5-9.5 seconds with that hardware on a
rotating disk should be less than 20 seconds. I’m running Gnome-Shell
3.8.1 but have an older gen i5 and 8GB of ram…

Check in YaST network settings, ensure the system is set to using
NetworkManager and not ifup.

I have a HP ProBook with a dual core AMD and 4GB of ram, 5400rpm drive
and it boots up in around 25 seconds…

–
Cheers Malcolm °¿° (Linux Counter #276890)
openSUSE 12.3 (x86_64) Kernel 3.7.10-1.4-desktop
up 2 days 11:22, 3 users, load average: 0.16, 0.07, 0.05
CPU Intel® i5 CPU M520@2.40GHz | GPU Intel® Arrandale

7

I’m using NetworkManager already. By the way, booting into Gnome 3.6 takes about
another minute. I’m at a loss here … :frowning:

8

On a non-SSD system using 12.3 KDE with ext4 file systems, dual 2.0 GHx CPUs,
and a 3.10-rc0 kernel, I get


finger@larrylap:~> systemd-analyze
Startup finished in 7890ms (kernel) + 29996ms (userspace) = 37887ms
finger@larrylap:~> systemd-analyze  blame
7117ms ntp.service
4550ms systemd-vconsole-setup.service
2925ms cycle.service
2917ms systemd-udev-root-symlink.service
1323ms NetworkManager.service
1316ms postfix.service
1189ms dev-mqueue.mount
1057ms avahi-daemon.service
1042ms systemd-logind.service
1006ms systemd-remount-fs.service
674ms systemd-modules-load.service
577ms xdm.service
466ms systemd-tmpfiles-setup.service
457ms systemd-sysctl.service
401ms openSUSE12.2_64.mount
385ms home.mount
276ms systemd-udev-trigger.service
217ms vboxdrv.service
120ms udisks2.service
96ms vboxweb-service.service
91ms rsyslog.service
82ms vboxballoonctrl-service.service
77ms console-kit-daemon.service
77ms systemd-readahead-replay.service
76ms vboxautostart-service.service
71ms fbset.service
67ms polkit.service
42ms systemd-udevd.service
39ms systemd-user-sessions.service
38ms systemd-readahead-collect.service
29ms rc-local.service
26ms console-kit-log-system-start.service
23ms upower.service
17ms var-lock.mount
15ms bluetooth.service
14ms sys-kernel-debug.mount
8ms var-run.mount
finger@larrylap:~>

My systemd-remount-fs.service takes about 1 sec and readahead-reply is only 77
ms. Your 26 seconds appears to be the result of an fsck run on the partition
used for /, and that is confirmed by the replay time. Your machine is not
shutting down cleanly. Fix that and you should get kernel times below 10 sec.

9

Okay, I’ll try that. Where would I look for problems during the shutdown?
This link suggests that such logs should be in /var/log/boot.omsg, but I don’t have that
file. There is only a file boot.log, but there is nothing in that file indicating any problems.

10

On 05/09/2013 12:46 PM, Neukoellner wrote:
>
> Okay, I’ll try that. Where would I look for problems during the
> shutdown?
> ‘This link’ (http://tinyurl.com/cwganao) suggests that such logs should
> be in /var/log/boot.omsg, but I don’t have that
> file. There is only a file boot.log, but there is nothing in that file
> indicating any problems.

I think if you check the date on boot.log that you will find it is rather old.
Those boot.x files are not used with systemd. It writes that information into
/var/log/messages after the system gets started.

The easiest way to see any fsck or journal replays is to hit the ESC key as soon
as the boot splash starts. That way you can watch the kernel log in real time.

11

I did that, but I could not really tell if anything unusual was going on. Anyways, now I get


➜  ~  systemd-analyze      
Startup finished in 32119ms (kernel) + 79162ms (userspace) = 111282ms

➜  ~  systemd-analyze blame            
 17148ms systemd-vconsole-setup.service
 12574ms systemd-remount-fs.service
  7098ms NetworkManager.service
  4946ms systemd-tmpfiles-setup.service
  4685ms home.mount
  3692ms dev-hugepages.mount
  3683ms dev-mqueue.mount
  3650ms systemd-udev-root-symlink.service
  2151ms systemd-readahead-collect.service
  1673ms md.service
  1566ms cycle.service
  1224ms xdm.service
  1030ms colord.service
   879ms avahi-daemon.service
   844ms systemd-logind.service
   607ms vboxdrv.service
   371ms upower.service
   294ms plymouth-start.service
   263ms systemd-modules-load.service
   240ms rtkit-daemon.service
   195ms systemd-user-sessions.service
   175ms vboxweb-service.service
   150ms udisks2.service
   127ms systemd-readahead-replay.service
   114ms vboxballoonctrl-service.service
   113ms vboxautostart-service.service
    63ms fbset.service
    50ms systemd-udev-trigger.service
    42ms rsyslog.service
    39ms accounts-daemon.service
    35ms systemd-sysctl.service
    17ms var-lock.mount
    13ms sys-kernel-debug.mount
    10ms polkit.service
     6ms rc-local.service
     4ms var-run.mount
     2ms systemd-udevd.service
     2ms sys-fs-fuse-connections.mount

and


➜  ~  dmesg                            
    0.000000] Initializing cgroup subsys cpuset
    0.000000] Initializing cgroup subsys cpu
    0.000000] Linux version 3.7.10-1.4-desktop (geeko@buildhost) (gcc version 4.7.2 20130108 [gcc-4_7-branch revision 195012] (SUSE Linux) ) #1 SMP PREEMPT Fri Apr 19 12:06:34 UTC 2013 (8ef74f8)
    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.7.10-1.4-desktop root=UUID=27d73959-3098-4567-abbc-395d938f0e75 resume=/dev/disk/by-id/ata-HITACHI_HTS725050A7E630_TF1500Y9G58PBB-part1 splash=silent showopts
...
   14.517822] Btrfs loaded
   14.609495] device fsid 27d73959-3098-4567-abbc-395d938f0e75 devid 1 transid 23448 /dev/sda2
   14.633503] device fsid b8368db0-bd27-43ef-af65-af97a45c95e3 devid 1 transid 31474 /dev/sda3
   14.645363] PM: Marking nosave pages: [mem 0x0009d000-0x000fffff]
   14.645372] PM: Marking nosave pages: [mem 0x20000000-0x201fffff]
   14.645387] PM: Marking nosave pages: [mem 0x40004000-0x40004fff]
   14.645390] PM: Marking nosave pages: [mem 0xd0780000-0xffffffff]
   14.646905] PM: Basic memory bitmaps created
   14.696604] PM: Basic memory bitmaps freed
   14.696614] video LNXVIDEO:00: Restoring backlight state
   14.711627] PM: Starting manual resume from disk
   14.711636] PM: Hibernation image partition 8:1 present
   14.711638] PM: Looking for hibernation image.
   14.711841] PM: Image not found (code -22)
   14.711848] PM: Hibernation image not present or could not be loaded.
   14.739534] device fsid 27d73959-3098-4567-abbc-395d938f0e75 devid 1 transid 23448 /dev/sda2
   14.740073] btrfs: disk space caching is enabled
   23.394302] systemd[1]: systemd 195 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ; suse)
   31.884894] systemd[1]: Inserted module 'autofs4'
   32.001700] systemd[1]: Set hostname to <linux-c5nr.site>.
   66.913221] systemd[1]: Starting Collect Read-Ahead Data...
   66.937509] systemd[1]: Starting Replay Read-Ahead Data...
   66.942561] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
   66.942888] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
   66.943017] systemd[1]: Starting Remote File Systems.
   66.943191] systemd[1]: Reached target Remote File Systems.
   66.943301] systemd[1]: Starting Syslog Socket.
   66.943477] systemd[1]: Listening on Syslog Socket.
   66.943511] systemd[1]: Starting Delayed Shutdown Socket.
   66.943757] systemd[1]: Listening on Delayed Shutdown Socket.
   66.943781] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
   66.944004] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
   66.944075] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
   66.944368] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
   66.944406] systemd[1]: Starting Encrypted Volumes.
   66.944685] systemd[1]: Reached target Encrypted Volumes.
   66.944845] systemd[1]: Starting udev Kernel Socket.
   66.945001] systemd[1]: Listening on udev Kernel Socket.
   66.945135] systemd[1]: Starting udev Control Socket.
   66.945312] systemd[1]: Listening on udev Control Socket.
   66.945348] systemd[1]: Expecting device dev-disk-by\x2did-ata\x2dHITACHI_HTS725050A7E630_TF1500Y9G58PBB\x2dpart1.device...
   66.945632] systemd[1]: Expecting device dev-disk-by\x2duuid-b8368db0\x2dbd27\x2d43ef\x2daf65\x2daf97a45c95e3.device...
   66.945929] systemd[1]: Starting Journal Socket.
   66.946094] systemd[1]: Listening on Journal Socket.
   66.946178] systemd[1]: Starting LSB: Set default boot entry if called...
   66.952375] systemd[1]: Mounting Huge Pages File System...
   66.958608] systemd[1]: Mounting POSIX Message Queue File System...
   66.967375] systemd[1]: Starting Create dynamic rule for /dev/root link...
   66.978682] systemd[1]: Starting Journal Service...
   66.988278] systemd[1]: Started Journal Service.
   70.632202] systemd-udevd[314]: starting version 195
   72.257520] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
   72.260154] EDD information not available.
   82.776044] btrfs: disk space caching is enabled
   87.422191] wmi: Mapper loaded
   87.495961] microcode: CPU0 sig=0x306a9, pf=0x10, revision=0x12
...
   89.208712] ieee80211 phy0: Selected rate control algorithm 'iwl-agn-rs'
   89.344740] Adding 2103292k swap on /dev/sda1.  Priority:-1 extents:1 across:2103292k 
   89.347625] device fsid b8368db0-bd27-43ef-af65-af97a45c95e3 devid 1 transid 31474 /dev/sda3
   89.349936] btrfs: disk space caching is enabled
   93.858057] systemd-journald[291]: Received SIGUSR1
  104.495508] vboxguest: PCI device not found, probably running on physical hardware.
  111.274037] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
  111.374817] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
  111.375076] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
  111.379011] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
  111.385935] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1
 ...

I had to shorten the output, but there is going on a lot of stuff in quick succession, and then


   14.740073] btrfs: disk space caching is enabled
   23.394302] systemd[1]: systemd 195 running in system mode. (+PAM  +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ;  suse)
   31.884894] systemd[1]: Inserted module 'autofs4'
   32.001700] systemd[1]: Set hostname to <linux-c5nr.site>.
   66.913221] systemd[1]: Starting Collect Read-Ahead Data...

there are these big gaps. I really cannot interpret all of this, but it seems to be something file-system related.
Which file-system are you using?

12

On 05/09/2013 03:06 PM, Neukoellner wrote:
>
> lwfinger;2555430 Wrote:
>> On 05/09/2013 12:46 PM, Neukoellner wrote:
>>>
>>> Okay, I’ll try that. Where would I look for problems during the
>>> shutdown?
>>> ‘This link’ (‘openSUSE 12.3: Chapter 4. Analyzing and Managing System
>> Log Files’ (http://tinyurl.com/cwganao)) suggests that such logs should
>>> be in /var/log/boot.omsg, but I don’t have that
>>> file. There is only a file boot.log, but there is nothing in that
>> file
>>> indicating any problems.
>>
>> I think if you check the date on boot.log that you will find it is
>> rather old.
>> Those boot.x files are not used with systemd. It writes that
>> information into
>> /var/log/messages after the system gets started.
>>
>> The easiest way to see any fsck or journal replays is to hit the ESC
>> key as soon
>> as the boot splash starts. That way you can watch the kernel log in
>> real time.
>
> I did that, but I could not really tell if anything unusual was going
> on. Anyways, now I get
>
>
> Code:
> --------------------
>
> ➜ ~ systemd-analyze
> Startup finished in 32119ms (kernel) + 79162ms (userspace) = 111282ms
>
> ➜ ~ systemd-analyze blame
> 17148ms systemd-vconsole-setup.service
> 12574ms systemd-remount-fs.service
> 7098ms NetworkManager.service
> 4946ms systemd-tmpfiles-setup.service
> 4685ms home.mount
> 3692ms dev-hugepages.mount
> 3683ms dev-mqueue.mount
> 3650ms systemd-udev-root-symlink.service
> 2151ms systemd-readahead-collect.service
> 1673ms md.service
> 1566ms cycle.service
> 1224ms xdm.service
> 1030ms colord.service
> 879ms avahi-daemon.service
> 844ms systemd-logind.service
> 607ms vboxdrv.service
> 371ms upower.service
> 294ms plymouth-start.service
> 263ms systemd-modules-load.service
> 240ms rtkit-daemon.service
> 195ms systemd-user-sessions.service
> 175ms vboxweb-service.service
> 150ms udisks2.service
> 127ms systemd-readahead-replay.service
> 114ms vboxballoonctrl-service.service
> 113ms vboxautostart-service.service
> 63ms fbset.service
> 50ms systemd-udev-trigger.service
> 42ms rsyslog.service
> 39ms accounts-daemon.service
> 35ms systemd-sysctl.service
> 17ms var-lock.mount
> 13ms sys-kernel-debug.mount
> 10ms polkit.service
> 6ms rc-local.service
> 4ms var-run.mount
> 2ms systemd-udevd.service
> 2ms sys-fs-fuse-connections.mount
>
> --------------------
>
>
> and
>
>
> Code:
> --------------------
>
> ➜ ~ dmesg
> 0.000000] Initializing cgroup subsys cpuset
> 0.000000] Initializing cgroup subsys cpu
> 0.000000] Linux version 3.7.10-1.4-desktop (geeko@buildhost) (gcc version 4.7.2 20130108 [gcc-4_7-branch revision 195012] (SUSE Linux) ) #1 SMP PREEMPT Fri Apr 19 12:06:34 UTC 2013 (8ef74f8)
> 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-3.7.10-1.4-desktop root=UUID=27d73959-3098-4567-abbc-395d938f0e75 resume=/dev/disk/by-id/ata-HITACHI_HTS725050A7E630_TF1500Y9G58PBB-part1 splash=silent showopts
> …
> 14.517822] Btrfs loaded
> 14.609495] device fsid 27d73959-3098-4567-abbc-395d938f0e75 devid 1 transid 23448 /dev/sda2
> 14.633503] device fsid b8368db0-bd27-43ef-af65-af97a45c95e3 devid 1 transid 31474 /dev/sda3
> 14.645363] PM: Marking nosave pages: [mem 0x0009d000-0x000fffff]
> 14.645372] PM: Marking nosave pages: [mem 0x20000000-0x201fffff]
> 14.645387] PM: Marking nosave pages: [mem 0x40004000-0x40004fff]
> 14.645390] PM: Marking nosave pages: [mem 0xd0780000-0xffffffff]
> 14.646905] PM: Basic memory bitmaps created
> 14.696604] PM: Basic memory bitmaps freed
> 14.696614] video LNXVIDEO:00: Restoring backlight state
> 14.711627] PM: Starting manual resume from disk
> 14.711636] PM: Hibernation image partition 8:1 present
> 14.711638] PM: Looking for hibernation image.
> 14.711841] PM: Image not found (code -22)
> 14.711848] PM: Hibernation image not present or could not be loaded.
> 14.739534] device fsid 27d73959-3098-4567-abbc-395d938f0e75 devid 1 transid 23448 /dev/sda2
> 14.740073] btrfs: disk space caching is enabled
> 23.394302] systemd[1]: systemd 195 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ; suse)
> 31.884894] systemd[1]: Inserted module ‘autofs4’
> 32.001700] systemd[1]: Set hostname to <linux-c5nr.site>.
> 66.913221] systemd[1]: Starting Collect Read-Ahead Data…
> 66.937509] systemd[1]: Starting Replay Read-Ahead Data…
> 66.942561] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
> 66.942888] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
> 66.943017] systemd[1]: Starting Remote File Systems.
> 66.943191] systemd[1]: Reached target Remote File Systems.
> 66.943301] systemd[1]: Starting Syslog Socket.
> 66.943477] systemd[1]: Listening on Syslog Socket.
> 66.943511] systemd[1]: Starting Delayed Shutdown Socket.
> 66.943757] systemd[1]: Listening on Delayed Shutdown Socket.
> 66.943781] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
> 66.944004] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
> 66.944075] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
> 66.944368] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
> 66.944406] systemd[1]: Starting Encrypted Volumes.
> 66.944685] systemd[1]: Reached target Encrypted Volumes.
> 66.944845] systemd[1]: Starting udev Kernel Socket.
> 66.945001] systemd[1]: Listening on udev Kernel Socket.
> 66.945135] systemd[1]: Starting udev Control Socket.
> 66.945312] systemd[1]: Listening on udev Control Socket.
> 66.945348] systemd[1]: Expecting device dev-disk-by\x2did-ata\x2dHITACHI_HTS725050A7E630_TF1500Y9G58PBB\x2dpart1.device…
> 66.945632] systemd[1]: Expecting device dev-disk-by\x2duuid-b8368db0\x2dbd27\x2d43ef\x2daf65\x2daf97a45c95e3.device…
> 66.945929] systemd[1]: Starting Journal Socket.
> 66.946094] systemd[1]: Listening on Journal Socket.
> 66.946178] systemd[1]: Starting LSB: Set default boot entry if called…
> 66.952375] systemd[1]: Mounting Huge Pages File System…
> 66.958608] systemd[1]: Mounting POSIX Message Queue File System…
> 66.967375] systemd[1]: Starting Create dynamic rule for /dev/root link…
> 66.978682] systemd[1]: Starting Journal Service…
> 66.988278] systemd[1]: Started Journal Service.
> 70.632202] systemd-udevd[314]: starting version 195
> 72.257520] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
> 72.260154] EDD information not available.
> 82.776044] btrfs: disk space caching is enabled
> 87.422191] wmi: Mapper loaded
> 87.495961] microcode: CPU0 sig=0x306a9, pf=0x10, revision=0x12
> …
> 89.208712] ieee80211 phy0: Selected rate control algorithm ‘iwl-agn-rs’
> 89.344740] Adding 2103292k swap on /dev/sda1. Priority:-1 extents:1 across:2103292k
> 89.347625] device fsid b8368db0-bd27-43ef-af65-af97a45c95e3 devid 1 transid 31474 /dev/sda3
> 89.349936] btrfs: disk space caching is enabled
> 93.858057] systemd-journald[291]: Received SIGUSR1
> 104.495508] vboxguest: PCI device not found, probably running on physical hardware.
> 111.274037] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
> 111.374817] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
> 111.375076] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
> 111.379011] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
> 111.385935] iwlwifi 0000:03:00.0: Radio type=0x0-0x3-0x1
> …
>
> --------------------
>
>
> I had to shorten the output, but there is going on a lot of stuff in
> quick succession, and then
>
> Code:
> --------------------
>
> 14.740073] btrfs: disk space caching is enabled
> 23.394302] systemd[1]: systemd 195 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ; suse)
> 31.884894] systemd[1]: Inserted module ‘autofs4’
> 32.001700] systemd[1]: Set hostname to <linux-c5nr.site>.
> 66.913221] systemd[1]: Starting Collect Read-Ahead Data…
>
> --------------------
>
>
> there are these big gaps. I really cannot interpret all of this, but it
> seems to be something file-system related.
> Which file-system are you using?

At this time, I will not use btrfs. All mine are ext4.

Is / on your system also btrfs?

13

I’m getting:

8088.380115] systemd[1]: rsyslog.service start request repeated too quickly, refusing to start.

lines in dmesg over and over. Is this the same issue? I’m seeing very high CPU load right after the last update. It did not do this before.

Bob Taylor
<EWTech>

14

Yes, all btrfs. And I’m beginning to question my decision to use it.

However, I have installed Kernel 3.9.1 and now I’m down to 32 seconds boot time.
I’ll have to restart my computer a couple of times to see if this improvement is permanent.