dhcpcd-discuss

Hi Michel

On 26/01/2015 12:48, Michel, Matthias wrote:
> I have sometimes an unexpected behavior after start
> /etc/init.d/networking restart.
>  
> First output after restart without a running dhcp server in the network

...

> When I than restart the network with a dhcp server inside the network I
> got sometimes this unexpected behavior:
>  
> root@dxr2:~# /etc/init.d/networking restart
> Reconfiguring network interfaces...
> Deconfiguring network interfaces... dhcpcd[1838]: sending signal ARLM to
> pid 1793
> dhcpcd[1838]: waiting for pid 1793 to exit
> done.
> Configuring network interfaces... use hw-init-network
>  
> Configuring bridge sys1...
> bridge sys1 already exists
> Configuring bridge sys1... done.
> dhcpcd[1905]: version 6.6.1 starting
> dhcpcd[1905]: sys1: executing `/usr/libexec/dhcpcd-run-hooks' PREINIT
> dhcpcd[1905]: sys1: executing `/usr/libexec/dhcpcd-run-hooks' CARRIER
> dhcpcd[1905]: DUID 00:01:00:01:c7:92:bc:8f:d6:96:42:ed:5a:dd
> dhcpcd[1905]: sys1: IAID 42:ed:5a:dd
> dhcpcd[1905]: sys1: delaying IPv6 router solicitation for 0.6 seconds
> dhcpcd[1905]: sys1: delaying IPv4 for 1.0 seconds
> dhcpcd[1905]: sys1: soliciting an IPv6 router
> dhcpcd[1905]: sys1: delaying Router Solicitation for LL address
> dhcpcd[1905]: sys1: using hwaddr d6:96:42:ed:5a:dd
> dhcpcd[1905]: sys1: soliciting a DHCP lease
> dhcpcd[1905]: sys1: sending DISCOVER (xid 0x8bce5991), next in 4.9 seconds
> dhcpcd[1905]: sys1: sending Router Solicitation
> dhcpcd[1905]: sys1: xid 0x8c0cfa86 is for hwaddr
> d6:96:42:ed:5a:df:00:00:00:00:00:00:00:00:00:00
> dhcpcd[1905]: sys1: sending Router Solicitation
> dhcpcd[1905]: sys1: sending DISCOVER (xid 0x8bce5991), next in 8.4 seconds
> dhcpcd[1905]: sys1: probing for an IPv4LL address
> dhcpcd[1905]: sys1: probing for 169.254.119.27
> dhcpcd[1905]: sys1: sending ARP probe (1 of 3), next in 1.1 seconds
> dhcpcd[1905]: sys1: offered 192.168.251.187 from 192.168.251.99 `'
> dhcpcd[1905]: sys1: sending REQUEST (xid 0x8bce5991), next in 3.3 seconds
> dhcpcd[1905]: sys1: acknowledged 192.168.251.187 from 192.168.251.99 `'
> dhcpcd[1905]: sys1: probing for 192.168.251.187
> dhcpcd[1905]: sys1: sending ARP probe (1 of 3), next in 1.5 seconds
> dhcpcd[1905]: sys1: sending ARP probe (2 of 3), next in 1.3 seconds
> dhcpcd[1905]: sys1: sending ARP probe (2 of 3), next in 1.7 seconds
> dhcpcd[1905]: sys1: sending ARP probe (3 of 3), next in 2.0 seconds
> dhcpcd[1905]: sys1: sending Router Solicitation
> dhcpcd[1905]: sys1: sending ARP probe (3 of 3), next in 2.0 seconds
> dhcpcd[1905]: sys1: using IPv4LL address 169.254.119.27
> dhcpcd[1905]: sys1: writing lease `/var/db/dhcpcd-sys1.lease'
> dhcpcd[1905]: sys1: adding IP address 169.254.119.27/16
> dhcpcd[1905]: sys1: adding route to 169.254.0.0/16
> dhcpcd[1905]: sys1: executing `/usr/libexec/dhcpcd-run-hooks' IPV4LL
> dhcpcd[1905]: forking to background
> dhcpcd[1905]: forked to background, child pid 1918
> done.
> Reconfiguring done.
>  
> This behavior is not the same as in older versions of dhcpcd.
> What I have done and it seem that I got the same old behavior
> I undo this patch from your source code.

What behaviour do you expect? This output looks fine to me.
One of the new features in dhcpcd is multiple ARP states, so we can
probe the network for IPv4LL and DHCP at the same time. This is what you
are seeing.
In this instance, IPv4LL "won" by virtue of finishing first, but if you
examine your logs you will the find that the DHCP lease takes over.

> --- dhcpcd-6.6.1/ipv4ll.c-orig  2014-10-29 01:53:02.000000000 +0100
> +++ dhcpcd-6.6.1/ipv4ll.c       2014-11-07 12:04:29.186406539 +0100
> @@ -106,17 +106,19 @@
> {
>          struct dhcp_state *state = D_STATE(astate->iface);
>          struct dhcp_message *offer;
>  
> -       /* A DHCP lease could have already been offered.
> -        * Backup this lease and replace once the IPv4LL addres is bound */
> -       offer = state->offer;
> -       state->offer = ipv4ll_make_lease(astate->addr.s_addr);
> -       if (state->offer == NULL)
> -               syslog(LOG_ERR, "%s: %m", __func__);
> -       else
> -               dhcp_bind(astate->iface, astate);
> -       state->offer = offer;
> +       if (state->state != DHS_BOUND) {
> +               /* A DHCP lease could have already been offered.
> +                * Backup and replace once the IPv4LL addres is bound */
> +               offer = state->offer;
> +               state->offer = ipv4ll_make_lease(astate->addr.s_addr);
> +               if (state->offer == NULL)
> +                       syslog(LOG_ERR, "%s: %m", __func__);
> +               else
> +                       dhcp_bind(astate->iface, astate);
> +               state->offer = offer;
> +       }
> }
>  
> So please help me to understand the following code line
>         if (state->state != DHS_BOUND)
>  
> Because without this if statement I got the behavior I expect.
> Did I miss something? Or why did you add this line of code?

It's a good question!
Here's the commit comment:
	Add a guard to IPv4LL probed in case of an ARP race.

So, in your prior code output, IPv4LL "won". This guard is for when DHCP
"wins" and a IPv4LL probe will finish immediately afterwards. This
ensures that IPv4LL will never override DHCP.


Thanks

Roy