On Thu, Oct 24 2019 16:09:41 -0400, kwesterb...@gmail.com wrote:
> >>> # route monitor >/tmp/route-monitor.good &
> >>> # dhclient vio0
> >>> # ping 1.1.1.1
> >>
> >> Can you add a "ifconfig vio0" at this point,
> >>> ^C
> >>> # ifconfig vio0 -soii
> >>> # ping 1.1.1.1
> >>
> >> and here.
> > I can of course repeat any of these tests on a -CURRENT system vs. a
> > -CURRENT system that has the commit that introduced the problem
> > reverted, if you like.
>
> Yes, please.
So once more, with feeling. These are the bsd.rd's under test:
bad: cc77704b1667b9e88ff797de7c9baefae04bf275 aka if_vio.c r1.14
good: same as previous, but with the following diff. The revert of
dhclient.c r1.634 did not apply cleanly because of more recent changes
to the code (namely r1.635), so I've manually made what I think is the
inverse change here, to not restart if the link state did not change.
This diff does make the problem go away (but I don't know why).
diff --git a/sbin/dhclient/dhclient.c b/sbin/dhclient/dhclient.c
index c5d197ee274..042254d7798 100644
--- a/sbin/dhclient/dhclient.c
+++ b/sbin/dhclient/dhclient.c
@@ -345,6 +345,7 @@ rtm_dispatch(struct interface_info *ifi, struct rt_msghdr
*rtm)
struct ifa_msghdr *ifam;
struct if_ieee80211_data *ifie;
uint32_t oldmtu;
+ int oldlinkup;
switch (rtm->rtm_type) {
case RTM_PROPOSAL:
@@ -390,11 +391,13 @@ rtm_dispatch(struct interface_info *ifi, struct rt_msghdr
*rtm)
oldmtu = ifi->mtu;
interface_state(ifi);
- if (oldmtu == ifi->mtu)
- quit = RESTART;
- else
- log_debug("%s: MTU change RTM_IFINFO ignored",
- log_procname);
+ if (LINK_STATE_IS_UP(ifi->link_state) != oldlinkup) {
+ if (oldmtu == ifi->mtu)
+ quit = RESTART;
+ else
+ log_debug("%s: MTU change RTM_IFINFO ignored",
+ log_procname);
+ }
break;
case RTM_80211INFO:
Here's the test script I ran from both bsd.rd's:
#!/bin/sh
[ -n "$1" ] || { echo "usage"; exit 1; }
exec > test.$1 2>&1
set -x
route monitor >route-monitor.$1 &
dhclient vio0
sleep 1
ifconfig vio0
ping -c 1 1.1.1.1
ifconfig vio0 -soii
sleep 1
ping -c 1 1.1.1.1
ifconfig vio0
kill -INT %1
and the results. first, "bad":
$ cat test.bad
+ dhclient vio0
+ route monitor
+ > route-monitor.bad
+ sleep 1
+ ifconfig vio0
vio0: flags=808843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,AUTOCONF4> mtu 1500
lladdr 96:00:00:34:06:8e
llprio 3
groups: egress
media: Ethernet autoselect
status: active
inet 95.217.7.62 netmask 0xffffffff
+ ping -c 1 1.1.1.1
PING 1.1.1.1 (1.1.1.1): 56 data bytes
64 bytes from 1.1.1.1: icmp_seq=0 ttl=57 time=18.778 ms
--- 1.1.1.1 ping statistics ---
1 packets transmitted, 1 packets received, 0.0% packet loss
round-trip min/avg/max/std-dev = 18.778/18.778/18.778/0.000 ms
+ ifconfig vio0 -soii
+ sleep 1
+ ping -c 1 1.1.1.1
ping: sendmsg: Invalid argument
PING 1.1.1.1 (1.1.1.1): 56 data bytes
ping: wrote 1.1.1.1 64 chars, ret=-1
--- 1.1.1.1 ping statistics ---
1 packets transmitted, 0 packets received, 100.0% packet loss
+ ifconfig vio0
vio0:
flags=c08843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,INET6_NOSOII,AUTOCONF4> mtu
1500
lladdr 96:00:00:34:06:8e
llprio 3
groups: egress
media: Ethernet autoselect
status: active
inet 95.217.7.62 netmask 0xffffffff
+ kill -INT %1
$ cat route-monitor.bad
got message of size 168 on Fri Oct 25 11:45:38 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:45:38 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:45:38 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:45:38 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 96 on Fri Oct 25 11:45:38 2019
RTM_PROPOSAL: config proposal: len 96, source dhcp table 0, ifidx 1, pid:
22261, seq -593891804, errno 0
flags:<UP,DONE,PROTO3>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
Static Routes:
Domain search:
Domain Name Servers:
got message of size 96 on Fri Oct 25 11:45:38 2019
RTM_NEWADDR: address being added to iface: len 96, metric 0, flags:
sockaddrs: <NETMASK,IFP,IFA,BRD>
255.255.255.255 96:00:00:34:06:8e 95.217.7.62 0.0.0.0
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 192, priority 1, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,LOCAL>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
95.217.7.62 96:00:00:34:06:8e 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 192, priority 4, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,DONE,CLONING,CONNECTED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
95.217.7.62 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 192, priority 8, table 0, ifidx 1, pid: 678, seq 0,
errno 0
flags:<UP,DONE,CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
172.31.1.1 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 144 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 144, priority 0, table 0, ifidx 1, pid: 678, seq 0,
errno 17
flags:<CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
172.31.1.1 95.217.7.62 255.255.255.255
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 192, priority 7, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 link#1 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_ADD: Add Route: len 192, priority 8, table 0, ifidx 1, pid: 678, seq 0,
errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 678, seq
-1688123477, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:38 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 678, seq
-2029380539, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_RESOLVE: Route created by cloning: len 192, priority 7, table 0, ifidx 1,
pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED,CACHED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 d2:74:7f:6e:37:e3 96:00:00:34:06:8e 95.217.7.62
got message of size 168 on Fri Oct 25 11:45:39 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,INET6_NOSOII>
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 678, seq
870724543, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 1 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 208 on Fri Oct 25 11:45:39 2019
RTM_DELETE: Delete Route: len 208, priority 7, table 0, ifidx 1, pid: 678, seq
0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED,CACHED>
fmask:
use: 2 mtu: 0 expire: 1200
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
172.31.1.1 link#1 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_DELETE: Delete Route: len 192, priority 7, table 0, ifidx 1, pid: 0, seq 0,
errno 0
flags:<HOST,DONE,CLONED,CACHED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 link#1 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_DELETE: Delete Route: len 192, priority 8, table 0, ifidx 1, pid: 678, seq
1, errno 0
flags:<DONE,CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
172.31.1.1 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_ADD: Add Route: len 192, priority 8, table 0, ifidx 1, pid: 678, seq 0,
errno 0
flags:<UP,DONE,CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
172.31.1.1 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 144 on Fri Oct 25 11:45:39 2019
RTM_ADD: Add Route: len 144, priority 0, table 0, ifidx 1, pid: 678, seq 0,
errno 17
flags:<CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
172.31.1.1 95.217.7.62 255.255.255.255
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_ADD: Add Route: len 192, priority 7, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 link#1 96:00:00:34:06:8e 95.217.7.62
got message of size 160 on Fri Oct 25 11:45:39 2019
RTM_ADD: Add Route: len 160, priority 0, table 0, ifidx 1, pid: 678, seq 0,
errno 17
flags:<GATEWAY,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 95.217.7.62
got message of size 192 on Fri Oct 25 11:45:39 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 678, seq
-1044169088, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 1 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
then, "good":
$ cat test.good
+ dhclient vio0
+ route monitor
+ > route-monitor.good
+ sleep 1
+ ifconfig vio0
vio0: flags=808843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,AUTOCONF4> mtu 1500
lladdr 96:00:00:34:06:8e
llprio 3
groups: egress
media: Ethernet autoselect
status: active
inet 95.217.7.62 netmask 0xffffffff
+ ping -c 1 1.1.1.1
PING 1.1.1.1 (1.1.1.1): 56 data bytes
64 bytes from 1.1.1.1: icmp_seq=0 ttl=57 time=7.957 ms
--- 1.1.1.1 ping statistics ---
1 packets transmitted, 1 packets received, 0.0% packet loss
round-trip min/avg/max/std-dev = 7.957/7.957/7.957/0.000 ms
+ ifconfig vio0 -soii
+ sleep 1
+ ping -c 1 1.1.1.1
PING 1.1.1.1 (1.1.1.1): 56 data bytes
64 bytes from 1.1.1.1: icmp_seq=0 ttl=57 time=7.947 ms
--- 1.1.1.1 ping statistics ---
1 packets transmitted, 1 packets received, 0.0% packet loss
round-trip min/avg/max/std-dev = 7.947/7.947/7.947/0.000 ms
+ ifconfig vio0
vio0:
flags=c08843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,INET6_NOSOII,AUTOCONF4> mtu
1500
lladdr 96:00:00:34:06:8e
llprio 3
groups: egress
media: Ethernet autoselect
status: active
inet 95.217.7.62 netmask 0xffffffff
+ kill -INT %1
$ cat route-monitor.good
got message of size 168 on Fri Oct 25 11:47:05 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:47:05 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:47:05 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 168 on Fri Oct 25 11:47:05 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 96 on Fri Oct 25 11:47:05 2019
RTM_PROPOSAL: config proposal: len 96, source dhcp table 0, ifidx 1, pid:
93221, seq -1235616654, errno 0
flags:<UP,DONE,PROTO3>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
Static Routes:
Domain search:
Domain Name Servers:
got message of size 96 on Fri Oct 25 11:47:05 2019
RTM_NEWADDR: address being added to iface: len 96, metric 0, flags:
sockaddrs: <NETMASK,IFP,IFA,BRD>
255.255.255.255 96:00:00:34:06:8e 95.217.7.62 0.0.0.0
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 192, priority 1, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,LOCAL>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
95.217.7.62 96:00:00:34:06:8e 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 192, priority 4, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,DONE,CLONING,CONNECTED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
95.217.7.62 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 192, priority 8, table 0, ifidx 1, pid: 56044, seq 0,
errno 0
flags:<UP,DONE,CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
172.31.1.1 95.217.7.62 255.255.255.255 96:00:00:34:06:8e 95.217.7.62
got message of size 144 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 144, priority 0, table 0, ifidx 1, pid: 56044, seq 0,
errno 17
flags:<CLONING,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK>
172.31.1.1 95.217.7.62 255.255.255.255
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 192, priority 7, table 0, ifidx 1, pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 link#1 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_ADD: Add Route: len 192, priority 8, table 0, ifidx 1, pid: 56044, seq 0,
errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_RESOLVE: Route created by cloning: len 192, priority 7, table 0, ifidx 1,
pid: 0, seq 0, errno 0
flags:<UP,HOST,DONE,LLINFO,CLONED,CACHED>
fmask:
use: 0 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,IFP,IFA>
172.31.1.1 d2:74:7f:6e:37:e3 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 56044, seq
1611749725, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 4 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 192 on Fri Oct 25 11:47:05 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 56044, seq
1590428816, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 4 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
got message of size 168 on Fri Oct 25 11:47:06 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: vio0, link: active, mtu:
1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST,INET6_NOSOII>
got message of size 192 on Fri Oct 25 11:47:06 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 56044, seq
-2015332144, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 5 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 172.31.1.1 0.0.0.0 96:00:00:34:06:8e 95.217.7.62
--
Lauri Tirkkonen | lotheac @ IRCnet
