Re: dhcpcd 7.1.1 (and 7.2.0) time out on boot
Matt Horan
Thu Apr 25 15:22:49 2019
On Thu, Apr 25, 2019 at 03:47:45PM +0100, Roy Marples wrote:
> On 25/04/2019 15:16, Matt Horan wrote:
> >> Does dhcpcd recover from carrier loss?
> >
> > It doesn't seem so. After the first reboot I waited over a minute and
> > dhcpcd never got a lease. When I restarted dhcpcd it got a lease
> > immediately.
> >
> > I do see that dhcpcd forks to the background, so it should still be
> > running, but seems to not detect that carrier has returned. IPv4 works
> > fine during the entire process, so I believe the interface is still up.
>
> OK.
>
> Can you add this to the top of dhcpcd.conf please?
>
> debug
> logfile /var/log/dhcpcd.log
>
> Reboot and then email me the log - privately if you feel it has
> sensitive data.
dhcpcd.log and dmesg with route monitor output attached.
--
Matt Horan matt@xxxxxxxxxxxxx https://matthoran.com/
Apr 25 11:13:36 [65404]: dhcpcd-7.1.1 starting
Apr 25 11:13:36 [65404]: DUID 00:01:00:01:24:53:c3:07:00:0d:b9:41:d8:74
Apr 25 11:13:36 [65404]: em0: IAID b9:41:d8:74
Apr 25 11:13:36 [65404]: em0: IA type 25 IAID 00:00:00:00
Apr 25 11:13:36 [65404]: em0: delaying IPv6 router solicitation for 1.0 seconds
Apr 25 11:13:36 [65404]: em0: reading lease `/var/db/dhcpcd/em0.lease6'
Apr 25 11:13:36 [65404]: em0: rebinding prior DHCPv6 lease
Apr 25 11:13:36 [65404]: em0: delaying REBIND6 (xid 0x8b4976), next in 0.9 seconds
Apr 25 11:13:36 [65404]: em1: IAID b9:41:d8:75
Apr 25 11:13:36 [65404]: em0: carrier lost
Apr 25 11:14:06 [65404]: timed out
Apr 25 11:14:06 [65404]: forking to background
Apr 25 11:14:06 [65404]: forked to background, child pid 29918
starting package daemons: dhcpcdgot message of size 168 on Thu Apr 25 11:13:36 2019
RTM_IFINFO: iface status change: len 168, if# 1, name: em0, link: active, mtu: 1500, flags:<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST>
got message of size 192 on Thu Apr 25 11:13:36 2019
RTM_GET: Report Metrics: len 192, priority 8, table 0, ifidx 1, pid: 39731, seq 2128284594, errno 0
flags:<UP,GATEWAY,DONE,STATIC>
fmask:
use: 4089 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA>
0.0.0.0 24.193.94.1 0.0.0.0 00:0d:b9:41:d8:74 24.193.94.231
got message of size 120 on Thu Apr 25 11:13:36 2019
RTM_NEWADDR: address being added to iface: len 120, metric 0, flags:
sockaddrs: <NETMASK,IFP,IFA>
ffff:ffff:ffff:ffff:: 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
got message of size 224 on Thu Apr 25 11:13:36 2019
RTM_ADD: Add Route: len 224, priority 1, table 0, ifidx 2, 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>
fe80::826f:f28a:bbae:c448%em1 00:0d:b9:41:d8:75 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
got message of size 256 on Thu Apr 25 11:13:36 2019
RTM_ADD: Add Route: len 256, priority 4, table 0, ifidx 2, 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>
fe80::%em1 fe80::826f:f28a:bbae:c448%em1 ffff:ffff:ffff:ffff:: 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
got message of size 296 on Thu Apr 25 11:13:36 2019
RTM_DELETE: Delete Route: len 296, priority 56, table 0, ifidx 1, pid: 21594, seq 2, errno 0
flags:<GATEWAY,DONE,STATIC>
fmask:
use: 8 mtu: 0 expire: 0
locks: inits:
sockaddrs: <DST,GATEWAY,NETMASK,IFP,IFA,LABEL>
:: fe80::217:10ff:fe88:8be1%em0 :: 00:0d:b9:41:d8:74 fe80::e399:de83:d65:ac4c%em0 "slaacd"
got message of size 192 on Thu Apr 25 11:13:37 2019
RTM_CHGADDRATTR: address attributes being changed: len 192, metric 0, flags:
sockaddrs: <NETMASK,IFP,IFA>
ffff:ffff:ffff:ffff:: 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
got message of size 224 on Thu Apr 25 11:13:39 2019
RTM_ADD: Add Route: len 224, priority 3, table 0, ifidx 2, 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>
fe80::4e34:88ff:fe8c:6c75%em1 link#2 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
got message of size 224 on Thu Apr 25 11:13:39 2019
RTM_RESOLVE: Route created by cloning: len 224, priority 3, table 0, ifidx 2, 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>
fe80::4e34:88ff:fe8c:6c75%em1 4c:34:88:8c:6c:75 00:0d:b9:41:d8:75 fe80::826f:f28a:bbae:c448%em1
.
Archive administrator: postmaster@marples.name