dhcpcd-discuss

On 05/17/2018 08:20 AM, Roy Marples wrote:
> On 17/05/2018 01:55, Moritz Warning wrote:
>> On 05/16/2018 09:37 PM, Roy Marples wrote:
>>> On 16/05/2018 17:01, Moritz Warning wrote:
>>>> On 05/16/2018 10:28 AM, Roy Marples wrote:
>>>>> Hi Moritz
>>>>>
>>>>> On 15/05/2018 23:37, Moritz Warning wrote:
>>>>>> from dhcpcd 7.0.4-1 on Arch Linux gives me "dhcp6_listen: Address already in use" and exits.
>>>>>> The problem appears when connecting to my WLAN using wicd 1.7.4-1:
>>>>>>
>>>
>>>
>>>>>> May 15 23:26:22 brick dhcpcd[18975]: forked to background, child pid 19022
>>>>>> May 15 23:26:22 brick dhcpcd[18975]: dhcp6_listen: Address already in use
>>>
>>> Attached patch should solve this error.
>>>
>>>>>> May 15 23:26:22 brick dhcpcd[19025]: sending signal ALRM to pid 19022
>>>>>> May 15 23:26:22 brick dhcpcd[19025]: waiting for pid 19022 to exit
>>>>>> May 15 23:26:22 brick dhcpcd[19022]: received SIGALRM, releasing
>>>
>>> Something called `dhcpcd -k` here which releases the lease as you see.
>>> I think that is the real error - does wicd do that?
>> Yes, wicd calls "dhcpcd -k" when it detects no ip address on the specified interface.
>>
>>>
>>> Can you let me know if the patch addresses the listen error please?
>>>
>>> Thanks
>>>
>>> Roy
>>
>> The error still appears.
> 
> That is odd.
> Try this new patch which logs a lot more, if you post a new log it should say which address is failing.
> 
>> But the connection also fails sometimes when the error is not showing up.
>> It is that way even without the patch. So it might not be the cause.
>>
>> Is this "sending signal ALRM to pid 19022" part of the shutdown sequence of dhcpcd?
> 
> Yes. because dhcpcd itself logged sending signal on a different pid, it's clear something called `dhcpcd -k` to shut it down. This is likely wicd and likely because dhcpcd forked when getting a working IPv6 address an wicd expects a working IPv4 address.
> 
> Try adding `waitip 4` to /etc/dhcpcd.conf
> 
> Roy

The patch revealed some interesting info:
May 17 19:53:19 brick dhcpcd[12604]: LISTENING TO fdbc:652b:8f56:0:75f0:740c:fdf8:84e4/64
May 17 19:53:19 brick dhcpcd[12598]: LISTENING TO fdbc:652b:8f56:0:75f0:740c:fdf8:84e4/64
May 17 19:53:19 brick dhcpcd[12598]: dhcp6_listen: Address already in use

Anyway, "waitip 4" in /etc/dhcpcd.conf also make the problem disappear.

Does dhcpcd signal wicd as soon an IP address (IPv6 in this case), has been received/set?

May 17 01:05:38 xanax wicd[9979]: dhcpcd not running
May 17 01:05:38 xanax dhcpcd[18576]: dhcpcd not running
May 17 01:05:38 xanax kernel: IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready
May 17 01:05:38 xanax kernel: IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready
May 17 01:05:38 xanax wicd[9979]: Failed to connect to non-global ctrl_ifname: wlp58s0  error: No such file or directory
May 17 01:05:39 xanax wicd[9979]: dhcpcd not running
May 17 01:05:39 xanax dhcpcd[18610]: dhcpcd not running
May 17 01:05:39 xanax kernel: IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready
May 17 01:05:39 xanax wicd[9979]: Failed to connect to non-global ctrl_ifname: wlp58s0  error: No such file or directory
May 17 01:05:39 xanax wicd[9979]: Error for wireless request "Set Bit Rate" (8B20) :
May 17 01:05:39 xanax wicd[9979]:     SET failed on device %s ; No such device.
May 17 01:05:41 xanax kernel: brcmfmac: brcmf_cfg80211_scan: Connecting: status (3)
May 17 01:05:41 xanax kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp58s0: link becomes ready
May 17 01:05:42 xanax dhcpcd[18666]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:42 xanax dhcpcd[18666]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:42 xanax dhcpcd[18666]: DUID 00:01:00:01:22:8f:74:2f:c8:ff:28:77:db:cb
May 17 01:05:42 xanax dhcpcd[18666]: wlp58s0: IAID 28:77:db:cb
May 17 01:05:42 xanax dhcpcd[18666]: wlp58s0: adding address fe80::6f97:9f29:38c0:9c7
May 17 01:05:43 xanax dhcpcd[18666]: wlp58s0: soliciting an IPv6 router
May 17 01:05:43 xanax dhcpcd[18666]: wlp58s0: rebinding lease of 172.16.0.115
May 17 01:05:43 xanax dhcpcd[18666]: wlp58s0: probing address 172.16.0.115/16
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: Router Advertisement from fe80::6666:b3ff:fe50:1230
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: adding address fdbc:652b:8f56:0:75f0:740c:fdf8:84e4/64
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: adding route to fdbc:652b:8f56::/64
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: soliciting a DHCPv6 lease
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: ADV fdbc:652b:8f56::a6f/128 from fe80::6666:b3ff:fe50:1230
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: accepted reconfigure key
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: REPLY6 received from fe80::6666:b3ff:fe50:1230
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: adding address fdbc:652b:8f56::a6f/128
May 17 01:05:44 xanax dhcpcd[18666]: wlp58s0: renew in 21600, rebind in 34560, expire in 4294967295 seconds
May 17 01:05:46 xanax dhcpcd[18666]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:46 xanax dhcpcd[18666]: forked to background, child pid 19048
May 17 01:05:46 xanax wicd[9979]: sending signal ALRM to pid 19048
May 17 01:05:46 xanax wicd[9979]: waiting for pid 19048 to exit
May 17 01:05:46 xanax dhcpcd[19051]: sending signal ALRM to pid 19048
May 17 01:05:46 xanax dhcpcd[19051]: waiting for pid 19048 to exit
May 17 01:05:46 xanax dhcpcd[19048]: received SIGALRM, releasing
May 17 01:05:46 xanax dhcpcd[19048]: wlp58s0: removing interface
May 17 01:05:46 xanax dhcpcd[19048]: wlp58s0: deleting address fdbc:652b:8f56::a6f/128
May 17 01:05:46 xanax dhcpcd[19048]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:46 xanax dhcpcd[19048]: wlp58s0: deleting address fdbc:652b:8f56:0:75f0:740c:fdf8:84e4/64
May 17 01:05:46 xanax dhcpcd[19048]: wlp58s0: deleting route to fdbc:652b:8f56::/64
May 17 01:05:46 xanax dhcpcd[19048]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:46 xanax dhcpcd[19048]: wlp58s0: deleting address fe80::6f97:9f29:38c0:9c7
May 17 01:05:46 xanax dhcpcd[19048]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:46 xanax dhcpcd[19048]: script_runreason: /libexec/dhcpcd-run-hooks: No such file or directory
May 17 01:05:46 xanax dhcpcd[19048]: dhcpcd exited
May 17 01:05:47 xanax kernel: IPv6: ADDRCONF(NETDEV_UP): wlp58s0: link is not ready