Jump to content

systemd-analyze


sunrat

Recommended Posts

I keep finding out really neat things about systemd. The first was how journalctl shows system logs in a much simpler way than browsing logs.

Now I just found the systemd-analyze function to quickly show boot time.

roger@brain:~$ systemd-analyze
Startup finished in 3.742s (kernel) + 7.600s (userspace) = 11.343s

Pretty fast and I haven't even tried to optimise it.

You can also get a graphical depiction like the old bootchart with:

$ systemd-analyze plot > plot.svg

I won't post mine because it's huge, but it showed it could save another 4 seconds off userspace time if it wasn't waiting for ntp.

Cool stuff! :thumbsup: B)

  • Like 1
Link to comment
Share on other sites

securitybreach

I am also a big fan of systemd. Here are my results:

 comhack@Cerberus ~ % systemd-analyze
Startup finished in 1.876s (kernel) + 7.309s (userspace) = 9.185s

comhack@Cerberus ~ % systemd-analyze blame
1.663s systemd-logind.service
1.252s lm_sensors.service
1.207s cpupower.service
1.182s rpcbind.service
1.055s ntpd.service
933ms urxvtd@comhack.service
760ms nfsd.service
736ms systemd-fsck@dev-disk-by\x2duuid-3067b591\x2d934e\x2d4c73\x2da4a7\x2de5d9da6c267a.service
664ms systemd-fsck@dev-disk-by\x2duuid-cb0d6b0f\x2d1c2a\x2d46c8\x2d99eb\x2dbbe4e1bcb1b5.service
628ms systemd-fsck@dev-disk-by\x2duuid-3fc84665\x2d73ed\x2d46ed\x2da4c6\x2d31d4ce2bc1b7.service
603ms kmod-static-nodes.service
590ms sys-kernel-debug.mount
588ms dev-hugepages.mount
574ms systemd-modules-load.service
546ms dev-mqueue.mount
518ms systemd-vconsole-setup.service
494ms alsa-restore.service
443ms systemd-tmpfiles-clean.service
408ms systemd-udev-trigger.service
344ms polkit.service
317ms systemd-remount-fs.service
312ms systemd-sysctl.service
290ms tmp.mount
246ms user@1000.service
213ms systemd-tmpfiles-setup-dev.service
111ms home.mount
78ms systemd-user-sessions.service
70ms systemd-random-seed.service
67ms systemd-journal-flush.service
55ms systemd-tmpfiles-setup.service
47ms backup.mount
43ms udisks.service
36ms systemd-update-utmp.service
24ms dev-disk-by\x2duuid-bc069bca\x2d6b4d\x2d4174\x2db6e4\x2d9bf8ece14ae7.swap
19ms MEDIA.mount
15ms systemd-udevd.service
2ms network.service
1ms sys-kernel-config.mount
1ms srv-nfs4-MEDIA.mount
comhack@Cerberus ~ % 

Link to comment
Share on other sites

Here is mine from my newly installed ssd,

 

[11:18][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 5.128s (kernel) + 13.117s (userspace) = 18.246s

 

Hmm. Not as fast as you guys. :hmm:

Link to comment
Share on other sites

Hmm. Not as fast as you guys. :hmm:

Do the blame or plot thing to see what's taking time in userspace. Mine was ntp so would be similar to SB's otherwise.

5.135s ntp.service

Link to comment
Share on other sites

Hmm. Looks like I certainly have a unique Arch os. :hysterical:

 

[11:34][bloodaxe@longship ~]$ systemd-analyze blame

11.672s dhcpcd@eth0.service

415ms media.mount

77ms user@1000.service

71ms systemd-udev-trigger.service

70ms kmod-static-nodes.service

62ms systemd-sysctl.service

61ms systemd-vconsole-setup.service

60ms systemd-fsck@dev-disk-by\x2duuid-65C5330150F0B7C3.service

57ms dev-hugepages.mount

57ms dev-mqueue.mount

57ms sys-kernel-debug.mount

48ms sys-kernel-config.mount

42ms systemd-logind.service

35ms systemd-fsck-root.service

32ms systemd-tmpfiles-clean.service

19ms systemd-tmpfiles-setup-dev.service

18ms ntpd.service

15ms systemd-tmpfiles-setup.service

13ms systemd-journal-flush.service

12ms alsa-restore.service

11ms systemd-random-seed.service

9ms systemd-udevd.service

8ms systemd-update-utmp.service

lines 1-23...skipping...

11.672s dhcpcd@eth0.service

415ms media.mount

77ms user@1000.service

71ms systemd-udev-trigger.service

70ms kmod-static-nodes.service

62ms systemd-sysctl.service

61ms systemd-vconsole-setup.service

60ms systemd-fsck@dev-disk-by\x2duuid-65C5330150F0B7C3.service

57ms dev-hugepages.mount

57ms dev-mqueue.mount

57ms sys-kernel-debug.mount

48ms sys-kernel-config.mount

42ms systemd-logind.service

35ms systemd-fsck-root.service

32ms systemd-tmpfiles-clean.service

19ms systemd-tmpfiles-setup-dev.service

18ms ntpd.service

15ms systemd-tmpfiles-setup.service

13ms systemd-journal-flush.service

12ms alsa-restore.service

11ms systemd-random-seed.service

9ms systemd-udevd.service

8ms systemd-update-utmp.service

7ms systemd-user-sessions.service

5ms tmp.mount

5ms systemd-remount-fs.service

lines 1-26...skipping...

11.672s dhcpcd@eth0.service

415ms media.mount

77ms user@1000.service

71ms systemd-udev-trigger.service

70ms kmod-static-nodes.service

62ms systemd-sysctl.service

61ms systemd-vconsole-setup.service

60ms systemd-fsck@dev-disk-by\x2duuid-65C5330150F0B7C3.service

57ms dev-hugepages.mount

57ms dev-mqueue.mount

57ms sys-kernel-debug.mount

48ms sys-kernel-config.mount

42ms systemd-logind.service

35ms systemd-fsck-root.service

32ms systemd-tmpfiles-clean.service

19ms systemd-tmpfiles-setup-dev.service

18ms ntpd.service

15ms systemd-tmpfiles-setup.service

13ms systemd-journal-flush.service

12ms alsa-restore.service

11ms systemd-random-seed.service

9ms systemd-udevd.service

8ms systemd-update-utmp.service

7ms systemd-user-sessions.service

5ms tmp.mount

5ms systemd-remount-fs.service

1ms sys-fs-fuse-connections.mount

~

 

My system should be faster than Josh's.

 

As for example,

 

Mine = 42ms systemd-logind.service

Josh = 1.663s systemd-logind.service

Mine = 62ms systemd-sysctl.service

Josh = 312ms systemd-sysctl.service

However I seem to have a hold up or two,

 

Mine = 11.672s dhcpcd@eth0.service

Josh = don't seem to have this

 

Mine = 415ms media.mount

Josh = 19ms MEDIA.mount

 

 

Now why my output shows three times I have no idea. The results are interesting though. I guess I need to brush up on optimizing my system.

I'll post the output of my system running on the F3 hdd for a comparison.

 

:breakfast:

Link to comment
Share on other sites

60 GB SSD

 

[11:18][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 5.128s (kernel) + 13.117s (userspace) = 18.246s

 

500 GB F3 HDD

 

[12:27][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 7.296s (kernel) + 16.808s (userspace) = 24.105s

 

Second try with 500 GB F3

 

[12:43][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 5.268s (kernel) + 12.859s (userspace) = 18.127s

 

 

True to form my system is throwing up strange results. After " systemd-analyze blame" I end up with "lines 1-31/31(END)" but no standard prompt. An the results are odd.

 

 

 

 

Faster = 7.515s dhcpcd@eth0.service

Miles slower = 3.539s systemd-fsck@dev-disk-by\x2duuid-d7b2d735\x2d3c66\x2d4e53\x2d92

Miles slower = 2.533s systemd-logind.service

 

I think the system did a fsck check on a drive which may explain some results.

 

All is well though as me system is still acting strangely. Who needs normal. o:)

 

Here is the output from my second try with the F3

 

6.039s dhcpcd@eth0.service

1.697s media.mount

1.640s systemd-fsck@dev-disk-by\x2duuid-f407013b\x2dd8e3\x2d4f7b\x2db

1.635s systemd-fsck@dev-disk-by\x2duuid-6332a101\x2dc1e5\x2d47a4\x2d9

1.060s systemd-logind.service

646ms systemd-fsck@dev-disk-by\x2duuid-d7b2d735\x2d3c66\x2d4e53\x2d9

6.039s dhcpcd@eth0.service

6.039s dhcpcd@eth0.service

1.697s media.mount

1.640s systemd-fsck@dev-disk-by\x2duuid-f407013b\x2dd8e3\x2d4f7b\x2db

1.635s systemd-fsck@dev-disk-by\x2duuid-6332a101\x2dc1e5\x2d47a4\x2d9

1.060s systemd-logind.service

646ms systemd-fsck@dev-disk-by\x2duuid-d7b2d735\x2d3c66\x2d4e53\x2d9

456ms systemd-fsck@dev-disk-by\x2duuid-65C5330150F0B7C3.service

452ms systemd-udev-trigger.service

410ms kmod-static-nodes.service

386ms dev-hugepages.mount

386ms sys-kernel-debug.mount

385ms dev-mqueue.mount

376ms boot.mount

326ms systemd-tmpfiles-setup.service

321ms systemd-vconsole-setup.service

298ms systemd-user-sessions.service

288ms systemd-sysctl.service

276ms home.mount

247ms sys-kernel-config.mount

246ms systemd-remount-fs.service

222ms user@1000.service

194ms systemd-random-seed.service

188ms var.mount

125ms dev-disk-by\x2duuid-0549b8b3\x2d2e81\x2d478b\x2d96ae\x2d195389

123ms ntpd.service

98ms systemd-tmpfiles-setup-dev.service

55ms systemd-udevd.service

46ms systemd-update-utmp.service

22ms systemd-journal-flush.service

15ms tmp.mount

7ms alsa-restore.service

5ms sys-fs-fuse-connections.mount

 

Almost every result is different to the first try with the F3 (not shown). It would seem that every boot is different, as any cobbler would tell you. Also a slow ssd does not boot faster than a standard hard drive.

What a load of old cobblers. :Laughing:

Edited by abarbarian
Link to comment
Share on other sites

securitybreach

Well first off, the output will not end with a command prompt unless you hit q afterwards. The reason being is so you can scroll the output if need be. Secondly if you do not remove unneeded services, your boot will be much slower. Lastly, unless you followed the wiki entry for SSDs, aligned your partitions and used the trim option; your SSD will not be any faster than your sata drive.

https://wiki.archlinux.org/index.php/SSD#Tips_for_Maximizing_SSD_Performance

https://wiki.archlinux.org/index.php/SSD_Benchmarking

https://wiki.archlinux.org/index.php/Improve_Boot_Performance

Link to comment
Share on other sites

Lastly, unless you followed the wiki entry for SSDs, aligned your partitions and used the trim option; your SSD will not be any faster than your sata drive.

https://wiki.archlin...SSD_Performance

https://wiki.archlin...SD_Benchmarking

https://wiki.archlin...oot_Performance

 

 

[15:19][root@longship bloodaxe]# blockdev --getalignoff /dev/sdf1

0

[15:20][root@longship bloodaxe]# hdparm -I /dev/sdf |grep TRIM

* Data Set Management TRIM supported (limit 1 block)

[15:20][root@longship bloodaxe]#

 

Fstab entry

 

/dev/sdf1 / ext4 defaults,noatime,discard 0 1

 

 

Well as per the wiki me ssd is set up ok. An it is still not noticeably faster at boot than me hdd. Work wise it is certainly faster.

Yup I do need to look into setting me system up but am a tad under pressure from the bride at the moment. :shifty:

Edited by abarbarian
  • Like 1
Link to comment
Share on other sites

Another good guide here:

http://freedesktop.o.../Optimizations/

systemd can already offer boot times of < 1s for the Core OS (userspace only, i.e. only the bits controlled by systemd) and < 2s for a complete up-to-date desktop environments on simpler (but modern, i.e. SSDs) laptops if configured properly
:o

More tweaking is in order, boys! ;)

 

Those Arch wiki guides on SSDs are possibly the best around.

  • Like 1
Link to comment
Share on other sites

Sans ntp -

Startup finished in 3.608s (kernel) + 4.851s (userspace) = 8.460s

B)

 

Later that same evening, removed lvm-related stuff -

systemctl mask lvm2-activation-early.service
systemctl mask lvm2-activation.service

Startup finished in 3.542s (kernel) + 3.724s (userspace) = 7.266s

 

Still a few more I can hide but, would I even notice? :)

  • Like 1
Link to comment
Share on other sites

  • 3 months later...
abarbarian
╰─><(((“>$ systemd-analyze 30/05/14

Startup finished in 6.876s (kernel) + 15.271s (userspace) = 22.147s

 

Well I made a few tweaks to systemd and thankfully I still have a working system. This is baffling the heck out of me as I get a different time for startup and userspace every time.

My findings are not very scientific as I have made some changes to my set up. In that I now can start the pc and go straight into a grub menu instead of having to use the boot menu. An I have sucessfully added a W7 to grub that works. So no more fiddling about and waiting. I can just power up and either run to Arch or hit W7 in the grub menu.

 

:breakfast:

Link to comment
Share on other sites

dhcpcd@eth0.service is a beast. Once I got my laptop loaded on the SSD and started running on WiFi, I disabled that service because if memory serves me, I was registering something like 13 seconds for that one service alone. I know there are those on here that are not fans of systemd, but this penguin is DEFINITELY a fan. ;)

  • Like 1
Link to comment
Share on other sites

After the incorporation of systemd, I did not know how to make a static IP. The server which is still under inet has a static IP. Has been a LONG TIME since I updated the server because "If it ain't broke, don't fix it" :) Though, that theory is about to change with needing to hit it remotely. ;)

Link to comment
Share on other sites

securitybreach

Here is the custom systemd service I made called network.service and located at /etc/systemd/system/network.service :

[unit]
Description=Wired Static IP Connectivity
Wants=network.target
Before=network.target

[service]
Type=oneshot
RemainAfterExit=yes
EnvironmentFile=/etc/conf.d/network
ExecStart=/sbin/ip link set dev enp3s0 up
ExecStart=/sbin/ip addr add 192.168.1.2/24 broadcast 192.168.1.255 dev enp3s0
ExecStart=/sbin/ip route add default via 192.168.1.1

ExecStop=/sbin/ip addr flush dev enp3s0
ExecStop=/sbin/ip link set dev enp3s0 down

[install]
WantedBy=multi-user.target

 

Replace the IP you want, your router IP and also the device label. Then systemctl enable network.service and disable the dhcpcd@eth0.service service.

Link to comment
Share on other sites

  • 3 weeks later...

Here is the custom systemd service I made called network.service and located at /etc/systemd/system/network.service :

[unit]
Description=Wired Static IP Connectivity
Wants=network.target
Before=network.target

[service]
Type=oneshot
RemainAfterExit=yes
EnvironmentFile=/etc/conf.d/network
ExecStart=/sbin/ip link set dev enp3s0 up
ExecStart=/sbin/ip addr add 192.168.1.2/24 broadcast 192.168.1.255 dev enp3s0
ExecStart=/sbin/ip route add default via 192.168.1.1

ExecStop=/sbin/ip addr flush dev enp3s0
ExecStop=/sbin/ip link set dev enp3s0 down

[install]
WantedBy=multi-user.target

 

Replace the IP you want, your router IP and also the device label. Then systemctl enable network.service and disable the dhcpcd@eth0.service service.

 

Would that work for me ? I am on AOL using their router, an as far as I know I do not have a static IP addy. :hmm:

Link to comment
Share on other sites

securitybreach

Well I use that getting a static IP from my router, not from my ISP. The router gets the dynamic IP from the ISP.

Link to comment
Share on other sites

Mine is still 7.5 secs after 6 months from installing. But then I didn't set AHCI when I installed it and the Vertex2 is about 4 years old now. Many improvements have happened then.

I may have to lash out for one of these new-fangled SSDs soon. The Samsung 840 series is often in the top of the performance charts at Tom's Hardware.

  • Like 1
Link to comment
Share on other sites

You need a 240/256 GB ssd or above to see the fastest results. Josh would not even have time to blink at start up if he had one instead of his slow 120 GB. :tease:

  • Like 1
Link to comment
Share on other sites

  • 4 weeks later...

Here are the results of my old set up.

 

60 GB SSD

 

[11:18][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 5.128s (kernel) + 13.117s (userspace) = 18.246s

 

500 GB F3 HDD

 

[12:27][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 7.296s (kernel) + 16.808s (userspace) = 24.105s

 

Second try with 500 GB F3

 

[12:43][bloodaxe@longship ~]$ systemd-analyze

Startup finished in 5.268s (kernel) + 12.859s (userspace) = 18.127s

 

An here are the results of my new super dooper four core cpu and me much faster 120 GB ssd (not as good as 240 GB) and a totally clean fresh standard install of Arch 64. Now you would expect lightening fast results would you not after all that effort.

 

$ systemd-analyze

Startup finished in 6.522s (kernel) + 1min 30.279s (userspace) = 1min 36.802s

 

Impressive eh ! :Laughing:

Link to comment
Share on other sites

securitybreach

You need to run

systemd-analyze blame

to see why it is taking so long. You should have a 1-2 second boot time with an ssd. Also, does your drive support trim and did you follow the wiki entry for ssds?

Link to comment
Share on other sites

Well I have sorted a few small glitches I have made in me new install and I tried a systemd-analyze and this is what I got. :Laughing:

 

$ systemd-analyze
Startup finished in 6.940s (kernel) + 1min 30.366s (userspace) = 1min 37.306s

 

 

Also, does your drive support trim and did you follow the wiki entry for ssds?

 

 

 

He he you asked me that same Q for the last ssd I used. Same A=yes. :breakfast:

 

 

 

1min 50.954s man-db.service

109ms systemd-logind.service

96ms systemd-fsck@dev-disk-by\x2duuid-57d782bb\x2dee4d\x2d430f\x2d92

94ms systemd-vconsole-setup.service

92ms alsa-restore.service

91ms systemd-fsck@dev-disk-by\x2duuid-1e0a60e6\x2d465a\x2d49fd\x2d9e

87ms dhcpcd.service

62ms systemd-rfkill@rfkill0.service

49ms systemd-update-utmp.service

47ms systemd-udev-trigger.service

46ms logrotate.service

42ms user@1000.service

30ms systemd-journal-flush.service

25ms tmp.mount

23ms dev-hugepages.mount

21ms dev-mqueue.mount

21ms shadow.service

21ms home.mount

20ms systemd-remount-fs.service

20ms systemd-tmpfiles-setup-dev.service

19ms systemd-random-seed.service

19ms sys-kernel-config.mount

18ms var.mount

17ms sys-kernel-debug.mount

16ms systemd-tmpfiles-setup.service

11ms systemd-sysctl.service

10ms kmod-static-nodes.service

92ms alsa-restore.service

91ms systemd-fsck@dev-disk-by\x2duuid-1e0a60e6\x2d465a\x2d49fd\x2d9e

87ms dhcpcd.service

62ms systemd-rfkill@rfkill0.service

49ms systemd-update-utmp.service

47ms systemd-udev-trigger.service

46ms logrotate.service

42ms user@1000.service

30ms systemd-journal-flush.service

25ms tmp.mount

23ms dev-hugepages.mount

21ms dev-mqueue.mount

21ms shadow.service

21ms home.mount

20ms systemd-remount-fs.service

20ms systemd-tmpfiles-setup-dev.service

19ms systemd-random-seed.service

19ms sys-kernel-config.mount

18ms var.mount

17ms sys-kernel-debug.mount

16ms systemd-tmpfiles-setup.service

11ms systemd-sysctl.service

10ms kmod-static-nodes.service

9ms systemd-tmpfiles-clean.service

8ms systemd-user-sessions.service

5ms systemd-udevd.service

4ms sys-fs-fuse-connections.mount

 

here is the miscreant,

 

1min 50.954s man-db.service

 

Funny I never had that service in my last look at blame.Of to see what it is. :breakfast:

Link to comment
Share on other sites

securitybreach

Here ya go:

It is triggered by a systemd.timer. These have been put in use in place of anacron. So if your comptuer was due for this to be run while the machine was off, it does it upon restart/wake/whatever. This is not something that will happen frequently.

Check out the timer unit to see how frequently it runs. It is really no different than the time intervals that were in place before with anacron.

https://bbs.archlinux.org/viewtopic.php?id=180039

Link to comment
Share on other sites

Well I started my pc and got to Window Maker and ran systemd-analyze from a terminal and got the results below.After three or four minutes I tried systemd-analyze again and it gave a result. So I have no idea what is going on. How can boot up not be finished when I am in a desktop and able to run programs???

 

[bloodaxe@longship ~]$ systemd-analyze
Bootup is not yet finished. Please try again later.
[bloodaxe@longship ~]$ systemd-analyze blame
	   140ms systemd-logind.service
	   122ms systemd-fsck@dev-disk-by\x2duuid-1e0a60e6\x2d465a\x2d49fd\x2d9e
	   110ms dhcpcd.service
	   103ms alsa-restore.service
	    88ms systemd-vconsole-setup.service
	    82ms systemd-fsck@dev-disk-by\x2duuid-57d782bb\x2dee4d\x2d430f\x2d92
	    54ms systemd-udev-trigger.service
	    42ms user@1000.service
	    38ms systemd-journal-flush.service
	    36ms systemd-update-utmp.service
	    35ms systemd-rfkill@rfkill0.service
	    31ms home.mount
	    24ms tmp.mount
	    24ms systemd-tmpfiles-setup.service
	    22ms dev-hugepages.mount
	    21ms dev-mqueue.mount
	    20ms systemd-random-seed.service
	    18ms var.mount
	    18ms sys-kernel-config.mount
	    17ms systemd-tmpfiles-setup-dev.service
	    16ms sys-kernel-debug.mount
	    15ms systemd-user-sessions.service
	    14ms systemd-sysctl.service
	    12ms systemd-remount-fs.service
	    11ms kmod-static-nodes.service
		 7ms systemd-udevd.service

[bloodaxe@longship ~]$ systemd-analyze
Bootup is not yet finished. Please try again later.
[bloodaxe@longship ~]$ systemd-analyze blame | grep man-db
[bloodaxe@longship ~]$ systemd-analyze
Startup finished in 7.211s (kernel) + 1min 30.300s (userspace) = 1min 37.512s
[bloodaxe@longship ~]$ systemd-analyze blame | grep man-db
[bloodaxe@longship ~]$ 

 

:angry2:

Link to comment
Share on other sites

securitybreach

Well two of your drives were fsck'd (checked) at bootup so that only happens once in a while. Plus the math doesnt add up right. I just added all your services and they add up to 1120ms which is 0.018 minutes so something else is starting..

Link to comment
Share on other sites

I came to the same conclusion but what is starting and how do I find it ?? This is a fresh install everything is supposed to work ok for at least a few days till I cock it up. It may be to do with dhcpcd so I'll go and investigate further.

 

Also why does the 1min 30.300s bit not show up in systemd-analyze blame ?? I thought everything was supposed to show up there. Bleeping modern day progress, bah humbug. :angry2:

Edited by abarbarian
Link to comment
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

×
×
  • Create New...