dhcpcd-discuss

Roy Marples <roy@xxxxxxxxxxxx> writes:

> On Thu, 2008-11-27 at 09:23 +0100, Jean Wolter wrote:
>> Both changes work fine:
>> 
>> Wed Nov 26 19:52:20 2008: eth2: sending ARP probe (1 of 3), next in 1.02 seconds
>> Wed Nov 26 19:52:20 2008: eth2: ignoring offer of 192.168.1.33 from 192.168.1.1
>> Wed Nov 26 19:52:21 2008: eth2: ignoring offer of 85.5.83.104 from 138.187.24.10
>> Wed Nov 26 19:52:21 2008: eth2: sending ARP probe (2 of 3), next in 1.18 seconds
>> Wed Nov 26 19:52:23 2008: eth2: sending ARP probe (3 of 3), next in 2.00 seconds
>> Wed Nov 26 19:52:25 2008: eth2: sending DHCP_REQUEST with xid 0x5a7e98f9, next in 4.69 seconds
>> 
>> I booted the same setup on top of a 2.4 linux kernel, which does
>> not provide a monotonic clock - dhcpcd detected it correctly,
>> displayed the warning and used gettimeofday.
>
> As your interface link seems to flap (which causes this bug I think), it
> might be an idea to try out a snapshot to see if it happens with that.

It took a while but I finally managed to try it (I mean let somebody
else try it). With this version there is a different problem. As you
can see in the debug output the dhcp client gets two offers after its
request:

| eth2: ignoring offer of 192.168.1.33 from 192.168.1.1 
| eth2: ignoring offer of 85.5.83.104 from 138.187.24.10 

I am not sure, where the second offer comes from, but its the same IP
the dsl modem the dhcp server is running on has on its outer
interface.

dhcpcd 4.0.4 ignore the second offer(s) and accepts the first offer:

eth2: offered 192.168.1.33 from 192.168.1.1
eth2: checking 192.168.1.33 is available on attached networks
eth2: ignoring offer of 192.168.1.33 from 192.168.1.1
eth2: ignoring offer of 92.105.164.116 from 138.187.24.107
eth2: acknowledged 192.168.1.33 from 192.168.1.1
eth2: leased 192.168.1.33 for 86400 seconds

dhcpcd 4.99 behaves differently, it restarts its checks and accepts
the last IP offered:

20:57:51 dhcpcd: version 4.99.6 starting
20:57:51 dhcpcd: eth2: broadcasting for a lease
20:57:51 dhcpcd: eth2: sending DHCP_DISCOVER (xid 0xae806b1), next in 3.11 seconds
20:57:52 dhcpcd: eth2: offered 192.168.1.33 from 192.168.1.1
20:57:52 dhcpcd: eth2: checking 192.168.1.33 is available on attached networks
20:57:52 dhcpcd: eth2: sending ARP probe (1 of 3), next in 1.77 seconds
20:57:52 dhcpcd: eth2: offered 192.168.1.33 from 192.168.1.1
20:57:52 dhcpcd: eth2: checking 192.168.1.33 is available on attached networks
20:57:52 dhcpcd: eth2: sending ARP probe (1 of 3), next in 1.15 seconds
20:57:52 dhcpcd: eth2: offered 92.105.164.116 from 138.187.24.107
20:57:52 dhcpcd: eth2: checking 92.105.164.116 is available on attached networks
20:57:52 dhcpcd: eth2: sending ARP probe (1 of 3), next in 1.07 seconds
20:57:53 dhcpcd: eth2: sending ARP probe (2 of 3), next in 1.62 seconds
20:57:55 dhcpcd: eth2: sending ARP probe (3 of 3), next in 2.00 seconds
20:57:57 dhcpcd: eth2: sending DHCP_REQUEST (xid 0xae806b1), next in 3.89 seconds
20:58:01 dhcpcd: eth2: sending DHCP_REQUEST (xid 0xae806b1), next in 8.53 seconds
20:58:02 dhcpcd: eth2: acknowledged 92.105.164.116 from 138.187.24.107
20:58:02 dhcpcd: eth2: leased 92.105.164.116 for 28800 seconds

At the end it leases the wrong IP. I am not sure whether this is a
problem with dhcpcd or the dhcp servers (or the modem passing along
the dhcp request to its own dhcp server). I just would like to point
out, that the behaviour differs and it leave the client with an
invalid interface setup.

On second thought I looked at the code and there is a difference
between 4.0.4 and 4.99. After 4.0.4 receives an offer and before it
starts the ARP probing it changes its state to STATE_PROBING and
therefore ignores all following offers. 4.99 does not do this, it stays
in the DHS_DISCOVER state which appears to cause the problem.

regards,
Jean