Bug 975933

Summary: Slow boot: 33s waiting for wicked interfaces to start - wicked Timer ni_timer_next_timeout
Product: [openSUSE] openSUSE Distribution Reporter: Donald Curtis <bugrprt21882>
Component: NetworkAssignee: wicked maintainers <wicked-maintainers>
Status: RESOLVED DUPLICATE QA Contact: E-mail List <qa-bugs>
Severity: Normal    
Priority: P5 - None CC: mt
Version: Leap 42.1   
Target Milestone: ---   
Hardware: x86-64   
OS: openSUSE 42.1   
Whiteboard:
Found By: --- Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: wicked systemd journals

Description Donald Curtis 2016-04-18 10:33:52 UTC
Created attachment 673315 [details]
wicked systemd journals

Resulting from the Leap 42.1 Install/Boot/Login Forum discussion:
The wicked.service is taking a significant amount of time to complete (also with 13.2):
(Leap 42.1 # systemd-analyze blame)
15.759s wicked.service
11ms wickedd-dhcp4.service
8ms wickedd-dhcp6.service
7ms wickedd-auto4.service
6ms wickedd.service
4ms wickedd-nanny.service
Attached:
Leap 42.1 systemd journal extracts from a Lenovo G505s Laptop first with the wlan0 disabled (only eth0) and then with wlan0 enabled.

/etc/sysconfig/network/config values:
Logs from Apr 18 09:40 and Apr 18 11:28 are with WICKED_DEBUG="" and WICKED_LOG_LEVEL="info"
Logs from Apr 18 10:38 and Apr 18 11:42 are with WICKED_DEBUG="timer" and WICKED_LOG_LEVEL="debug2"
Comment 1 Donald Curtis 2016-04-18 10:50:43 UTC
I mean this Leap 42.1 Install/Boot/Login Forum discussion:
<https://forums.opensuse.org/showthread.php/514501-Slow-boot-33s-waiting-for-wicked-interfaces-to-start>
Yes, yes, my systems are showing "only" a 16 second delay but, other folks are experiencing somewhat longer delays.
Comment 2 Donald Curtis 2016-04-19 08:45:46 UTC
Regarding Bug 972471: "Slow boot: 33s waiting for wicked interfaces to start"

What I'm missing in the issues being discussed in 972471 is the behaviour of the wicked (not wickedd) timer "ni_timer_next_timeout".

** In my case (this bug: 975933):
During boot, the wickedd DHCP4 and DHCP6 systemd services both complete within the range of 8 ms through 11 ms, and report that they've pulled the DHCP information from the (DSL) Router.

The wickedd DHCP4 daemon validates the DHCPv4 address and commits the DHCPv4 lease within a second or two.
The wickedd DHCP6 daemon however needs more than 5 minutes to validate the DHCPv6 lease (may be Router dependent ... ).
 ** N.B.: The DHCPv6 lease validation occurs after wicked has indicated "interfaces up".
 ** N.B.: With 13.2 the wickedd DHCP6 daemon needs about 8 minutes to validate the DHCPv6 lease with the same (DSL) Router as that used by my Leap 42.1 system.

The Timer 'ni_timer_next_timeout' seems to be the influencing factor with respect to the wicked daemon -- in my journal dated 2016-04-18:10:38 the wicked daemon with PID 884 was using the 'ni_timer_next_timeout' ID 0xc96410 which expired at Apr 18 10:39:30 and seemed to trigger the "lo" and "eth0" up indications.
(I've seen that "systemd[1]: Started wicked managed network interfaces" is missing from the published journal extracts.)
Comment 3 Donald Curtis 2016-08-17 14:16:34 UTC
Please see Bug 993516.
Checked the contents of /etc/sysconfig/network/ and made the following changes:
 - In "config" decreased WAIT_FOR_INTERFACES from '30' to '8'.
 - In "dhcp" made the following changes:
 * DHCLIENT_RELEASE_BEFORE_QUIT and DHCLIENT6_RELEASE_BEFORE_QUIT set to "yes".
 * DHCLIENT_WAIT_AT_BOOT and DHCLIENT6_WAIT_AT_BOOT decreased from '15' to '4'.

Additionally, commented out an extraneous DHCLIENT_SET_DEFAULT_ROUTE='yes' in ifcfg-enp2s0.
------------------------------------------------
 # systemd-analyze 
Startup finished in 2.005s (kernel) + 1.421s (initrd) + 10.867s (userspace) = 14.293s
 # systemd-analyze blame | head
          6.610s wicked.service
          2.172s apparmor.service
           682ms systemd-udev-settle.service
           505ms home.mount
           485ms vboxdrv.service
           457ms postfix.service
           454ms apache2.service
           360ms home01.mount
           321ms nfsserver.service
           268ms smb.service
 #
Comment 4 Marius Tomaschewski 2016-11-23 17:30:07 UTC
wicked.service is an "wicked ifup --timeout $DHCLIENT_WAIT_AT_BOOT all"
call that causes to send the config (ifcfg files) to wickedd-* and wait
specified time for results it receives back before it exits and reports.

I really don't understand what this bug is trying to report in contrast
to 993516. Yes, it is possible to tune things, but we cannot do this by
default, because it depends on too many things (NIC hw, ...).

*** This bug has been marked as a duplicate of bug 993516 ***
Comment 5 Marius Tomaschewski 2016-11-24 07:39:46 UTC
(In reply to Marius Tomaschewski from comment #4)
> wicked.service is an "wicked ifup --timeout $DHCLIENT_WAIT_AT_BOOT all" call
correct is:            "wicked ifup --timeout $WAIT_FOR_INTERFACES all"