RE: TIMEOUT on Rebind?
David Hauck
Mon Jun 06 19:49:46 2016
On Monday, June 06, 2016 12:36 PM, David Hauck wrote:
> Hi Roy,
>
> On Monday, June 06, 2016 12:25 PM, Roy Marples wrote:
>> Hi David
>>
>> On 06/06/2016 18:47, David Hauck wrote:
>>> I don't have reboot configured for a specific value and my
>>> understanding is that this defaults to 5s in this case.
>>>
>>>> If this fails, dhcpcd will use the last lease if it's not expired
>>>> and the lastlease option is enabled. At this point you should see
>>>> the TIMEOUT reason.
>>>
>>> Right, OK, I definitely don't see this reason code show up. Any
>>> more ideas why?
>>
>> None!
>> So lets add some debug code to find out.
>> Patch attached - you should see an extra DEBUG line with some
>> parameteres. Both should be non zero.
>> Let me know.
>
> OK, thx, I'll try this. Although the patch you provided is likely for
> a different version of dhcpcd (again, I'm running v6.7.1); it is
> simple enough that I can modify it easily for the v6.7.1 code though.
OK, here's what I see (this is back to the first case again where the rebind happens quickly followed by the later "soliciting a DHCP lease" stall . I mentioned last Wednesday that I also see cases where CARRIER immediately transitions to the "soliciting a DHCP lease" stall.
20160606 12:42:53.869 info daemon(dhcpcd):eth1: carrier lost
20160606 12:42:53.889 info daemon(dhcpcd):eth1: 60-custom: received reason=NOCARRIER, ip=, sn=, gw=, dns=, options=, hn=
20160606 12:42:53.889 info daemon(dhcpcd):eth1: deleting route to 205.159.216.128/25
20160606 12:42:53.889 info daemon(dhcpcd):eth1: deleting default route via 205.159.216.130
20160606 12:42:53.906 info daemon(dhcpcd):eth1: 60-custom: received reason=EXPIRE, ip=, sn=, gw=, dns=, options=, hn=
20160606 12:42:58.284 info daemon(dhcpcd):eth1: carrier acquired
20160606 12:42:58.290 info daemon(dhcpcd):eth1: 60-custom: received reason=CARRIER, ip=, sn=, gw=, dns=, options=, hn=
20160606 12:42:58.291 info daemon(dhcpcd):eth1: IAID e0:53:f3:9f
20160606 12:42:58.729 info daemon(dhcpcd):eth1: rebinding lease of 205.159.216.183
20160606 12:42:58.729 info daemon(dhcpcd):DEBUG 128 1 <=== here's the syslog line that was added
20160606 12:43:03.729 info daemon(dhcpcd):eth1: leased 205.159.216.183 for 28800 seconds
20160606 12:43:03.729 info daemon(dhcpcd):eth1: adding route to 205.159.216.128/25
20160606 12:43:03.729 info daemon(dhcpcd):eth1: adding default route via 205.159.216.130
20160606 12:43:03.738 info daemon(dhcpcd):eth1: 60-custom: received reason=REBOOT, ip=205.159.216.183, sn=255.255.255.128, gw=205.159.216.130, dns=205.159.216.147 172.20.0.6 205.159.216.73, options=, hn=
20160606 12:43:03.749 info daemon(dhcpcd):eth1: soliciting a DHCP lease
Thanks,
-David
> -David
>
>> Roy
Archive administrator: postmaster@marples.name