[workaround] dhcpcd: ipv4_addroute: File exists

orschiro · 2014-04-02 17:23:31

Hi there,

I use netctl + dhcpcd for all my network connections.

netctl 1.6-1
dhcpcd 6.3.2-1

This is really working brilliantly. However, sometimes when I send my laptop into hibernation, on resume I cannot resolve any connection although netctl successfully connected to the network profile.

In these cases the logs report:

Apr 02 12:19:37 thinkpad dhcpcd[7474]: DUID 00:01:00:01:1a:93:69:fe:00:16:ea:ef:90:62
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: IAID ea:ef:90:62
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: rebinding lease of 192.168.178.15
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: NAK: requested address not available from 131.211.14.212
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: message: requested address not available
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: soliciting a DHCP lease
Apr 02 12:19:38 thinkpad dhcpcd[7474]: wls1: offered 145.107.100.177 from 131.211.14.212
Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: leased 145.107.100.177 for 1800 seconds
Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: adding route to 145.107.100.0/23
Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: adding default route via 145.107.100.1
Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: ipv4_addroute: File exists
Apr 02 12:19:44 thinkpad dhcpcd[7474]: forked to background, child pid 7628

I would like to trace this issue further back. Is this a problem of netctl, dhcpcd or systemctl hibernation?

Thanks!

Last edited by orschiro (2014-06-06 07:45:18)

Rexilion · 2014-04-03 05:28:12

It seems that the old default route still exists. Would be nice if you could get an outpuf of

/usr/bin/ip route

before dhcpcd starts. Another method would be to unconditionally delete the default route with a dhcpcd/systemd hook.

orschiro · 2014-04-03 05:40:32

@Rexilion

Thanks. Do you mean next time when the error occurs again?

Now it's working. The output:

~ /usr/bin/ip route
default via 192.168.178.1 dev wls1  metric 302 
192.168.178.0/24 dev wls1  proto kernel  scope link  src 192.168.178.15  metric 302

Another method would be to unconditionally delete the default route with a dhcpcd/systemd hook.

This sounds worth a try. How would I do this? Can you give an example?

Last edited by orschiro (2014-04-03 05:40:41)

Rexilion · 2014-04-03 06:26:08

Here is what I think that happens:

Your current output shows a default route (it starts with 'default'). You suspend and then resume, the line is still there.

First, you switch to another network:

Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: rebinding lease of 192.168.178.15
Apr 02 12:19:37 thinkpad dhcpcd[7474]: wls1: NAK: requested address not available from 131.211.14.212
Apr 02 12:19:38 thinkpad dhcpcd[7474]: wls1: offered 145.107.100.177 from 131.211.14.212
Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: leased 145.107.100.177 for 1800 seconds

And once that is settled, dhcpcd wants to add the default route for the new network:

Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: adding default route via 145.107.100.1

but this fails:

Apr 02 12:19:44 thinkpad dhcpcd[7474]: wls1: ipv4_addroute: File exists

Maybe it happens because you switched network during the suspend/resume cycle?

orschiro · 2014-04-03 06:35:53

Maybe it happens because you switched network during the suspend/resume cycle?

Yes, indeed! Normally I hibernate whilst being connected to my home network. Then I resume at Uni where netctl automatically connects to Eduroam. A pretty normal usecase I would say. That's why I wonder that dhcpcd does not handle this fully.

Rexilion · 2014-04-03 06:44:24

I guess this is a shortcoming of netctl or dhcpcd.

You need to plug a

ip route del default

somewhere.

Dhcpcd has it's hooks stored under /usr/lib/dhcpcd/dhcpcd-hooks/ . There is a manpage here. Well now, the art is to perform this cleanup in your specific case. I suggest you use $reason NAK and act on that:

NAK dhcpcd received a NAK from the DHCP server. This should be
treated as EXPIRE.

Something like:

#!/bin/bash

if [ "$reason" = NAK ]
 then ip route del default
fi

orschiro · 2014-04-03 07:50:31

Thanks!

As you advised, I created an executable file /usr/lib/dhcpcd/dhcpcd-hooks/eduroam-fix with the above content.

I will test the behaviour the next and report if the error vanishes.

orschiro · 2014-04-04 08:57:42

So, I created the following file but I still get the same error message. Any ideas why? Is the naming of the file wrong?

~ cat /usr/lib/dhcpcd/dhcpcd-hooks/30-eduroam-fix 
#!/bin/bash

if [ "$reason" = NAK ]
 then ip route del default
fi

-r--r--r-- 1 root root 66 2014-04-03 13:25:41.654654623 +0200 /usr/lib/dhcpcd/dhcpcd-hooks/30-eduroam-fix

Rexilion · 2014-04-04 14:07:27

Cannot tell from here. What you could do, is create a dummy bash script that outputs all the reasons into a seperate file (with a date stamp) and analyze what is really going on.

Maybe it's not setting reason to NAK (altough that would be odd).

I did not expect this.

orschiro · 2014-04-05 08:22:00

@Rexilion

Thanks I can try that.

Does the script have to be executable? I looked at the other scripts in the directory and they were not.

Is maybe the 30- prefix not suitable?

Rexilion · 2014-04-05 13:41:21

I always have these questions too. What I do is the following: Create a script that outputs it's env (set >> ) into a file into your homedir. Play with dhcpcd and see if the file appears, then you know the script is being executed.

Hell, you could even make it play sound to get an interactive effect. Everytime dhcpcd does something, make it beep or so .

orschiro · 2014-04-08 09:01:34

Alright. I extended my script the following way:

~ cat /usr/lib/dhcpcd/dhcpcd-hooks/30-eduroam-fix 
#!/bin/bash

if [ "$reason" = NAK ] then 
  ip route del default
  touch /home/orschiro/nak-fix-working
fi

But now I receive these errors:

Apr 08 08:30:19 thinkpad dhcpcd[27743]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 08:30:19 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 08:30:19 thinkpad dhcpcd[27743]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 08:30:25 thinkpad dhcpcd[27743]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 08:45:26 thinkpad dhcpcd[27871]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:00:25 thinkpad dhcpcd[27871]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:03:31 thinkpad dhcpcd[1067]: wls1: DHCP lease expired
Apr 08 09:03:31 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:03:41 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:15:25 thinkpad dhcpcd[27871]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:18:41 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:28:32 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2
Apr 08 09:48:41 thinkpad dhcpcd[1067]: wls1: DHCP lease expired
Apr 08 09:48:41 thinkpad dhcpcd[1067]: script_runreason: /usr/lib/dhcpcd/dhcpcd-run-hooks: WEXITSTATUS 2

Rexilion · 2014-04-08 13:01:14

Another thing you always need to do is to check the syntax:

bash -n /usr/lib/dhcpcd/dhcpcd-hooks/30-eduroam-fix

It contains a syntax error (bash error code 2).

orschiro · 2014-04-10 07:24:07

@Rexilion

Stupid error. Thanks for the hint...

Yet dhcpcd continued to hang.

Currently I do not have the time to investigate the issue further. Switching to dhclient resolved the issue for now.

cfr · 2014-06-06 01:33:38

I don't think this should be marked as solved! Maybe '[workaround]' but the issue isn't solved just because you don't have time to further investigate. I have a similar issue and followed the '[soved]' tag...

orschiro · 2014-06-06 07:45:54

@cfr

Sorry, you are absolutely right. I adapted the thread tag.

Arch Linux

#1 2014-04-02 17:23:31

[workaround] dhcpcd: ipv4_addroute: File exists

#2 2014-04-03 05:28:12

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#3 2014-04-03 05:40:32

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#4 2014-04-03 06:26:08

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#5 2014-04-03 06:35:53

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#6 2014-04-03 06:44:24

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#7 2014-04-03 07:50:31

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#8 2014-04-04 08:57:42

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#9 2014-04-04 14:07:27

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#10 2014-04-05 08:22:00

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#11 2014-04-05 13:41:21

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#12 2014-04-08 09:01:34

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#13 2014-04-08 13:01:14

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#14 2014-04-10 07:24:07

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#15 2014-06-06 01:33:38

Re: [workaround] dhcpcd: ipv4_addroute: File exists

#16 2014-06-06 07:45:54

Re: [workaround] dhcpcd: ipv4_addroute: File exists

Board footer