Arch Linux

Please read this before reporting a bug:
https://wiki.archlinux.org/title/Bug_reporting_guidelines

Do NOT report bugs when a package is just outdated, or it is in the AUR. Use the 'flag out of date' link on the package page, or the Mailing List.

REPEAT: Do NOT report bugs for outdated packages!
Tasklist

FS#36455 - [dhcpcd] cant get an Ip after updating to 6.0.4/6.0.5

Attached to Project: Arch Linux
Opened by Jan Bickel (rosenrot) - Thursday, 08 August 2013, 13:18 GMT
Last edited by Ronald van Haren (pressh) - Friday, 31 January 2014, 14:56 GMT
Task Type Bug Report
Category Packages: Core
Status Closed
Assigned To Ronald van Haren (pressh)
Architecture x86_64
Severity High
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 6
Private No

Details

Description:
I cant access any network after upgrading to 6.0.4 or 6.0.5.
Downgrading to 5.6.8 it is working again.
Im using the Linux-Kernel 3.10.3.


Additional info:
* package versions: 6.0.X (tested with 6.0.4 and 6.0.5)
* log file: http://pastebin.com/XcDES0S0
* intel wifi card
* iwlwifi driver
* Linux kernel: 3.10.X


Steps to reproduce:
Wpa_supplicant connects to a network and after starting dhcpcd it reconnects constantly.
This task depends upon

Closed by  Ronald van Haren (pressh)
Friday, 31 January 2014, 14:56 GMT
Reason for closing:  Fixed
Additional comments about closing:  seems to be fixed by upstream according to the comments
Comment by Dave Reisner (falconindy) - Thursday, 08 August 2013, 13:46 GMT
Please don't link to pastebins, they always expire. Just attach files here.
Comment by Jan Bickel (rosenrot) - Thursday, 08 August 2013, 18:58 GMT
Here it is:

dhcpcd[28734]: version 6.0.4 starting
dhcpcd[28742]: wlan0: starting wpa_supplicant
dhcpcd[28734]: eth0: waiting for carrier
dhcpcd[28734]: wlan0: waiting for carrier
dhcpcd[28734]: wlan0: carrier acquired
dhcpcd[28734]: wlan0: soliciting an IPv6 router
dhcpcd[28734]: wlan0: rebinding lease of 192.168.0.104
dhcpcd[28734]: wlan0: soliciting a DHCP lease
dhcpcd[28734]: wlan0: carrier lost
dhcpcd[28734]: wlan0: carrier acquired
dhcpcd[28734]: wlan0: soliciting an IPv6 router
dhcpcd[28734]: wlan0: rebinding lease of 192.168.0.104
dhcpcd[28734]: wlan0: leased 192.168.0.104 for 86400 seconds
dhcpcd[28734]: wlan0: adding host route to 192.168.0.104 via 127.0.0.1
dhcpcd[28734]: wlan0: adding route to 192.168.0.0/24
dhcpcd[28734]: wlan0: adding default route via 192.168.0.1
dhcpcd[28734]: forked to background, child pid 28849

Successfully initialized wpa_supplicant
wlan0: SME: Trying to authenticate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Trying to associate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Associated with f8:df:a8:33:0e:7f
wlan0: WPA: Key negotiation completed with f8:df:a8:33:0e:7f [PTK=TKIP GTK=TKIP]
wlan0: CTRL-EVENT-CONNECTED - Connection to f8:df:a8:33:0e:7f completed [id=2 id_str=]
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: SME: Trying to authenticate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Trying to associate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Associated with f8:df:a8:33:0e:7f
wlan0: WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
wlan0: WPA: Could not verify EAPOL-Key MIC - dropping packet
wlan0: WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
wlan0: WPA: Could not verify EAPOL-Key MIC - dropping packet
wlan0: Authentication with f8:df:a8:33:0e:7f timed out.
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=2 ssid="VHC" auth_failures=1 duration=10
wlan0: Failed to initiate AP scan
wlan0: Failed to initiate AP scan
wlan0: Failed to initiate AP scan
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: Failed to initiate AP scan
wlan0: Failed to initiate AP scan
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: CTRL-EVENT-SSID-REENABLED id=2 ssid="VHC"
wlan0: SME: Trying to authenticate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Trying to associate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Associated with f8:df:a8:33:0e:7f
wlan0: WPA: Key negotiation completed with f8:df:a8:33:0e:7f [PTK=TKIP GTK=TKIP]
wlan0: CTRL-EVENT-CONNECTED - Connection to f8:df:a8:33:0e:7f completed [id=2 id_str=]
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: SME: Trying to authenticate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Trying to associate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Associated with f8:df:a8:33:0e:7f
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
wlan0: SME: Trying to authenticate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Trying to associate with f8:df:a8:33:0e:7f (SSID='VHC' freq=2452 MHz)
wlan0: Associated with f8:df:a8:33:0e:7f
wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:df:a8:33:0e:7f reason=3 locally_generated=1
dbus: wpas_dbus_bss_signal_prop_changed: Unknown Property value 7
Comment by Dave Reisner (falconindy) - Thursday, 08 August 2013, 19:02 GMT
You're sure you *only* downgraded dhcpcd? wpa_supplicant looks like it's having problems of its own.
Comment by Jan Bickel (rosenrot) - Friday, 09 August 2013, 20:22 GMT
Yes I did not touch wpa_supplicant, neither did I update it recently.
Comment by Jonas (IpsumJ) - Saturday, 10 August 2013, 05:25 GMT
EDIT: After a long night i found the problem at the DHCP Server

>
>I can't get an IP with dhcpcd 6.0.4-1 too:
>
Comment by Freddie Chopin (Freddie Chopin) - Saturday, 10 August 2013, 10:49 GMT
I'm having the same problem... I thought it was related to upgrade from netcft to netctl, but after reinstallation of whole system it turned out to be dhcpcd. I can set network without problem when booting installation CD, but as soon as I boot the installed system it does not work. The install CD has an older version, the system is installed with the most recent. Downgrading on the host solves the issue.

But I'm seeing different messages from the ones above. In here the wpa_supplicant (netctl won't work with new version of dhcpcd) does NOT disconnect and re-connect when dhcpcd is trying to do sth - there are no new messages when I start it at all. When I start dhcpcd it goes like this (more or less, it's hard to copy when using command line only, but I can provide exact logs if needed):
> soliciting IPv6 router
> offered 192.168... from 192.168...
> NaK (NULL) received
and this goes on for a while, before finally hitting timeout and giving up.
Comment by Roy Marples (rsmarples) - Thursday, 29 August 2013, 09:41 GMT
Please do provide an exact log.

It sounds like you're being offered an IP and then when you confirm it, the server NAKs it. So from my perspective dhcpcd is behaving correctly.

NOTE TO MAINTAINERS: dhcpcd-6 now ships with a wpa_supplicant hook script which will start wpa_supplicant per interface if it's wireless and /etc/wpa_supplicant.conf exists.
It will also stop wpa_supplicant IF the interface it's running on departs (like say a USB wifi card).
The goal is that dhcpcd can handle the hotplugging of interfaces entirely because there is no common standard for this between any BSD or Linux (or even different Linux flavours).
Comment by Bug Reporter 35296 (TtTFQN) - Friday, 20 September 2013, 05:31 GMT
I can solve these problem with the following workaround before shutdown:

dhcpcd --release wlan0

--> nexttime it is no problem to get an ip
Comment by Freddie Chopin (Freddie Chopin) - Saturday, 05 October 2013, 06:51 GMT
@up - does this command need to be given before every shutdown or maybe it "solves" the problem permanently?
Comment by Freddie Chopin (Freddie Chopin) - Saturday, 05 October 2013, 08:03 GMT
Ok, the workaroud does not work for me, because in my case the dhcpcd daemon doesn't event start properly after upgrade...

Here's a log of what happens if I try to establish the connection manually. One shell session has wpa_supplicant, in another I try to run dhcpcd.

---

[root@INFERNUS freddie]# dhcpcd wlp6s2
dhcpcd[3371]: version 6.0.5 starting
dhcpcd[3371]: wlp6s2: soliciting an IPv6 router
dhcpcd[3371]: wlp6s2: soliciting a DHCP lease
dhcpcd[3371]: wlp6s2: offered 192.168.2.6 from 192.168.2.1 `TP-LINK'
dhcpcd[3371]: wlp6s2: NAK: (null) from 192.168.2.1 `TP-LINK'
[... it can go on forever ...]
dhcpcd[3371]: wlp6s2: soliciting an IPv6 router
dhcpcd[3371]: wlp6s2: soliciting a DHCP lease
dhcpcd[3371]: wlp6s2: offered 192.168.2.6 from 192.168.2.1 `TP-LINK'
dhcpcd[3371]: wlp6s2: NAK: (null) from 192.168.2.1 `TP-LINK'
dhcpcd[3371]: wlp6s2: soliciting an IPv6 router
dhcpcd[3371]: wlp6s2: soliciting a DHCP lease
^Cdhcpcd[3371]: received SIGINT from PID 0, stopping
dhcpcd[3371]: wlp6s2: removing interface
dhcpcd[3371]: exited
[root@INFERNUS freddie]#

---

If I downgrade to version 5, everything just starts working.
Comment by Roy Marples (rsmarples) - Saturday, 05 October 2013, 11:30 GMT
And you attach a wireshark trace of the bootp (DHCP) transaction please?
Comment by Freddie Chopin (Freddie Chopin) - Saturday, 05 October 2013, 15:13 GMT
Here it is - I hope that it is what you asked for (;

Thx in advance!
Comment by Roy Marples (rsmarples) - Saturday, 05 October 2013, 16:09 GMT
The trace is fine. There is technically nothing wrong with this - dhcpcd sends a discover, the server offers an IP, dhcpcd reqeusts this IP and then the server NAKs it.
So it looks more like an error in the DHCP server.

Can you post a trace from a working dhcpcd please so we can see what options it sends differently.
I'm going to guess it's because dhcpcd-5 defaults to sending no clientid, but dhcpcd-6 sends a clientid based of the DUID + IAID as per RFC 4361
https://tools.ietf.org/html/rfc4361

You could also try editing /etc/dhcpcd.conf and ensuring both clientid and duid are commented out.
Comment by Bug Reporter 35296 (TtTFQN) - Saturday, 26 October 2013, 04:53 GMT
Your workaround seems to help:

After deactivating duid by commenting out in /etc/dhcpcd.conf

# Use the hardware address of the interface for the Client ID.
#clientid
# or
# Use the same DUID + IAID as set in DHCPv6 for DHCPv4 ClientID as per RFC4361.
#duid


It seems that my dhcp problems with AVM Fritzbox are gone.
Comment by Stan Holenda (texoft) - Sunday, 29 December 2013, 01:34 GMT
For me the problem was, that my systemd network service started a wpa_supplicant, which conflicted with another wpa_supplicant started by dhcpcd's hook.

Loading...