You are not logged in.

Pages: 1

#1 2014-11-03 13:45:55

geosmin
Member
Registered: 2014-09-22
Posts: 23

[SOLVED] Slow boot. Ran systemd-analyze blame.

Issue:
Boot seems snappy, but when I get to the tty login there's a ~35s-1m10s delay before the login completes.

What I've tried:
- Boot with WiFi switch off
- Remove wpa_supplicant
- "Remove" systemd-hostnamed service files (backed them up and restored them when I saw it hadn't helped)
- Add Type=simple to autologin.conf
- Remove autologin.conf
- Disable openvpn
- Disable connman
- Removed some RAM? Success!

$ systemd-analyze blame

     1min 9.815s user@1000.service
     1min 5.556s wpa_supplicant.service
         35.248s systemd-hostnamed.service
         12.764s openvpn@usa.service
          7.402s systemd-backlight@backlight:acpi_video0.service
          7.394s systemd-backlight@backlight:radeon_bl0.service
          7.353s shadow.service
          7.189s logrotate.service
          6.880s systemd-user-sessions.service
          1.267s systemd-logind.service
          1.265s connman.service
          1.255s chrony.service
          1.067s systemd-tmpfiles-clean.service
          1.049s alsa-restore.service
           914ms systemd-remount-fs.service
           860ms dev-hugepages.mount
           858ms dev-mqueue.mount
           856ms sys-kernel-config.mount
           854ms sys-kernel-debug.mount
           851ms tmp.mount
           755ms systemd-udev-trigger.service
           631ms kmod-static-nodes.service
           586ms systemd-fsck@dev-disk-by\x2duuid-12636bd2\x2d5d5b\x2d4267\x2d843f\x2db1bbc130e62c.service
           282ms systemd-vconsole-setup.service
           223ms systemd-random-seed.service
           204ms systemd-rfkill@rfkill0.service
           165ms systemd-sysctl.service
           158ms boot.mount
           147ms systemd-tmpfiles-setup.service
            98ms systemd-tmpfiles-setup-dev.service
            59ms systemd-update-utmp.service
            51ms systemd-udevd.service
            12ms connman-vpn.service
             3ms systemd-journal-flush.service
             1ms systemd-rfkill@rfkill1.service

Wow! What's going on?

$ systemd-analyze critical-chain

The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

graphical.target @20.574s
└─multi-user.target @20.553s
  └─openvpn@usa.service @7.768s +12.764s
    └─basic.target @7.765s
      └─timers.target @7.765s
        └─updatedb.timer @7.765s
          └─sysinit.target @7.735s
            └─systemd-journald.service @1min 42.978s
              └─system.slice @1.255s
                └─-.slice @1.250s

$ systemctl status user@1000

● user@1000.service - User Manager for UID 1000
   Loaded: loaded (/usr/lib/systemd/system/user@.service; static)
   Active: active (running) since Mon 2014-11-03 08:34:13 EST; 6min ago
 Main PID: 350 (systemd)
   Status: "Startup finished in 35.658s."
   CGroup: /user.slice/user-1000.slice/user@1000.service
           ├─350 /usr/lib/systemd/systemd --user
           └─351 (sd-pam)

Nov 03 08:33:37 arch2 systemd[350]: pam_unix(systemd-user:session): session opened for user geosmin by (uid=0)
Nov 03 08:34:13 arch2 systemd[1]: Started User Manager for UID 1000.

$ systemctl status wpa_supplicant

● wpa_supplicant.service - WPA supplicant
   Loaded: loaded (/usr/lib/systemd/system/wpa_supplicant.service; disabled)
   Active: active (running) since Mon 2014-11-03 08:34:13 EST; 8min ago
 Main PID: 356 (wpa_supplicant)
   CGroup: /system.slice/wpa_supplicant.service
           └─356 /usr/bin/wpa_supplicant -u

$ systemctl status systemd-hostnamed

● systemd-hostnamed.service - Hostname Service
   Loaded: loaded (/usr/lib/systemd/system/systemd-hostnamed.service; static)
   Active: failed (Result: exit-code) since Mon 2014-11-03 08:34:13 EST; 8min ago
     Docs: man:systemd-hostnamed.service(8)
           man:hostname(5)
           man:machine-info(5)
           [url]http://www.freedesktop.org/wiki/Software/systemd/hostnamed[/url]
  Process: 355 ExecStart=/usr/lib/systemd/systemd-hostnamed (code=exited, status=1/FAILURE)
 Main PID: 355 (code=exited, status=1/FAILURE)

Nov 03 08:34:12 arch2 systemd-hostnamed[355]: Failed to register name: Connection timed out
Nov 03 08:34:13 arch2 systemd[1]: systemd-hostnamed.service: main process exited, code=exited, status=1/FAILURE
Nov 03 08:34:13 arch2 systemd[1]: Failed to start Hostname Service.

Any input appreciated.

Last edited by geosmin (2014-11-05 08:16:24)

Offline

#2 2014-11-03 17:12:47

TheSaint
Member
From: my computer
Registered: 2007-08-19
Posts: 1,523

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

What it does systemd-hostnamed for you. I haven't it running.

do it good first, it will be faster than do it twice the saint wink

Offline

#3 2014-11-03 17:39:49

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

I strongly suspect the problem is with the user@1000 service.

Offline

#4 2014-11-03 19:44:12

karol
Archivist
Registered: 2009-05-06
Posts: 25,440

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

TheSaint wrote:

What it does systemd-hostnamed for you. I haven't it running.

It's the systemd component that sets hostname up. 'man systemd-hostnamed' for details.
You can drop e.g. dhcpcd and cron and let systemd take over.

Offline

#5 2014-11-04 01:01:10

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Anybody? Sorry for the bump but with 500+ views I'm confused as to how this has virtually no replies. Am I lacking info?

Last edited by geosmin (2014-11-04 01:05:50)

Offline

#6 2014-11-04 02:35:43

karol
Archivist
Registered: 2009-05-06
Posts: 25,440

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Does it happen every time? What's up with your systemd-hostnamed timing out, can you establish a connection later, e.g. running it manually?

When posting configs, code or command output, please use [ code ] tags, not [ quote ] tags https://bbs.archlinux.org/help.php#bbcode

like this

It makes the code more readable and - in case of longer listings - more convenient to scroll through.

Offline

#7 2014-11-04 05:37:14

TheSaint
Member
From: my computer
Registered: 2007-08-19
Posts: 1,523

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

I  suspect that computer is trying to register in a network.

do it good first, it will be faster than do it twice the saint wink

Offline

#8 2014-11-04 08:31:09

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

karol wrote:

Does it happen every time? What's up with your systemd-hostnamed timing out, can you establish a connection later, e.g. running it manually?

Happens every time, connection works fine and I can ping my hostname with no problem, not sure what else to check.

Again, I think the problem lies in user@1000.service artificially inflating the numbers on the other processes, is this possible?

Offline

#9 2014-11-05 06:16:04

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

bump

Edit: Any input appreciated, not sure where to go from here.

Last edited by geosmin (2014-11-05 06:34:36)

Offline

#10 2014-11-05 06:28:19

jasonwryan
Anarchist
From: .nz
Registered: 2009-05-09
Posts: 30,424
Website

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

geosmin wrote:

bump

Don't do that: https://wiki.archlinux.org/index.php/Fo … te#Bumping

Arch + dwm   •   Mercurial repos  •   Surfraw

Registered Linux User #482438

Offline

#11 2014-11-05 07:11:42

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Uninstalled wpa_supplicant, no change at all. Reinstalled.

Offline

#12 2014-11-05 07:25:36

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Decided to be reckless and did:
# mv /usr/lib/systemd/systemd-hostnamed /usr/lib/systemd/systemd-hostnamed~
# mv /usr/lib/systemd/system/systemd-hostnamed.service /usr/lib/systemd/system/systemd-hostnamed.service~

Now systemd-analyze blame shows:

50.804s wpa_supplicant.service
50.803s connman-vpn.service
3.367s user@1000.service
....

I have no idea what's going on.

Last edited by geosmin (2014-11-05 07:26:11)

Offline

#13 2014-11-05 07:33:15

Mr Green
Forum Fellow
From: U.K.
Registered: 2003-12-21
Posts: 5,896
Website

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Might help with some hardware information, does seem odd having such a slow boot. Why not run up live ISO and see what timings are on that.

Mr Green

Offline

#14 2014-11-05 07:49:23

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Mr Green wrote:

Might help with some hardware information, does seem odd having such a slow boot. Why not run up live ISO and see what timings are on that.

Things were working perfectly a week or two ago( login was instantaneous vs. login takes ~45 seconds), this is definitely new.

Last edited by geosmin (2014-11-05 07:51:35)

Offline

#15 2014-11-05 08:15:04

geosmin
Member
Registered: 2014-09-22
Posts: 23

Re: [SOLVED] Slow boot. Ran systemd-analyze blame.

Seems the issue had something to do with RAM. Removed one of the sticks and boot was back to being snappy. Put it back in and it's still fine. Will have to run memtest.

Please close.

Last edited by geosmin (2014-11-05 08:15:17)

Offline

Pages: 1

Board footer

Powered by FluxBB