Re: Possible race condition in acquiring IP address results in no IP address acquired
Roy Marples
Sat Sep 13 22:53:46 2014
Hi
On Friday 12 Sep 2014 12:02:07 Amit Uttamchandani wrote:
> This is the issue that happens:
>
> 1. When the system comes up, no network cable is plugged in.
> - At this point dhcpcd is launched for eth0.
> 2. Plug in network cable 8-10 seconds after system is up.
> - dhcpcd seems like it is still running, seems to acquire an IP and
> then times out.
> + We have a network monitor that detects kernel netlink up/down
> messages. Thus, when link comes up, we try and launch dhcpcd but
> it reports it is already running, so we let it be.
> 3. Thus, no IP address is obtained at all.
>
> Note: All configurations are default.
>
> Syslog from dhcpcd 6.0.5
> ========================
> Sep 12 11:23:52 falcon-UNKNOWN dhcpcd[618]: version 6.0.5 starting
> Sep 12 11:23:53 falcon-UNKNOWN dhcpcd[618]: eth0: waiting for carrier
> Sep 12 11:24:23 falcon-UNKNOWN dhcpcd[618]: timed out
> Sep 12 11:24:23 falcon-UNKNOWN dhcpcd[618]: allowing 8 seconds for IPv4LL
> timeout Sep 12 11:24:29 falcon-UNKNOWN dhcpcd[618]: eth0: carrier acquired
> # This is when our simple network monitor tries to launch dhcpcd with #
> 'dhcpcd eth0'
> Sep 12 11:24:29 falcon-UNKNOWN dhcpcd[1421]: dhcpcd already running on pid
> 618 (/var/run/dhcpcd-eth0.pid) Sep 12 11:24:29 falcon-UNKNOWN dhcpcd[618]:
> eth0: soliciting an IPv6 router Sep 12 11:24:29 falcon-UNKNOWN dhcpcd[618]:
> error writing DUID: /etc/dhcpcd.duid: Read-only file system Sep 12 11:24:29
> falcon-UNKNOWN dhcpcd[618]: eth0: rebinding lease of 192.168.1.178 Sep 12
> 11:24:31 falcon-UNKNOWN dhcpcd[618]: timed out
> Sep 12 11:24:31 falcon-UNKNOWN dhcpcd[618]: exited
>
> Syslog for dhcpcd 6.4.3
> =======================
> Sep 12 11:47:08 falcon-UNKNOWN dhcpcd[650]: version 6.4.3 starting
> Sep 12 11:47:08 falcon-UNKNOWN dhcpcd[650]: eth0: adding address
> fe80::ba2a:8253:babc:7a54 Sep 12 11:47:08 falcon-UNKNOWN dhcpcd[650]: eth0:
> waiting for carrier Sep 12 11:47:37 falcon-UNKNOWN dhcpcd[650]: eth0:
> carrier acquired # This is when our simple network monitor tries to launch
> dhcpcd with # 'dhcpcd eth0'
> Sep 12 11:47:37 falcon-UNKNOWN dhcpcd[1409]: dhcpcd already running on pid
> 650 (/var/run/dhcpcd-eth0.pid) Sep 12 11:47:37 falcon-UNKNOWN dhcpcd[650]:
> error writing DUID: /etc/dhcpcd.duid: Read-only file system Sep 12 11:47:37
> falcon-UNKNOWN dhcpcd[650]: DUID 00:03:00:01:00:1f:f2:08:a7:b0 Sep 12
> 11:47:37 falcon-UNKNOWN dhcpcd[650]: eth0: IAID f2:08:a7:b0 Sep 12 11:47:38
> falcon-UNKNOWN dhcpcd[650]: eth0: soliciting a DHCP lease Sep 12 11:47:38
> falcon-UNKNOWN dhcpcd[650]: timed out
> Sep 12 11:47:38 falcon-UNKNOWN dhcpcd[650]: allowing 8 seconds for IPv4LL
> timeout Sep 12 11:47:38 falcon-UNKNOWN dhcpcd[650]: eth0: soliciting an
> IPv6 router Sep 12 11:47:42 falcon-UNKNOWN dhcpcd[650]: eth0: offered
> 192.168.1.164 from 192.168.1.83 Sep 12 11:47:46 falcon-UNKNOWN dhcpcd[650]:
> timed out
> Sep 12 11:47:46 falcon-UNKNOWN dhcpcd[650]: exited
OK, the timeout you are seeing looks correct from the 1st dhcpcd instance
spawned. You're spawning the 2nd instance which says the 1st one is running
and then the 2nd one exits - it does not affect the 1st instance in any way or
form.
dhcpcd has it's own carrier management, you don't need to spawn a 2nd copy on
carrier up. If you do want to do this, ensure one isn't already running!
Thanks
Roy
Archive administrator: postmaster@marples.name