Bug 781646 - systemd is painfully slow -- waiting for network?
systemd is painfully slow -- waiting for network?
Status: VERIFIED DUPLICATE of bug 780644
Classification: openSUSE
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: Basesystem
13.1 Milestone 0
Other Other
: P5 - None : Normal (vote)
: ---
Assigned To: Frederic Crozat
E-mail List
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-09-22 07:29 UTC by Jiri Slaby
Modified: 2014-08-31 18:13 UTC (History)
1 user (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments
systemd-analyze plot (217.11 KB, image/svg+xml)
2012-09-22 07:29 UTC, Jiri Slaby
Details
packed /dev/.sysconfig/network (519.06 KB, application/x-compressed-tar)
2012-09-26 19:22 UTC, Jiri Slaby
Details
excerpt from /var/log/messages (18.74 KB, text/plain)
2012-09-26 19:24 UTC, Jiri Slaby
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jiri Slaby 2012-09-22 07:29:01 UTC
Created attachment 506659 [details]
systemd-analyze plot

When booting, systemd always waits for something like 30 s. It looks like it waits for network interface to become up. But network.service is not shown in the output of systemd-analyze? How can I debug this?
Comment 1 Jiri Slaby 2012-09-22 07:31:37 UTC
Here network.service is shown:
# systemd-analyze blame|head
  5160ms md.service
  4342ms network.service
  1899ms systemd-vconsole-setup.service
  1228ms home.mount
   677ms syslog.service
   619ms network-remotefs.service
   596ms systemd-logind.service
   539ms apache2.service
   508ms localnet.service
   416ms mpd.service


So what takes those 30s if network takes only 4s?
Comment 2 Jiri Slaby 2012-09-22 07:35:21 UTC
Ok, just in case. I don't use NM, it's a plain ifup+dhcp, one interface.

systemd-44-19.1.x86_64
Comment 3 Frederic Crozat 2012-09-24 08:39:15 UTC
systemd-analyze plot > boot.svg is usually more useful to debug those issues.
Comment 4 Jiri Slaby 2012-09-24 08:40:45 UTC
(In reply to comment #3)
> systemd-analyze plot > boot.svg is usually more useful to debug those issues.

This is what is attachment 506659 [details], isn't it?
Comment 5 Frederic Crozat 2012-09-24 08:50:47 UTC
(In reply to comment #4)
> (In reply to comment #3)
> > systemd-analyze plot > boot.svg is usually more useful to debug those issues.
> 
> This is what is attachment 506659 [details], isn't it?

oops, I missed it :)

strange that you don't see network.service at all

what is the output of systemctl status network.service ?
Comment 6 Marius Tomaschewski 2012-09-24 09:30:57 UTC
Just in case you run into this issue:

Are you using BOOTPROTO=dhcp in the ifcfg file or BOOTPROTO=dhcp4?
A setting of dhcp means dhcp4+dhcp6 and waits up to 15sec for IPv6
address... change to dhcp4 when there is no dhcp6 server in your
network.
The yast2 network default on 12.2 seems to be dhcp4 for the first
interface and dhcp when you have more than one. See also bnc#779928.

The difference to previous versions is, that before the dhcp6 client
were not always installed by the install-pattern/package selection...
Comment 7 Jiri Slaby 2012-09-24 09:45:51 UTC
(In reply to comment #5)
> what is the output of systemctl status network.service ?

network.service - LSB: Configure the localfs depending network interfaces
          Loaded: loaded (/etc/init.d/network)
          Active: active (running) since Mon, 24 Sep 2012 11:44:09 +0200; 11s ago
         Process: 15973 ExecStop=/etc/init.d/network stop (code=exited, status=0/SUCCESS)
         Process: 16837 ExecStart=/etc/init.d/network start (code=exited, status=0/SUCCESS)
          CGroup: name=systemd:/system/network.service
                  └ 18119 /sbin/dhcpcd --netconfig -L -E -c /etc/sysconfig/n...

+ tail from messages

(In reply to comment #6)
> Are you using BOOTPROTO=dhcp in the ifcfg file or BOOTPROTO=dhcp4?

grep BOOTPROTO /etc/sysconfig/network/ifcfg-eth100
BOOTPROTO='dhcp4'
Comment 8 Jiri Slaby 2012-09-24 21:29:51 UTC
Hmm wait. It is failed after fresh boot:
network.service - LSB: Configure the localfs depending network interfaces
          Loaded: loaded (/etc/init.d/network)
          Active: failed (Result: exit-code) since Mon, 24 Sep 2012 21:53:47 +0200; 1h 33min ago
          CGroup: name=systemd:/system/network.service
                  └ 5260 /sbin/dhcpcd --netconfig -L -E -c /etc/sysconfig/network/scripts/dhcpcd-hook -t 0 -h bellona eth100



But why? dhcp is running, networking is fine. So?
Comment 9 Marius Tomaschewski 2012-09-25 13:00:52 UTC
Could you try out the following patch / change?:

--- /sbin/ifup-dhcp
+++ /sbin/ifup-dhcp	2012-09-25 14:47:58.050145466 +0200
@@ -694,7 +694,7 @@
 				   ${LLADDR:+address $LLADDR} $LINK_OPTIONS
 
 				# wait a bit or dhclient(6) may produce false send errors
-				link_ready_wait "$INTERFACE" 3
+				link_ready_wait "$INTERFACE" $((${DHCLIENT_WAIT_AT_BOOT:-15}/2))
 
 				# (optionally) wait until a device is really configured
 				sleep ${DHCLIENT_SLEEP:-0}

and / or setting a DHCLIENT_SLEEP=3 or something like this.

Reason: when the dhcp client is started too early (link is not really
ready yet), the first packets may never reach the server and the
timeout between the resend gets increased / doubled. Finally, it may
need more time:

Sep 25 12:39:21 trinity kernel: [ 3205.004153] ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep 25 12:39:25 trinity kernel: [ 3208.418415] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Sep 25 12:39:25 trinity kernel: [ 3208.419175] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 25 12:39:25 trinity ifup-dhcp:     eth0      Starting DHCP4 client
Sep 25 12:39:25 trinity dhcpcd[8905]: eth0: dhcpcd 3.2.3 starting
Sep 25 12:39:25 trinity dhcpcd[8905]: eth0: hardware address = 90:b1:1c:5e:16:cf
Sep 25 12:39:25 trinity dhcpcd[8905]: eth0: broadcasting for a lease
Sep 25 12:39:25 trinity ifup-dhcp: . 
Sep 25 12:39:27 trinity ifup-dhcp: . 
Sep 25 12:39:30 trinity ifup-dhcp: . 
Sep 25 12:39:32 trinity ifup-dhcp: . 
Sep 25 12:39:34 trinity dhcpcd[8905]: eth0: offered 172.16.20.4 from 172.16.0.245 `exodus'
Comment 10 Marius Tomaschewski 2012-09-25 14:03:00 UTC
Another test you may try:

stop using the network "rcnetwork stop" (will redirect to the systemd).

Then stop again with -o boot (systemd not involved here) and remove
the modules:

   /etc/init.d/network stop -o boot ; rmmod e1000e

then load & start again + check the time:
   modprobe e1000e ; time /etc/init.d/network stop -o boot

This should be very similar to the time it needs at boot.
Comment 11 Marius Tomaschewski 2012-09-25 15:50:46 UTC
(In reply to comment #10)
> then load & start again + check the time:
>    modprobe e1000e ; time /etc/init.d/network stop -o boot
                                                ^^^^
                                                start
Comment 12 Jiri Slaby 2012-09-25 18:01:58 UTC
(In reply to comment #10)
> then load & start again + check the time:
>    modprobe e1000e ; time /etc/init.d/network start -o boot

real    0m5.808s
user    0m0.220s
sys     0m0.240s

But at boot, I see waiting for mandatory devices: eth100. . . . .
And it looks like it must time out to proceed...
Comment 13 Marius Tomaschewski 2012-09-26 14:12:36 UTC
Hmm...
I've installed 12.2 on my brand new machine that arrived yesterday and it
needs up to 15 sec to get dhcp4 + dhcp6 IPs on its Intel NIC -- this is
longer than my old machine...:

Sep 26 15:01:27 trinity network[4685]: Setting up (localfs) network interfaces:
...
Sep 26 15:01:27 trinity ifup[5050]:     eth0      device: Intel Corporation 82579LM Gigabit Network Con
Sep 26 15:01:28 trinity kernel: [  499.013491] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 15:01:28 trinity kernel: [  499.114196] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 15:01:28 trinity kernel: [  499.114993] ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep 26 15:01:31 trinity kernel: [  502.585932] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Sep 26 15:01:31 trinity kernel: [  502.586680] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 26 15:01:31 trinity ifup-dhcp[5100]:     eth0      Starting DHCP4+DHCP6 client
...
Sep 26 15:01:31 trinity dhcpcd[5949]: eth0: sending DHCP_DISCOVER with xid 0x36f274b6
Sep 26 15:01:31 trinity dhcpcd[5949]: eth0: waiting for 20 seconds
Sep 26 15:01:31 trinity dhclient[5965]: Internet Systems Consortium DHCP Client 4.2.4-P2
Sep 26 15:01:32 trinity dhclient[5965]: Bound to *:546
Sep 26 15:01:32 trinity dhclient[5965]: Listening on Socket/eth0
Sep 26 15:01:32 trinity dhclient[5965]: Sending on   Socket/eth0
Sep 26 15:01:33 trinity dhclient[5965]: XMT: Confirm on eth0, interval 980ms.
Sep 26 15:01:33 trinity dhclient[5965]: send_packet6: Cannot assign requested address
Sep 26 15:01:33 trinity dhclient[5965]: dhc6: sendpacket6() sent -1 of 82 bytes
<==== 1st send failed because it were sent before the interface
      has a link-local address (fe80:*).
Sep 26 15:01:33 trinity dhclient[5965]: XMT: Confirm on eth0, interval 1890ms.
Sep 26 15:01:34 trinity ifup-dhcp[5100]: .
Sep 26 15:01:34 trinity dhcpcd[5949]: eth0: sending DHCP_DISCOVER with xid 0x36f274b6
<==== 1st send never arrived (also too early?), now resend after ~3 sec.
Sep 26 15:01:35 trinity dhclient[5965]: XMT: Confirm on eth0, interval 3850ms.
Sep 26 15:01:35 trinity dhclient[5965]: RCV: Reply message on eth0 from fe80::21b:21ff:febf:79f0.
Sep 26 15:01:35 trinity dhclient[5965]: message status code Success: "All addresses still on link."
<==== OK, IPv6 address confirmed, so basically DHCPv6 is done here
<==== and dhclient-script calls "ifup -o dhcp":
Sep 26 15:01:36 trinity ifup[6440]:     eth0      device: Intel Corporation 82579LM Gigabit Network Connection (rev 04)
<==== OK, DHCPv6 completed here... it needed 5 secs to confirm. 1sec more
      than optimal because it started too early.
Sep 26 15:01:36 trinity ifup-dhcp[5100]: .
Sep 26 15:01:39 trinity ifup-dhcp[5100]: .
Sep 26 15:01:40 trinity dhcpcd[5949]: eth0: sending DHCP_DISCOVER with xid 0x36f274b6
<==== Again?!
Sep 26 15:01:40 trinity dhcpcd[5949]: eth0: got a packet with xid 0x36f274b6
Sep 26 15:01:40 trinity dhcpcd[5949]: eth0: offered 172.16.20.4 from 172.16.0.245 `exodus'
Sep 26 15:01:40 trinity dhcpcd[5949]: eth0: sending DHCP_REQUEST with xid 0x36f274b6
Sep 26 15:01:40 trinity dhcpcd[5949]: eth0: waiting for 11 seconds
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: got a packet with xid 0x36f274b6
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: checking 172.16.20.4 is available on attached networks
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: sending ARP probe #1
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: sending ARP probe #2
Sep 26 15:01:41 trinity ifup-dhcp[5100]: .
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: sending ARP probe #3
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: sending ARP claim #1
Sep 26 15:01:41 trinity dhcpcd[5949]: eth0: sending ARP claim #2
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: leased 172.16.20.4 for 3600 seconds
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: renew in 1800 seconds
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: rebind in 3150 seconds
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: adding IP address 172.16.20.4/24
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: adding default route via 172.16.20.254 metric 0
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: no dns information to write
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: writing /var/lib/dhcpcd/dhcpcd-eth0.info
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: exec "/etc/sysconfig/network/scripts/dhcpcd-hook" "/var/lib/dhcpcd/dhcpcd-eth0.info" "new"
Sep 26 15:01:42 trinity dhcpcd-hook: State: new. Leaseinfo: /var/lib/dhcpcd/dhcpcd-eth0.info
Sep 26 15:01:42 trinity dhcpcd-hook: new IP address: 172.16.20.4
Sep 26 15:01:42 trinity dhcpcd-hook: debug: no /var/run/ntp directory - skipping
Sep 26 15:01:42 trinity dhcpcd-hook: Running ifdown eth0 -o dhcp
Sep 26 15:01:42 trinity ifdown[7074]:     eth0      device: Intel Corporation 82579LM Gigabit Network Connection (rev 04)
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: exec "/etc/sysconfig/network/scripts/dhcpcd-hook" "/var/lib/dhcpcd/dhcpcd-eth0.info" "complete"
Sep 26 15:01:42 trinity dhcpcd-hook: State: complete. Leaseinfo: /var/lib/dhcpcd/dhcpcd-eth0.info
Sep 26 15:01:42 trinity dhcpcd-hook: Running ifup eth0 -o dhcp
Sep 26 15:01:42 trinity ifup[7179]:     eth0      device: Intel Corporation 82579LM Gigabit Network Connection (rev 04)
Sep 26 15:01:42 trinity dhcpcd-hook: DHCP4 configuration of eth0 is complete
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: forking to background
Sep 26 15:01:42 trinity dhcpcd[5949]: eth0: exiting
Sep 26 15:01:42 trinity dhcpcd[7307]: eth0: waiting for 1800 seconds
Sep 26 15:01:42 trinity network[4685]: eth0      Starting DHCP4+DHCP6 client. . . . .
Sep 26 15:01:42 trinity ifup-dhcp[5100]: 
Sep 26 15:01:42 trinity network[4685]: eth0      IP address: 172.16.20.4/24 (trinity)
Sep 26 15:01:42 trinity ifup-dhcp[5100]:     eth0      IP address: 172.16.20.4/24 (trinity)
Sep 26 15:01:42 trinity network[4685]: eth0      IP address: 2001:470:5036:2000::4/64
Sep 26 15:01:42 trinity ifup-dhcp[5100]:     eth0      IP address: 2001:470:5036:2000::4/64
Sep 26 15:01:42 trinity network[4685]: ..done    eth1      device: Realtek Semiconductor Co., Ltd. RTL8111/8168B
Sep 26 15:01:42 trinity ifup[7357]:     eth1      device: Realtek Semiconductor Co., Ltd. RTL8111/8168B
Sep 26 15:01:42 trinity network[4685]: No configuration found for eth1
Sep 26 15:01:42 trinity ifup[7357]:               No configuration found for eth1
Sep 26 15:01:42 trinity network[4685]: ..unusedSetting up service (localfs) network  .  .  .  .  .  .  .  .  .  ...done

but it is not DHCPv6 that needs longer in this case but DHCPv4... why?!
I think I've to take a look at my dhcpv4 server, ...

I've set DHCLIENT_SLEEP=3 and then I have ~ 4 sec until link becomes
ready + 3 sleep, then 2 discovers and dhcp4 is ready after 4 sec; total
rcnetwork boot time of 12 sec:

Sep 26 15:26:31 trinity network[540]: Setting up (localfs) network interfaces:
Sep 26 15:26:31 trinity ifup[926]:     eth0      device: Intel Corporation 82579LM Gigabit Network Con
Sep 26 15:26:32 trinity kernel: [   12.726890] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 15:26:32 trinity kernel: [   12.827797] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 15:26:32 trinity kernel: [   12.828596] ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep 26 15:26:36 trinity kernel: [   16.191785] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Sep 26 15:26:36 trinity kernel: [   16.192285] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 26 15:26:38 trinity ifup-dhcp[976]:     eth0      Starting DHCP4+DHCP6 client
Sep 26 15:26:38 trinity dhcpcd[1804]: eth0: dhcpcd 3.2.3 starting
Sep 26 15:26:38 trinity dhcpcd[1804]: eth0: sending DHCP_DISCOVER with xid 0x2542804d
Sep 26 15:26:38 trinity dhclient[1822]: Internet Systems Consortium DHCP Client 4.2.4-P2
Sep 26 15:26:40 trinity dhclient[1822]: RCV: Reply message on eth0 from fe80::21b:21ff:febf:79f0.
Sep 26 15:26:40 trinity dhclient[1822]: message status code Success: "All addresses still on link."
Sep 26 15:26:40 trinity ifup[2159]:     eth0      device: Intel Corporation 82579LM Gigabit Network Connection (rev 04)
Sep 26 15:26:40 trinity ifup-dhcp[976]: .
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: sending DHCP_DISCOVER with xid 0x2542804d
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: got a packet with xid 0x2542804d
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: offered 172.16.20.4 from 172.16.0.245 `exodus'
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: sending DHCP_REQUEST with xid 0x2542804d
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: waiting for 17 seconds
Sep 26 15:26:41 trinity dhcpcd[1804]: eth0: got a packet with xid 0x2542804d
Sep 26 15:26:42 trinity dhcpcd-hook: DHCP4 configuration of eth0 is complete
Sep 26 15:26:43 trinity network[540]: ..Setting up service (localfs) network  .  .  .  .  .  .  .  .  .  ...done

next boot sent only 1 discover and dhcp4+6 needed only ~3 sec (+4 link and
+3 sleep), but total at 15 again -- some post-hook wasted time (samba hook
problems or a similar issue kicks us back?)?

Sep 26 15:35:11 trinity network[498]: Setting up (localfs) network interfaces:
Sep 26 15:35:12 trinity kernel: [    9.966713] ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep 26 15:35:15 trinity kernel: [   12.704165] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 26 15:35:18 trinity dhcpcd[1634]: eth0: dhcpcd 3.2.3 starting
Sep 26 15:35:18 trinity kernel: [   15.716686] NET: Registered protocol family 17
Sep 26 15:35:18 trinity dhclient[1652]: Internet Systems Consortium DHCP Client 4.2.4-P2
Sep 26 15:35:19 trinity dhcpcd-hook: DHCP4 configuration of eth0 is complete
Sep 26 15:35:23 trinity ifup-dhcp[946]: .
Sep 26 15:35:35  ifup-dhcp[946]: last message repeated 5 times
Sep 26 15:35:35 trinity network[498]: ..unusedSetting up service (localfs) network  .  .  .  .  .  .  .  .  .  ...done

But it looks to me, that the time between "ip link set up", link ready and
link really usable is much longer than before & packets go to /dev/null.
Comment 14 Marius Tomaschewski 2012-09-26 14:27:23 UTC
I've added a "modprobe af_packet" before the link is set up or dhcp
clients are started and it is much better now:

Sep 26 16:05:37 trinity network[526]: Setting up (localfs) network interfaces:
Sep 26 16:05:38 trinity ifup[910]:     eth0      device: Intel Corporation 82579LM Gigabit Network Con
Sep 26 16:05:39 trinity kernel: [    5.413336] NET: Registered protocol family 17
Sep 26 16:05:39 trinity kernel: [    5.547356] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 16:05:39 trinity kernel: [    5.648244] e1000e 0000:00:19.0: irq 45 for MSI/MSI-X
Sep 26 16:05:39 trinity kernel: [    5.649048] ADDRCONF(NETDEV_UP): eth0: link is not ready
Sep 26 16:05:41 trinity kernel: [    8.401977] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx/Tx
Sep 26 16:05:42 trinity kernel: [    8.402730] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: dhcpcd 3.2.3 starting
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: sending DHCP_DISCOVER with xid 0x67773c8a
...
Sep 26 16:05:45 trinity dhclient[1665]: Internet Systems Consortium DHCP Client 4.2.4-P2
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: offered 172.16.20.4 from 172.16.0.245 `exodus'
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: sending DHCP_REQUEST with xid 0x67773c8a
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: got a packet with xid 0x67773c8a
Sep 26 16:05:45 trinity dhcpcd[1649]: eth0: sending ARP probe #1
...
Sep 26 16:05:46 trinity dhclient[1665]: Bound to *:546
Sep 26 16:05:46 trinity dhclient[1665]: XMT: Confirm on eth0, interval 980ms.
Sep 26 16:05:46 trinity dhclient[1665]: RCV: Reply message on eth0 from fe80::21b:21ff:febf:79f0.
Sep 26 16:05:46 trinity dhclient[1665]: message status code Success: "All addresses still on link."
Sep 26 16:05:46 trinity dhcpcd[1649]: eth0: leased 172.16.20.4 for 3600 seconds
Sep 26 16:05:46 trinity dhcpcd-hook: DHCP4 configuration of eth0 is complete

<<<=== basically done:
       link ready 5sec after start [NIC needs 4sec[, dhcp4 done in 2sec,
       dhcp6 in 1sec, total until now 9sec (with bash -x debug enabled).

Sep 26 16:05:47 trinity ifup-dhcp[960]: .
Sep 26 16:05:49 trinity ifup-dhcp[960]: .
Sep 26 16:05:51 trinity network[526]: ..unusedSetting up service (localfs) network  .  .  .  .  .  .  .  .  .  ...done

the post scripts need 5sec ... :-(

But I think we have a significant improvement already.

Sep 26 16:05:53 trinity systemd[1]: Startup finished in 2s 902ms 599us (kernel) + 17s 230ms 659us (userspace) = 20s 133ms 258us.

I'll prepare a test package that contains my changes.
Comment 15 Marius Tomaschewski 2012-09-26 14:31:56 UTC
Frederic,
I reassign to myself for now -- when we're done with network, it may come back :-)
Comment 16 Jiri Slaby 2012-09-26 14:44:52 UTC
(In reply to comment #14)
> I've added a "modprobe af_packet" before the link is set up or dhcp
> clients are started and it is much better now:

Just a note. This won't definitely help me, since I have no modules. Everything is built in here.
Comment 17 Marius Tomaschewski 2012-09-26 14:58:44 UTC
Ah... ok.

When you look at bnc#780644, Don has a "infinite" post-script time instead
of the 5 sec I've noticed [end of comment 15]. Looks like there something
would go really wrong under some conditions...

Please set DHCLIENT_DEBUG=yes, DHCLIENT6_DEBUG=yes in network/dhcp plus
DEBUG=EXTRA in /etc/sysconfig/network/config, reboot, then grab the
results: "tar cvzpf /tmp/network-exdbg.tgz /dev/.sysconfig/network"
and attach /tmp/network-exdbg.tgz, messages and /var/log/dhclient*.log.
Comment 18 Marius Tomaschewski 2012-09-26 15:00:13 UTC
(In reply to comment #17)
> of the 5 sec I've noticed [end of comment 15]. Looks like there something
                                            14
Comment 19 Marius Tomaschewski 2012-09-26 17:30:49 UTC
Could you try if this package helps (not yet published):

http://download.opensuse.org/repositories/home:/mtomaschewski:/branches:/openSUSE:/12.2:/Update/

it looks like the timeout is causes by ntp runtime add-server using
the init script try-restart and trying to synchrinize (at least in
my case), so I've added the code doing it directly to netconfig's
ntp-runtime module (<1sec now).

Except of this, please provide the requested debug output.
Comment 20 Jiri Slaby 2012-09-26 19:22:11 UTC
Created attachment 507249 [details]
packed /dev/.sysconfig/network
Comment 21 Jiri Slaby 2012-09-26 19:24:45 UTC
Created attachment 507250 [details]
excerpt from /var/log/messages
Comment 22 Jiri Slaby 2012-09-26 19:25:51 UTC
(In reply to comment #17)
> /var/log/dhclient*.log.

dhcpcd here.
Comment 23 Jiri Slaby 2012-09-26 19:35:24 UTC
(In reply to comment #19)
> Could you try if this package helps (not yet published):
> 
> http://download.opensuse.org/repositories/home:/mtomaschewski:/branches:/openSUSE:/12.2:/Update/

Updating sysconfig from here has no effect, unfortunately.
Comment 24 Marius Tomaschewski 2012-09-27 12:43:58 UTC
It is the "systemctl --ignore-dependencies force-reload nmb.service"
provided by samba-client (21-dhcpcd-hook-samba) again (bnc#732395);
See:
    grep "systemctl.*force-reload" exdeb.*.

You may try DHCLIENT_MODIFY_SMB_CONF=no in /etc/sysconfig/network/dhcp,
or move away the /etc/sysconfig/network/if-{up,down}.d/ hooks:

   21-dhcpcd-hook-samba, 55-samba-winbindd [, 21-smbfs]

or uninstall samba-client & co, when not needed.
Comment 25 Marius Tomaschewski 2012-09-27 12:54:59 UTC
Frederic, can you take a look at the hooks again?
Comment 26 Jiri Slaby 2012-09-27 14:53:20 UTC
(In reply to comment #24)
> It is the "systemctl --ignore-dependencies force-reload nmb.service"
> provided by samba-client (21-dhcpcd-hook-samba) again (bnc#732395);

Confirmed. Removing that line from the hook fixes the problem. Actually I hit the issue some time ago (bnc#731308), but already forgot...
Comment 27 Jiri Slaby 2012-09-27 17:35:25 UTC
Too lazy to track two bugs about the same.

*** This bug has been marked as a duplicate of bug 780644 ***