Slow netctl performance

Mr Green · 2014-01-27 16:09:02

I have switched too netctl as I figured better performance than using network manager

systemd-analyze blame
          9.626s netctl@wlan0\x2dSKY8B17D.service
          2.738s psd.service
           506ms psd-resync.service
           136ms systemd-fsck@dev-sdb2.service
            97ms systemd-logind.service
            89ms systemd-vconsole-setup.service
            83ms systemd-modules-load.service
            63ms colord.service
            63ms systemd-udev-trigger.service
            61ms home-mrgreen-bigdrive.mount
            58ms nfsd.service
            50ms dev-hugepages.mount
            50ms rpc-mountd.service
            49ms systemd-tmpfiles-clean.service
            46ms kmod-static-nodes.service
            43ms dev-mqueue.mount
            39ms systemd-sysctl.service
            38ms sys-kernel-debug.mount
            35ms systemd-remount-fs.service
            31ms user@1000.service
            29ms systemd-fsck@dev-sda3.service
            29ms alsa-restore.service
            26ms systemd-fsck@dev-sda4.service
            24ms systemd-tmpfiles-setup-dev.service
            14ms systemd-update-utmp.service
            13ms home.mount
            10ms rpc-idmapd.service
             8ms systemd-random-seed.service
             6ms systemd-tmpfiles-setup.service
             6ms var.mount
             5ms rpcbind.service
             4ms systemd-journal-flush.service
             3ms systemd-user-sessions.service
             3ms tmp.mount
             3ms sys-fs-fuse-connections.mount
             3ms systemd-udevd.service
             2ms sys-kernel-config.mount
             2ms var-lib-nfs-rpc_pipefs.mount

Startup finished in 4.631s (kernel) + 10.703s (userspace) = 15.335s

Looks very slow to me, going to chekc wiki again for netctl, meantime would like to know of anything I can do to reduce boot time?

WonderWoofy · 2014-01-27 16:39:48

The netctl@.service waits for an IP before reporting the service as complete. NetworkManager, wicd, and connman all report completion of the service only after the daemon has loaded. This is because they are meant to handle intermittent network connectivity, so a connection is never guaranteed.

If you want to continue to use netctl under similar conditions as NetworkManager, wicd, and connman, you should use the netctl-auto functionality. That service will complete after loading the available profiles rather than waiting for an IP.

If you really want a network manager service that performs well, I would recommend using connman. It is still being developed and documentation is sparse, but it starts fast and it uses its own internal dhcp client to get an IP, which seems (in my experience) to be much faster.

systemd-analyze blame wrote:

systemd-analyze blame
...
48ms thermald.service
41ms home.mount
41ms bluetooth.service
41ms systemd-logind.service
39ms systemd-vconsole-setup.service
37ms connman.service
36ms systemd-udev-trigger.service
30ms polkit.service
24ms lm_sensors.service
22ms systemd-journal-flush.service
19ms systemd-update-utmp.service
19ms ntpd.service
....

Mr Green · 2014-01-27 16:48:36

Not too worried about psd as it does give me real boost when using firefox. Might have been wrong as I figured netctl would be a faster better option. Will take a look at connman (not heard of it!).

Thank you

WonderWoofy · 2014-01-27 17:32:36

Install wpa_actiond, then instead of enabling a single profile, enable netctl-auto@<interface>.service (you'll have to use systemctl directly for this).

Mr Green · 2014-01-27 18:45:30

Well now getting

systemd-analyze 
Bootup is not yet finished. Please try again later.

but blame gives me something I like

109ms netctl-auto@wlan0.service

Will check systemctl as I did use the wrong name at first

Happier now ;-)

WonderWoofy · 2014-01-27 23:03:54

The only times I get those "Bootup is not yet finished..." things is when I have a service enabled for an interface or disk that doesn't exist. So for example, if you enable dhcpcd@wlan0, but your interface is actually renamed by udev to enp12s0, then it is going to wait for a set period of time until it finally gives up. This is caused by the BindsTo=sys-subsystem-net-devices-%i.device in the dhcpcd@.service file.

Mr Green · 2014-01-28 09:16:31

Interface name is wlan0, disabled netctl-auto and boot up time is still very long so might be something else. Systemctl status does not show any real issues will look at journalctl at some point. Never noticed it before using an SSD drive boot times were seconds...

WonderWoofy · 2014-01-28 15:16:03

See if there are any failed devices. Do 'systemctl --type=device' and see if you see any red. If so, systemd is stuck waiting on that failed device.

Mr Green · 2014-01-28 15:26:36

Looks fine

[~]$ systemctl --type=device
UNIT                                                                                                  LOAD   ACTIVE SUB     DESCRIPTION
sys-devices-pci0000:00-0000:00:02.0-0000:01:00.1-sound-card1.device                                   loaded active plugged High Definition Audio Controller
sys-devices-pci0000:00-0000:00:0a.0-0000:03:00.0-net-eth0.device                                      loaded active plugged P8P67 and other motherboards
sys-devices-pci0000:00-0000:00:11.0-ata6-host5-target5:0:0-5:0:0:0-block-sda-sda1.device              loaded active plugged KINGSTON_SV200S3128G
sys-devices-pci0000:00-0000:00:11.0-ata6-host5-target5:0:0-5:0:0:0-block-sda-sda2.device              loaded active plugged KINGSTON_SV200S3128G
sys-devices-pci0000:00-0000:00:11.0-ata6-host5-target5:0:0-5:0:0:0-block-sda-sda3.device              loaded active plugged KINGSTON_SV200S3128G
sys-devices-pci0000:00-0000:00:11.0-ata6-host5-target5:0:0-5:0:0:0-block-sda-sda4.device              loaded active plugged KINGSTON_SV200S3128G
sys-devices-pci0000:00-0000:00:11.0-ata6-host5-target5:0:0-5:0:0:0-block-sda.device                   loaded active plugged KINGSTON_SV200S3128G
sys-devices-pci0000:00-0000:00:11.0-ata7-host6-target6:0:0-6:0:0:0-block-sdb-sdb1.device              loaded active plugged SAMSUNG_HD103SI
sys-devices-pci0000:00-0000:00:11.0-ata7-host6-target6:0:0-6:0:0:0-block-sdb-sdb2.device              loaded active plugged SAMSUNG_HD103SI
sys-devices-pci0000:00-0000:00:11.0-ata7-host6-target6:0:0-6:0:0:0-block-sdb.device                   loaded active plugged SAMSUNG_HD103SI
sys-devices-pci0000:00-0000:00:11.0-ata8-host7-target7:0:0-7:0:0:0-block-sr0.device                   loaded active plugged Optiarc_DVD_RW_AD-7240S
sys-devices-pci0000:00-0000:00:13.2-usb4-4\x2d4-4\x2d4:1.0-host8-target8:0:0-8:0:0:0-block-sdc.device loaded active plugged Compact_Flash
sys-devices-pci0000:00-0000:00:13.2-usb4-4\x2d4-4\x2d4:1.0-host8-target8:0:0-8:0:0:1-block-sdd.device loaded active plugged SM_xD-Picture
sys-devices-pci0000:00-0000:00:13.2-usb4-4\x2d4-4\x2d4:1.0-host8-target8:0:0-8:0:0:2-block-sde.device loaded active plugged SD_MMC
sys-devices-pci0000:00-0000:00:13.2-usb4-4\x2d4-4\x2d4:1.0-host8-target8:0:0-8:0:0:3-block-sdf.device loaded active plugged MS_MS-Pro
sys-devices-pci0000:00-0000:00:14.2-sound-card0.device                                                loaded active plugged M4A785TD Motherboard
sys-devices-pci0000:00-0000:00:14.4-0000:04:05.0-net-wlan0.device                                     loaded active plugged AR2417 Wireless Network Adapter [AR5007G 802.11bg]
sys-devices-platform-serial8250-tty-ttyS1.device                                                      loaded active plugged /sys/devices/platform/serial8250/tty/ttyS1
sys-devices-platform-serial8250-tty-ttyS2.device                                                      loaded active plugged /sys/devices/platform/serial8250/tty/ttyS2
sys-devices-platform-serial8250-tty-ttyS3.device                                                      loaded active plugged /sys/devices/platform/serial8250/tty/ttyS3
sys-devices-pnp0-00:07-tty-ttyS0.device                                                               loaded active plugged /sys/devices/pnp0/00:07/tty/ttyS0
sys-module-configfs.device                                                                            loaded active plugged /sys/module/configfs
sys-module-fuse.device                                                                                loaded active plugged /sys/module/fuse
sys-subsystem-net-devices-eth0.device                                                                 loaded active plugged P8P67 and other motherboards
sys-subsystem-net-devices-wlan0.device                                                                loaded active plugged AR2417 Wireless Network Adapter [AR5007G 802.11bg]

LOAD   = Reflects whether the unit definition was properly loaded.
ACTIVE = The high-level unit activation state, i.e. generalization of SUB.
SUB    = The low-level unit activation state, values depend on unit type.

25 loaded units listed. Pass --all to see loaded but inactive units, too.
To show all installed unit files use 'systemctl list-unit-files'.

Did try booting without netctl and boot is fast around 8 secs, am starting to think of trying to 'start' 'stop' service on log[in|out]

WonderWoofy · 2014-01-28 16:01:04

You did remember to disable the netctl@<profile>.service when you enabled netctl-auto@wlan0.service, yeah?

Mr Green · 2014-01-29 11:48:04

Yes made sure I did that, am thinking it is just netctl takes quite some time to set up wireless device. netctl-auto is much quicker but still run into a long userspace time

systemd-analyze 
Startup finished in 5.269s (kernel) + 1min 30.281s (userspace) = 1min 35.551s

Will admit I have switched back to netctl@<profile>service for now

Mr Green · 2014-02-01 09:40:53

This is output of user session

-- Logs begin at Wed 2014-01-22 11:30:54 GMT, end at Sat 2014-02-01 09:25:38 GMT. --
Feb 01 09:25:08 macmillan systemd[463]: Failed to open private bus connection: Failed to connect to socket /run/user/1000/dbus/user_bus_socket: No such file or directory
Feb 01 09:25:08 macmillan systemd[463]: Mounted /sys/kernel/config.
Feb 01 09:25:08 macmillan systemd[463]: Mounted /sys/fs/fuse/connections.
Feb 01 09:25:08 macmillan systemd[463]: Stopped target Sound Card.
Feb 01 09:25:08 macmillan systemd[463]: Starting Default.
Feb 01 09:25:08 macmillan systemd[463]: Reached target Default.
Feb 01 09:25:08 macmillan systemd[463]: Startup finished in 20ms.
Feb 01 09:25:38 macmillan org.a11y.Bus[477]: Activating service name='org.a11y.atspi.Registry'
Feb 01 09:25:38 macmillan org.a11y.Bus[477]: Successfully activated service 'org.a11y.atspi.Registry'
Feb 01 09:25:38 macmillan org.a11y.atspi.Registry[658]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Feb 01 09:25:38 macmillan org.a11y.atspi.Registry[658]: ** (at-spi2-registryd:661): WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .se
Feb 01 09:25:38 macmillan org.a11y.atspi.Registry[658]: ** (at-spi2-registryd:661): WARNING **: Unable to register client with session manager

From system

Feb 01 09:25:01 macmillan systemd[1]: Starting Create list of required static device nodes for the current kernel...
Feb 01 09:25:01 macmillan systemd[1]: Started Create list of required static device nodes for the current kernel.
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
netctl@wlan0-SKY8B17D.service -> '/org/freedesktop/systemd1/unit/netctl_40wlan0_2dSKY8B17D_2eservice'

netctl@wlan0-SKY8B17D.service - Networking for netctl profile wlan0/SKY8B17D
   Loaded: loaded (/usr/lib/systemd/system/netctl@.service; static)
   Active: failed (Result: exit-code) since Sat 2014-02-01 09:26:37 GMT; 7min ago
     Docs: man:netctl.profile(5)
  Process: 809 ExecStart=/usr/lib/network/network start %I (code=exited, status=1/FAILURE)
 Main PID: 809 (code=exited, status=1/FAILURE)
   CGroup: /system.slice/system-netctl.slice/netctl@wlan0-SKY8B17D.service

Feb 01 09:26:37 macmillan network[809]: Profile 'wlan0/SKY8B17D' does not exist or is not readable
Feb 01 09:26:37 macmillan systemd[1]: netctl@wlan0-SKY8B17D.service: main process exited, code=exited, status=1/FAILURE
Feb 01 09:26:37 macmillan systemd[1]: Failed to start Networking for netctl profile wlan0/SKY8B17D.
Feb 01 09:26:37 macmillan systemd[1]: Unit netctl@wlan0-SKY8B17D.service entered failed state.

Do having working network so still unsure of problem. Am thinking of reinstalling Arch (more as a system cleanup) still confused as too why system takes so long to boot.

WonderWoofy · 2014-02-01 17:44:36

I know that netctl defaults to using interface-ssid (wlan0-SKY8B17D) as the profile name. But systemd treats '-' as a special character internally. It is what is used in systemd.mount and systemd.automount file names to denote actual paths. So it can sometimes cause things to go wonky. Try renaming your profile to just SKY8B17D or anything else without the dash/hyphen in the middle.

Miblo · 2014-02-01 18:04:48

You could also check the output of $(systemd-analyze plot > bootplot.svg) to try and narrow down which service could be holding things up. My culprit: dhcpcd. My saviour: connman.

Mr Green · 2014-02-01 19:03:00

@WonderWoofy you might have a point there, will give it a go...

WonderWoofy · 2014-02-01 19:19:09

Yeah, this is why I think it is looking at the profile name as a path:

netctl@wlan0-SKY8B17D wrote:

Feb 01 09:26:37 macmillan network[809]: Profile 'wlan0/SKY8B17D' does not exist or is not readable
...
Feb 01 09:26:37 macmillan systemd[1]: Failed to start Networking for netctl profile wlan0/SKY8B17D.

Mr Green · 2014-02-01 19:35:16

I could not see the problem for looking, can I send you all my configs for you to check over? ;-)

Thank you

WonderWoofy · 2014-02-01 20:08:23

No problem.

Mr Green · 2014-02-01 20:16:20

I still have long boot time

systemd-analyze 
Startup finished in 3.610s (kernel) + 1min 30.287s (userspace) = 1min 33.897s

Have disabled netctl and psd service with no change, it is in userspace but am not able to figure out the problem. Totally weird this one, maybe I need to reinstall .... downloading arch install media!

Arch Linux

#1 2014-01-27 16:09:02

Slow netctl performance

#2 2014-01-27 16:39:48

Re: Slow netctl performance

#3 2014-01-27 16:48:36

Re: Slow netctl performance

#4 2014-01-27 17:32:36

Re: Slow netctl performance

#5 2014-01-27 18:45:30

Re: Slow netctl performance

#6 2014-01-27 23:03:54

Re: Slow netctl performance

#7 2014-01-28 09:16:31

Re: Slow netctl performance

#8 2014-01-28 15:16:03

Re: Slow netctl performance

#9 2014-01-28 15:26:36

Re: Slow netctl performance

#10 2014-01-28 16:01:04

Re: Slow netctl performance

#11 2014-01-29 11:48:04

Re: Slow netctl performance

#12 2014-02-01 09:40:53

Re: Slow netctl performance

#13 2014-02-01 17:44:36

Re: Slow netctl performance

#14 2014-02-01 18:04:48

Re: Slow netctl performance

#15 2014-02-01 19:03:00

Re: Slow netctl performance

#16 2014-02-01 19:19:09

Re: Slow netctl performance

#17 2014-02-01 19:35:16

Re: Slow netctl performance

#18 2014-02-01 20:08:23

Re: Slow netctl performance

#19 2014-02-01 20:16:20

Re: Slow netctl performance

Board footer