Page 1 of 2 12 LastLast
Results 1 to 10 of 15

Thread: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

  1. #1
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    I've occasionally checked `systemd-analyze blame` and then done some tuning to improve boot times (removing ModemManager and things like that). After the most recent update to 4.15.13 (booting off microSD rather than USB), I get this:
    Code:
             30.265s wicked.service
              8.248s lvm2-monitor.service
              8.213s apparmor.service
              7.676s dev-mmcblk1p2.device
              6.277s ca-certificates.service
              6.111s systemd-hwdb-update.service
              2.564s initrd-switch-root.service
              1.659s smb.service
              1.468s wpa_supplicant.service
              1.454s systemd-journal-flush.service
              1.312s nmb.service
              1.154s sshd.service
    I hadn't seen such delays from wicked before (as best I can remember ... I think I would have noticed a 30-sec delay).

    Is anyone else seeing this kind of delay in wicked startup in an aarch64 TW RPi-3B environment? I've disabled IPv6 to try to speed it up -- even removed the wickedd-dhcp6.service requests from wickedd.service -- to no avail.

    I'm not sure what else to look at or for. Any suggestions? Any other outliers in that `blame` listing that I might pay attention to?

  2. #2
    Join Date
    Jun 2008
    Location
    Podunk
    Posts
    32,336
    Blog Entries
    15

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Hi
    Edit the /etc/sysconfig/networ/config file and set the WAIT_FOR_INTERFACE timeout to 0 also I set /etc/postfic/main.cf inet_protocols = ipv4
    Cheers Malcolm °¿° SUSE Knowledge Partner (Linux Counter #276890)
    SUSE SLE, openSUSE Leap/Tumbleweed (x86_64) | GNOME DE
    If you find this post helpful and are logged into the web interface,
    please show your appreciation and click on the star below... Thanks!

  3. #3
    Join Date
    Feb 2010
    Location
    Germany
    Posts
    4,576

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Wicked tuning:
    1st: Check the systemd journal of the current boot for the time taken by the various network components:
    # journalctl --this-boot | grep -Ei 'r8169|eth0|wicked|network|DHCP|ntp|nmb|smb'
    Where 'r8169' is my physical Ethernet controller pointed to by "eth0".

    2nd: Tweak this "/etc/sysconfig/network/config" setting for the time taken from "systemd[1]: Reached target Host and Network Name Lookups" to "kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready" -- I normally add 3 or 4 seconds extra to that time to allow the initial DHCP requests to complete. Note that, the final IPv6 DHCP request usually completes a second or two after everything else has completed:
    Code:
    ## Type:        integer
    ## Default:     30
    #
    # Some interfaces need some time to come up or come asynchronously via hotplug.
    # WAIT_FOR_INTERFACES is a global wait for all mandatory interfaces in
    # seconds. If empty no wait occurs.
    #
    # WAIT_FOR_INTERFACES="30"
    # WAIT_FOR_INTERFACES="12"
    WAIT_FOR_INTERFACES="6"
    And, also, this one if you have an "IPv6 forced by your ISP case":
    Code:
    ## Type:        string
    ## Default:     ""
    #
    # Allows to specify options to use when writting the /etc/resolv.conf,
    # for example:
    #       "debug attempts:1 timeout:10"
    # See resolv.conf(5) manual page for details.
    #
    NETCONFIG_DNS_RESOLVER_OPTIONS="inet6 edns0 single-request single-request-reopen"
    Some DSL Routers, when configured to be your DHCP server, need this in "/etc/sysconfig/network/dhcp":
    Code:
    ## Type:        yesno
    ## Default:     no
    #
    # Send a DHCPRELEASE to the server (sign off the address)? (yes|no)
    # This may lead to getting a different address/hostname next time an address
    # is requested. But some servers require it.
    #
    # DHCLIENT_RELEASE_BEFORE_QUIT="no"
    DHCLIENT_RELEASE_BEFORE_QUIT="yes"
    With these settings, my (AMD) Leap 42.3 boots are looking like this:
    Code:
     > systemd-analyze
    Startup finished in 2.305s (kernel) + 1.964s (initrd) + 17.157s (userspace) = 21.427s
     > systemd-analyze blame | head
              6.027s wicked.service
              5.330s nmb.service
              3.882s apparmor.service
              3.471s systemd-journal-flush.service
              1.593s home01.mount
              1.140s mysql.service
               735ms display-manager.service
               729ms plymouth-start.service
               668ms SuSEfirewall2.service
               603ms SuSEfirewall2_init.service
     >
    Ooops!! I've just now noticed that, the slow nmb server initialisation issue has returned … Normally the userspace time is about 5 seconds faster …

  4. #4
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Quote Originally Posted by malcolmlewis View Post
    Hi
    Edit the /etc/sysconfig/networ/config file and set the WAIT_FOR_INTERFACE timeout to 0 also I set /etc/postfic/main.cf inet_protocols = ipv4
    Thanks, Malcolm. Both looked like they'd be important parameters to change, but they made no difference:
    Code:
             30.478s wicked.service
              9.171s lvm2-monitor.service
              8.879s apparmor.service
              8.705s dev-mmcblk0p2.device
              7.032s systemd-hwdb-update.service
              6.279s ca-certificates.service
              4.189s systemd-journal-flush.service
              2.506s initrd-switch-root.service
              1.773s smb.service
              1.294s sshd.service
              1.262s nmb.service
    Off to try dcurtisfra's suggestions for analysis and tuning. Post again after that.

  5. #5
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    For those thinking about this problem ... please hold off! :-)

    dcurtisfra's suggestions below guided me in the right direction, I think, and I'm now analyzing the logs.

    Quote Originally Posted by dcurtisfra View Post
    Wicked tuning:
    1st: Check the systemd journal of the current boot for the time taken by the various network components:
    # journalctl --this-boot | grep -Ei 'r8169|eth0|wicked|network|DHCP|ntp|nmb|smb'
    Where 'r8169' is my physical Ethernet controller pointed to by "eth0".

    2nd: Tweak this "/etc/sysconfig/network/config" setting for the time taken from "systemd[1]: Reached target Host and Network Name Lookups" to "kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready" -- I normally add 3 or 4 seconds extra to that time to allow the initial DHCP requests to complete. Note that, the final IPv6 DHCP request usually completes a second or two after everything else has completed:
    ...

    So I started here, and in looking at the first logs, I realized that the one change I made (that I can think of) prior to my last two `zypper dup`'s was to disconnect my eth0 cable ... I'm now running strictly off wlan0, unlike when I was tuning earlier with ethernet connected.

    So I plugged the ethernet cable back in and rebooted, and wicked's launch time is now about 7 seconds.

    It's clear that something in the startup process is causing wicked (or something it depends upon) to wait for a long period (maybe 30 sec?).

    I'm doing a log comparison now, but I don't want to waste anyone else's time trying to figure this out ... with the analysis suggestions of dcurtisfra, I think I can get it.

    I'll post the results if I get it worked out.

    Thanks, all!!

  6. #6
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Quote Originally Posted by hdtodd View Post
    I'm doing a log comparison now, but I don't want to waste anyone else's time trying to figure this out ... with the analysis suggestions of dcurtisfra, I think I can get it.

    I'll post the results if I get it worked out.
    I looked in the places dcurtisfra suggested. Following Malcolm's suggestion, I had already changed the WAIT to "0" with no effect. I've disabled IPv6 so I don't think those parameters apply. So I don't see anything else to do there.

    Comparing the journalctl logs without and then with eth0 connected, I found the following differences in the logs:
    Code:
    Pi-6:/home/hdtodd # journalctl --this-boot | grep -Ei 'smsc95xx|wlan0|eth0|wicked|network|DHCP|ntp|nmb|smb'
    
    Mar 28 08:28:08 Pi-6 wickedd[721]: ni_process_reap: process 782 has not exited yet; now doing a blocking waitpid()
    Mar 28 08:28:08 Pi-6 wickedd[721]: ni_process_reap: process 784 has not exited yet; now doing a blocking waitpid()
    
    Mar 28 08:28:10 Pi-6 kernel: smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
    Mar 28 08:28:10 Pi-6 wickedd-dhcp4[687]: eth0: Request to acquire DHCPv4 lease with UUID 588abb5a-c556-0700-d102-000006000000
    Mar 28 08:28:11 Pi-6 wickedd-dhcp4[687]: eth0: Committed DHCPv4 lease with address 192.168.1.76 (lease time 86400 sec, renew in 43200 sec, rebind in 75600 sec)
    Mar 28 08:28:11 Pi-6 avahi-daemon[694]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.76.
    Mar 28 08:28:11 Pi-6 avahi-daemon[694]: New relevant interface eth0.IPv4 for mDNS.
    Mar 28 08:28:11 Pi-6 avahi-daemon[694]: Registering new address record for 192.168.1.76 on eth0.IPv4.
    Mar 28 08:28:15 Pi-6 wicked[764]: eth0            up
    
    WITHOUT eth0 plugged in
    Pi-6:/home/hdtodd # journalctl --this-boot | grep -Ei 'smsc95xx|wlan0|eth0|wicked|network|DHCP|ntp|nmb|smb'
    
    Apr 06 15:23:12 Pi-6 wicked[761]: eth0            setup-in-progress
    That is, aside from the exact sequence of some of the process completions, the only differences are in eth0 coming up vs being "setup-in-process" when there is no ethernet connection. But with the WAIT parameter set to "0" in both cases, I would have thought that eth0 setup-in-progress status would be irrelevant. [The Raspberry doesn't have a battery-backed-up clock, so the logs start Mar 28, when the kernel was compiled, and jump to current date/time as soon as an IP connection is established to a time server. Curious to note that that seems to happen sooner with no EN cable connection, but I can't think of an explanation.]

    Comparing overall boot times without and with ethernet cabled, the timings look like this:
    Code:
    Apr 06 15:23:15 Pi-6 systemd[1]: Startup finished in 7.001s (kernel) + 4.220s (initrd) + 47.492s (userspace) = 58.714s.
    Apr 06 15:23:19 Pi-6 systemd[1080]: Startup finished in 161ms.
    Apr 06 15:34:15 Pi-6 systemd[1]: Startup finished in 7.001s (kernel) + 4.194s (initrd) + 25.140s (userspace) = 36.336s.
    Apr 06 15:34:22 Pi-6 systemd[1249]: Startup finished in 159ms.
    So there's about 22 sec lost in userspace activity because the ethernet cable isn't plugged in. And looking back several weeks in the journalctl log, every boot has been slowed by about that amount ever since I removed the EN connection.

    I'll continue to ponder this to see if I can figure out what's causing the delay. If anyone has suggestions of where to look next, I'd welcome new ideas.

  7. #7
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Got it!

    Taking clues from both MalcolmLewis and dcurtisfra, I edited /etc/sysconfig/network/config to set
    Code:
    WAIT_FOR_INTERFACES="7"
    rather than "0".

    Disconnected the Ethernet cable and rebooted, and got
    Code:
    Pi-6:/home/hdtodd # systemd-analyze blame
             16.343s apparmor.service
             15.748s lvm2-monitor.service
             15.488s dev-mmcblk0p2.device
             13.667s systemd-hwdb-update.service
              8.704s systemd-journal-flush.service
              8.008s systemd-tmpfiles-setup-dev.service
              7.317s wicked.service
              5.133s ca-certificates.service
              2.498s initrd-switch-root.service
              1.676s smb.service
              1.376s nmb.service
              1.328s sshd.service
    So wicked is down to the same 7 sec whether or not the Ethernet cable is connected.

    But I see that the top delayers are now taking about twice as long as they did before! Sigh.

    Hope this helps others.

  8. #8
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Quote Originally Posted by hdtodd View Post
    But I see that the top delayers are now taking about twice as long as they did before! Sigh.
    Never mind. Did another `journalctl --vacuum-size=100M`
    and rebooted to get
    Code:
    Pi-6:/home/hdtodd # systemd-analyze blame
              7.337s wicked.service
              5.992s lvm2-monitor.service
              5.884s ca-certificates.service
              5.824s apparmor.service
              5.593s dev-mmcblk0p2.device
              4.000s systemd-hwdb-update.service
              2.524s initrd-switch-root.service
              1.662s smb.service
              1.423s nmb.service
              1.267s sshd.service
              1.175s systemd-journal-flush.service
    with no Ethernet connection.

    Fixed! Thanks Malcolm and dcurtisfra for your suggestions!

  9. #9
    Join Date
    Feb 2017
    Location
    Montana, USA & Vermont, USA
    Posts
    134

    Default Resolution: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    This started when I found that the boot time for Tumbleweed had gotten to be unreasonably long. I thought the cause would be a parameter in a config file. It turned out that the primary contributor was that I had moved from an Ethernet+wan0-connected configuration to a wan0-only configuration (that is, I had disconnected the Ethernet cable). Booting without the Ethernet connection cost approximately 25 seconds in boot time.

    But I intended to leave this Pi as a wifi-only system (no Ethernet cable to it). And it seemed that there should be a parameter that would restore the faster boot time by telling wicked not to wait so long for network connections.

    Following the suggestions of MalcolmLewis and dcurtisfra, I found that the long startup times were dependent upon the WAIT_FOR_INTERFACES parameter in /etc/sysconfig/network/config. Its default value is "30"; I'd seen before the suggestion to set it to "0" to speed up boot times, but I found that value didn't help.

    So I tried a variety of values for WAIT_FOR_INTERFACES and recorded the wicked startup times and the the systemd[1] startup times. Here are the results.

    TW 4.15.13 aarch64 Raspberry Pi-3B Boot Times
    Boot from microSD with Ethernet unplugged;
    wlan0 activated; IPv6 disabled; using wicked
    Dependence upon the setting for
    WAIT_FOR_INTERFACES in /etc/sysconfig/network/config
    journalctl --vacuum-size=100M between reboots
    systemd-analyze journalctl
    WAIT setting
    wicked startup
    systemd[1] startup finished
    "" 30.3 55.5
    "0" 30.3 57
    "1" 1.4 30.7
    "5" 5.2 32.9
    "7" 7.3 32.4
    "10" 10.3 35.6
    "30" 30.2 54.7

    It appears that the smallest non-zero setting is optimal for getting the fastest boot time in this particular environment (YMMV). Again, this is a very constrained environment: Tumbleweed 4.15.13 aarch64 on a Raspberry Pi-3B, booting off the microSD (not USB), and using the internal wlan0 and (disconnected) eth0.

    Based upon these tests, I plan to leave WAIT_FOR_INTERFACES="1" in my /etc/sysconfig/network/config file to optimize boot times. Cautions and forewarnings welcome.

    Perhaps this information may help if you're seeing long boot time on your openSUSE system.

  10. #10
    Join Date
    Jan 2014
    Location
    Erlangen
    Posts
    3,291

    Default Re: Long wicked startup times when booting TW 4.15.13 aarch64 on Raspberry Pi-3B

    Changed WAIT_FOR_INTERFACES in /etc/sysconfig/network/config from 30
    Code:
    erlangen:~ # systemd-analyze
    Startup finished in 1.874s (kernel) + 840ms (initrd) + 18.165s (userspace) = 20.880s
    graphical.target reached after 18.161s in userspace
    erlangen:~ # systemd-analyze critical-chain |grep +
    The time the unit takes to start is printed after the "+" character.
    └─display-manager.service @16.638s +1.522s
      └─apache2.service @16.514s +114ms
          └─ntpd.service @16.465s +43ms
              └─wicked.service @1.140s +15.320s
                └─wickedd-nanny.service @1.131s +8ms
                  └─wickedd.service @1.122s +7ms
                    └─wickedd-auto4.service @1.091s +29ms
                                └─systemd-update-utmp.service @1.021s +3ms
                                  └─auditd.service @1.004s +16ms
                                    └─systemd-tmpfiles-setup.service @983ms +19ms
                                        └─home\x2dHDD.mount @742ms +237ms
                                            └─lvm2-monitor.service @176ms +561ms
    erlangen:~ #
    to 1

    Code:
    erlangen:~ # systemd-analyze
    Startup finished in 1.880s (kernel) + 872ms (initrd) + 7.505s (userspace) = 10.258s
    graphical.target reached after 7.494s in userspace
    erlangen:~ # systemd-analyze critical-chain |grep +
    The time the unit takes to start is printed after the "+" character.
      └─minidlna.service @2.286s +5.207s
          └─iscsi.service @2.254s +27ms
              └─wicked.service @1.209s +1.039s
                └─wickedd-nanny.service @1.200s +8ms
                  └─wickedd.service @1.184s +14ms
                    └─wickedd-dhcp4.service @1.145s +37ms
                                └─sys-fs-fuse-connections.mount @5.073s +39ms
                                  └─systemd-modules-load.service @178ms +93ms
    erlangen:~ #
    Any idea how to reduce wait for minidlna? Users don't need it for graphical login.
    AMD Athlon 4850e (2009), openSUSE 13.1, KDE 4, Intel i3-4130 (2014), i7-6700K (2016), i5-8250U (2018), AMD Ryzen 5 3400G (2020), openSUSE Tumbleweed, KDE Plasma 5

Page 1 of 2 12 LastLast

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •