dhcpcd-discuss

On Friday, October 17, 2014 2:05 PM, David Hauck wrote:
> On Friday, October 17, 2014 2:00 PM, Roy Marples wrote:
>> On 2014-10-17 16:56, David Hauck wrote:
>>> On Friday, October 17, 2014 6:56 AM, Roy Marples wrote:
>>>> On 17/10/2014 14:25, David Hauck wrote:
>>>>>> I don't see this problem with dhcpcd-6.5.0 (well, the latest trunk).
>>>>>> There was a problem, although unrelated, which resulted in this
>>>>>> patch
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> http://roy.marples.name/projects/dhcpcd/ci/4c1f2f8a298ad244f8c7397
>>>>>> 1 0b a e46088ea7efd6?sbs=0 But that patch means nothing for 6.1.0.
>>>>>> 
>>>>>> So, can you test 6.5.0 with that patch please?
>>>>> 
>>>>> Sure, I'll test either 6.5.0 of 6.1.0 with the patch, but may not
>>>>> get to this
>>>> before the end of the day.
>>> 
>>> I did a quick test of this (essentially just a rebuild of 'dhcpcd'
>>> v6.5.0 and deploy to the target - I didn't deploy the hooks and
>>> this seems OK since the changes there seem to be irrelevant to my
>>> configuration) and I'm seeing the same issue.
>>> 
>>> Here's my configuration: hostname option rapid_commit option
>>> domain_name_servers, domain_name, domain_search, host_name option
>>> classless_static_routes option ntp_servers require
>>> dhcp_server_identifier nohook lookup-hostname timeout 20 ipv4only
>>> vendor 01,"0"
>>> 
>>> Any ideas for what else to try?
>> 
>> Here's my syslog capture using your config on one interface.
>> 
>> Oct 17 21:42:26 [dhcpcd] version 6.5.0 starting Oct 17 21:42:27
>> [dhcpcd] enp3s0: soliciting a DHCP lease Oct 17 21:42:46 [dhcpcd] timed
>> out Oct 17 21:42:46 [dhcpcd] allowing 8 seconds for IPv4LL timeout Oct
>> 17 21:42:47 [dhcpcd] enp3s0: probing for an IPv4LL address Oct 17
>> 21:42:52 [dhcpcd] enp3s0: using IPv4LL address 169.254.102.37 Oct 17
>> 21:42:52 [dhcpcd] enp3s0: adding route to 169.254.0.0/16 Oct 17
>> 21:42:52 [dhcpcd] forked to background, child pid 8646 Oct 17 21:43:00
>> [dhcpcd] enp3s0: carrier lost Oct 17 21:43:00 [dhcpcd] enp3s0: deleting
>> route to 169.254.0.0/16 Oct 17 21:43:07 [dhcpcd] enp3s0: carrier
>> acquired Oct 17 21:43:13 [dhcpcd] enp3s0: using IPv4LL address
>> 169.254.102.37 Oct 17 21:43:13 [dhcpcd] enp3s0: adding route to
>> 169.254.0.0/16 Oct 17 21:43:17 [dhcpcd] enp3s0: soliciting a DHCP lease
>> Oct 17 21:43:17 [dhcpcd] enp3s0: offered 10.73.2.30 from 10.73.1.1
>> `uberserver.marples.name' Oct 17 21:43:22 [dhcpcd] enp3s0: leased
>> 10.73.2.30 for 3600 seconds Oct 17 21:43:22 [dhcpcd] enp3s0: adding
>> route to 10.73.2.0/24 Oct 17 21:43:22 [dhcpcd] enp3s0: adding default
>> route via 10.73.2.1 Oct 17 21:43:22 [dhcpcd] enp3s0: deleting route to
>> 169.254.0.0/16
>> 
>> As you can see it works fine.
> 
> Weird, huh...
> 
>> But my version is beyond 6.5.0. However, as I cannot replicate your
>> issue with it I'll release 6.5.1 tonight which hopefully you can re-test with.
>> Adding the debug option gives a lot more output, you should use the
>> same option when reporting back as it tells me a lot more about the
>> state of dhcpcd.
> 
> Sure, thanks.

I just tried v5.6.1 and it does behave differently (although not like your result above). In the v6.5.1 case I don't see the constant cycling between IPV4LL and EXPIRE states, but I also don't see the expected transition to a new, valid lease:
 
20141017 14:39:32.114 info daemon(dhcpcd):version 6.5.1 starting
20141017 14:39:32.127 info daemon(dhcpcd):eth1: 60-netacquire: received reason=PREINIT, beeppid=0, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:39:32.141 info daemon(dhcpcd):eth1: 60-netacquire: received reason=NOCARRIER, beeppid=21387, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:39:32.216 info daemon(dhcpcd):eth1: waiting for carrier
20141017 14:39:33.845 info daemon(dhcpcd):eth1: carrier acquired
20141017 14:39:33.859 info daemon(dhcpcd):eth1: 60-netacquire: received reason=CARRIER, beeppid=21387, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:39:33.859 info daemon(dhcpcd):DUID 00:01:00:01:1b:bd:fd:00:00:1b:21:0a:21:03
20141017 14:39:33.860 info daemon(dhcpcd):eth1: IAID ab:36:1c:fc
20141017 14:39:34.330 info daemon(dhcpcd):eth1: soliciting a DHCP lease
20141017 14:39:52.142 warning daemon(dhcpcd):allowing 9 seconds for IPv4LL timeout
20141017 14:39:54.332 info daemon(dhcpcd):eth1: probing for an IPv4LL address
20141017 14:39:58.729 info daemon(dhcpcd):eth1: using IPv4LL address 169.254.35.255
20141017 14:39:58.729 info daemon(dhcpcd):eth1: adding route to 169.254.0.0/16
20141017 14:39:58.744 info daemon(dhcpcd):eth1: 60-netacquire: received reason=IPV4LL, beeppid=21387, ip=169.254.35.255, sn=255.255.0.0, gw=, dns=, options=, hn=
20141017 14:39:58.750 info daemon(dhcpcd):forked to background, child pid 21608
20141017 14:40:14.419 info daemon(dhcpcd):eth1: carrier lost
20141017 14:40:14.432 info daemon(dhcpcd):eth1: 60-netacquire: received reason=NOCARRIER, beeppid=0, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:40:14.442 info daemon(dhcpcd):eth1: deleting route to 169.254.0.0/16
20141017 14:40:14.456 info daemon(dhcpcd):eth1: 60-netacquire: received reason=EXPIRE, beeppid=21718, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:40:23.697 info daemon(dhcpcd):eth1: carrier acquired
20141017 14:40:23.711 info daemon(dhcpcd):eth1: 60-netacquire: received reason=CARRIER, beeppid=21718, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:40:23.711 info daemon(dhcpcd):eth1: IAID ab:36:1c:fc
20141017 14:40:29.401 info daemon(dhcpcd):eth1: using IPv4LL address 169.254.35.255
20141017 14:40:29.401 info daemon(dhcpcd):eth1: adding route to 169.254.0.0/16
20141017 14:40:29.416 info daemon(dhcpcd):eth1: 60-netacquire: received reason=IPV4LL, beeppid=21718, ip=169.254.35.255, sn=255.255.0.0, gw=, dns=, options=, hn=
20141017 14:40:31.425 warning daemon(dhcpcd):eth1: IPv4LL 10 second defence failed
20141017 14:40:31.435 info daemon(dhcpcd):eth1: deleting route to 169.254.0.0/16
20141017 14:40:31.447 info daemon(dhcpcd):eth1: 60-netacquire: received reason=EXPIRE, beeppid=0, ip=, sn=, gw=, dns=, options=, hn=
20141017 14:40:32.449 info daemon(dhcpcd):eth1: probing for an IPv4LL address
20141017 14:40:37.593 info daemon(dhcpcd):eth1: 60-netacquire: received reason=EXPIRE, beeppid=21879, ip=, sn=, gw=, dns=, options=, hn=

It's now 10mins past the last timestamp above, so I'm not seeing any further transitions/activity with dhcpcd in the log.

I'm using 'if{up|down} eth1' to bring the interface up and down - i.e., as follows:

1. ifdown eth1
2. attach C1
3. ifup eth1
4. remove C1
5. attach C2
6. review logs

I configured v6.5.1 without --disable-debug. I'm thinking you were referring to something else when mentioned adding the "debug option". What did you mean by this exactly ;)?

Thanks,
-David

> -David
> 
>> Thanks
>> 
>> Roy