On Tue, 2017-12-19 at 07:16 -0500, Sam Varshavchik wrote:
Gordon Messmer writes:
> On 12/18/2017 05:52 AM, Sam Varshavchik wrote:
> > Time IP addresses
> > ======== ==================
> > 08:35:34
> > 08:35:35 192.168.0.1
> >
> > At 08:35:34 the server had no IP addresses
>
>
> Well, it probably had 127.0.0.1, which brings into question what
> the
> complete state of the network was.
>
> Could you arrange to execute "ip addr show | logger" in your unfrak
> script?
> That way we get all of the interfaces and all of the addresses
> regardless of
> family.
>
> Could you also see if removing the "-s" flag from
> /usr/lib/systemd/system/NetworkManager-wait-online.service changes
> the
> behavior of the system?
Running just "ip addr show | logger" was not conclusive. Looks like
the
overhead of doing so delays things long enough so even the first time
this
actually runs all the network interfaces have their IP addresses
already
assigned.
Removing the -s option from actually makes things worse. The script
has to
wait noticably longer before all IP addresses are assigned:
Subject: systemd network initialization unfrak report
Time IP addresses
======== ==================
06:52:56
06:52:57
06:52:58
06:52:59 192.168.0.1
Usually it's 1 or 2 seconds. Without the -s option it's 4-5 seconds.
This seems consistent with the description of what the -s option
does, from
the man page. The way I parse its man page entry is that the -s
option
actually waits for more things to happen, before it's done. So
removing that
option makes NetworkManager's definition of when things are online
occur
much earlier.
This is confirmed by running "ip addr show | logger" without -s
option. This
produces some useful results. This time, the first time "ip addr
show" runs
it's early enough so that the network is not fully initialized.
syslog shows two runs of "ip addr show", showing no IP addresses
configured
on one of the two network interfaces. The 2nd network interface
already has
its IP addresses assigned. This is followed by some messages from
NetworkManager, then another run of "ip addr show", showing all
network
interfaces with assigned IP addresses.
Both eno1 and eno2 have statically assigned IP addresses in
/etc/sysconfig/network-scripts.
Dec 19 06:57:09 shorty systemd[1]: Starting Unfrak systemd network
startup...
Dec 19 06:57:09 shorty systemd[1]: iscsi.service: Unit cannot be
reloaded because it is inactive.
Dec 19 06:57:09 shorty root[1400]: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu
65536 qdisc noqueue state UNKNOWN group default qlen 1000
Dec 19 06:57:09 shorty root[1400]: link/loopback 00:00:00:00:00:00
brd 00:00:00:00:00:00
Dec 19 06:57:09 shorty root[1400]: inet 127.0.0.1/8 scope host lo
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet6 ::1/128 scope host
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: 2: eno1: <NO-
CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel state DOWN
group default qlen 1000
Dec 19 06:57:09 shorty root[1400]: link/ether 0c:c4:7a:32:c1:82
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:09 shorty root[1400]: 3: eno2:
<BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group
default qlen 1000
Dec 19 06:57:09 shorty root[1400]: link/ether 0c:c4:7a:32:c1:83
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:09 shorty root[1400]: inet 68.166.206.83/29 brd
68.166.206.87 scope global eno2
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet 68.166.206.82/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet 68.166.206.84/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet 68.166.206.85/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet 68.166.206.86/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:09 shorty root[1400]: inet6
fe80::ec4:7aff:fe32:c183/64 scope link tentative
Dec 19 06:57:09 shorty root[1400]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu
65536 qdisc noqueue state UNKNOWN group default qlen 1000
Dec 19 06:57:10 shorty root[1403]: link/loopback 00:00:00:00:00:00
brd 00:00:00:00:00:00
Dec 19 06:57:10 shorty root[1403]: inet 127.0.0.1/8 scope host lo
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet6 ::1/128 scope host
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: 2: eno1: <NO-
CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel state DOWN
group default qlen 1000
Dec 19 06:57:10 shorty root[1403]: link/ether 0c:c4:7a:32:c1:82
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:10 shorty root[1403]: 3: eno2:
<BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group
default qlen 1000
Dec 19 06:57:10 shorty root[1403]: link/ether 0c:c4:7a:32:c1:83
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:10 shorty root[1403]: inet 68.166.206.83/29 brd
68.166.206.87 scope global eno2
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet 68.166.206.82/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet 68.166.206.84/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet 68.166.206.85/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet 68.166.206.86/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty root[1403]: inet6
fe80::ec4:7aff:fe32:c183/64 scope link tentative
Dec 19 06:57:10 shorty root[1403]: valid_lft forever
preferred_lft forever
Dec 19 06:57:10 shorty systemd-networkd[955]: eno2: Gained IPv6LL
Dec 19 06:57:10 shorty NetworkManager[956]: <info> [1513684630.6860]
manager: startup complete
Dec 19 06:57:11 shorty kernel: e1000e: eno1 NIC Link is Up 1000 Mbps
Full Duplex, Flow Control: Rx/Tx
Dec 19 06:57:11 shorty kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eno1:
link becomes ready
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4385]
device (eno1): link connected
Dec 19 06:57:11 shorty systemd-networkd[955]: eno1: Gained carrier
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4390]
device (eno1): state change: unavailable -> disconnected (reason
'carrier-changed', internal state 'managed')
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4396]
policy: auto-activating connection 'lan0'
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4405]
device (eno1): Activation: starting connection 'lan0' (d1a1ee90-f006-
43bb-9cbf-175ad32f6565)
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4406]
device (eno1): state change: disconnected -> prepare (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4410]
device (eno1): state change: prepare -> config (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4436]
device (eno1): state change: config -> ip-config (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty named[1035]: listening on IPv4 interface eno1,
192.168.0.1#53
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4464]
device (eno1): state change: ip-config -> ip-check (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty nm-dispatcher[990]: req:5 'pre-up' [eno1]: new
request (1 scripts)
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4509]
device (eno1): state change: ip-check -> secondaries (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.4511]
device (eno1): state change: secondaries -> activated (reason 'none',
internal state 'managed')
Dec 19 06:57:11 shorty root[1415]: 1: lo: <LOOPBACK,UP,LOWER_UP> mtu
65536 qdisc noqueue state UNKNOWN group default qlen 1000
Dec 19 06:57:11 shorty root[1415]: link/loopback 00:00:00:00:00:00
brd 00:00:00:00:00:00
Dec 19 06:57:11 shorty root[1415]: inet 127.0.0.1/8 scope host lo
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet6 ::1/128 scope host
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: 2: eno1:
<BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP
group default qlen 1000
Dec 19 06:57:11 shorty root[1415]: link/ether 0c:c4:7a:32:c1:82
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:11 shorty root[1415]: inet 192.168.0.1/24 brd
192.168.0.255 scope global eno1
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet6
fe80::ec4:7aff:fe32:c182/64 scope link tentative
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: 3: eno2:
<BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group
default qlen 1000
Dec 19 06:57:11 shorty root[1415]: link/ether 0c:c4:7a:32:c1:83
brd ff:ff:ff:ff:ff:ff
Dec 19 06:57:11 shorty root[1415]: inet 68.166.206.83/29 brd
68.166.206.87 scope global eno2
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet 68.166.206.82/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty NetworkManager[956]: <info> [1513684631.5589]
device (eno1): Activation: successful, device activated.
Dec 19 06:57:11 shorty root[1415]: inet 68.166.206.84/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet 68.166.206.85/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet 68.166.206.86/29 brd
68.166.206.87 scope global secondary eno2
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty root[1415]: inet6
fe80::ec4:7aff:fe32:c183/64 scope link
Dec 19 06:57:11 shorty root[1415]: valid_lft forever
preferred_lft forever
Dec 19 06:57:11 shorty nm-dispatcher[990]: req:6 'up' [eno1]: new
request (7 scripts)
Dec 19 06:57:11 shorty systemd[1]: Started Unfrak systemd network
startup.
Note that "ip addr show" ran as part of the script that has a
dependency on
nm-line.
After reversing all changes, putting the -s option back in, and not
running
"ip addr", repeated boots shows the status quo being restored. The
presence
of the -s option reduces the additional time that the script needs to
wait
for all IP addresses to be assigned to 1 or 2 seconds. But it still
has to
wait, since nm-online -s -q returns too early.
One question that has been bugging me for some time now: I wonder if
nm-online checks for IP-addressing only when the "require ipv4
addressing for this connection to complete" option nm-connection-
editor (which I guess results in IPV4_FAILURE_FATAL=yes being set in
the config file for the interface) is set. Do you have the
IPV4_FAILURE_FATAL set in /etc/sysconfig/network-scripts/ifcfg-xxx
file?
If I find some time, I will play around with it to see if this solves
the problems with a switch port that takes time to go into forwarding
state are solved with this option.... I may have a look at the sources
of nm-online to see if it even looks at this parameter.
BR, Louis