# NetworkManager fails to acquire ip-adress

## Letharion

/var/log/messages from trying to connect to a wlan:

```
21:46:11 NetworkManager[1876]: <info> Activation (wlan0) starting connection 'Auto flygboll'

21:46:11 NetworkManager[1876]: <info> (wlan0): device state change: 3 -> 4 (reason 0)

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...

21:46:11 NetworkManager[1876]: <info> (wlan0): device state change: 4 -> 5 (reason 0)

21:46:11 NetworkManager[1876]: <info> Activation (wlan0/wireless): access point 'Auto flygboll' has security, but secrets are required.

21:46:11 NetworkManager[1876]: <info> (wlan0): device state change: 5 -> 6 (reason 0)

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...

21:46:11 NetworkManager[1876]: <info> (wlan0): device state change: 6 -> 4 (reason 0)

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...

21:46:11 NetworkManager[1876]: <info> (wlan0): device state change: 4 -> 5 (reason 0)

21:46:11 NetworkManager[1876]: <info> Activation (wlan0/wireless): connection 'Auto flygboll' has security, and secrets exist.  No new secrets needed.

21:46:11 NetworkManager[1876]: <info> Config: added 'ssid' value 'flygboll'

21:46:11 NetworkManager[1876]: <info> Config: added 'scan_ssid' value '1'

21:46:11 NetworkManager[1876]: <info> Config: added 'key_mgmt' value 'WPA-PSK'

21:46:11 NetworkManager[1876]: <info> Config: added 'psk' value '<omitted>'

21:46:11 NetworkManager[1876]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.

21:46:11 NetworkManager[1876]: <info> Config: set interface ap_scan to 1

21:46:11 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  disconnected -> scanning

21:46:15 kernel: [  122.965177] wlan0: authenticate with 1c:bd:b9:8f:af:4c

21:46:15 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  scanning -> associating

21:46:15 kernel: [  122.968008] wlan0: send auth to 1c:bd:b9:8f:af:4c (try 1/3)

21:46:15 kernel: [  122.972791] wlan0: authenticated

21:46:15 kernel: [  122.972841] wlan0: associating with AP with corrupt beacon

21:46:15 kernel: [  122.973727] wlan0: associate with 1c:bd:b9:8f:af:4c (try 1/3)

21:46:15 kernel: [  122.977685] wlan0: RX AssocResp from 1c:bd:b9:8f:af:4c (capab=0x431 status=0 aid=2)

21:46:15 kernel: [  122.977696] wlan0: associated

21:46:15 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  associating -> associated

21:46:15 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  associated -> 4-way handshake

21:46:15 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  4-way handshake -> group handshake

21:46:15 dhcpcd[1934]: wlan0: carrier acquired

21:46:15 NetworkManager[1876]: <info> (wlan0): supplicant connection state:  group handshake -> completed

21:46:15 NetworkManager[1876]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'flygboll'.

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...

21:46:15 NetworkManager[1876]: <info> (wlan0): device state change: 5 -> 7 (reason 0)

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)

21:46:15 NetworkManager[1876]: <info> dhcpcd started with pid 2429

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.

21:46:15 dhcpcd[2429]: sending commands to master dhcpcd process

21:46:15 kernel: [  123.191895] wlan0: deauthenticating from 1c:bd:b9:8f:af:4c by local choice (reason=3)

21:46:15 NetworkManager[1876]: <info> (wlan0): DHCPv4 client pid 2429 exited with status 0

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) started...

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Timeout) complete.

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) failed (no IP configuration found)

21:46:15 NetworkManager[1876]: <info> (wlan0): device state change: 7 -> 9 (reason 5)

21:46:15 NetworkManager[1876]: <warn> Activation (wlan0) failed for access point (flygboll)

21:46:15 NetworkManager[1876]: <info> Marking connection 'Auto flygboll' invalid.

21:46:15 NetworkManager[1876]: <warn> Activation (wlan0) failed.

21:46:15 NetworkManager[1876]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.

21:46:15 NetworkManager[1876]: <info> (wlan0): device state change: 9 -> 3 (reason 0)

21:46:15 NetworkManager[1876]: <info> (wlan0): deactivating device (reason: 0).

21:46:15 dhcpcd[1934]: wlan0: not configured to accept IPv6 RAs

21:46:15 dhcpcd[1934]: wlan0: broadcasting for a lease

21:46:15 dhcpcd[1934]: control command: /sbin/dhcpcd -B -K -L -G -c /usr/libexec/nm-dhcp-client.action wlan0

21:46:15 kernel: [  123.224930] cfg80211: Calling CRDA for country: DE

21:46:15 dhcpcd[1934]: wlan0: carrier lost
```

Trying to connect to wired:

```
21:49:42 NetworkManager[1876]: <info> Activation (eth0) starting connection 'System (eth0)'

21:49:42 NetworkManager[1876]: <info> (eth0): device state change: 3 -> 4 (reason 0)

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...

21:49:42 NetworkManager[1876]: <info> (eth0): device state change: 4 -> 5 (reason 0)

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...

21:49:42 NetworkManager[1876]: <info> (eth0): device state change: 5 -> 7 (reason 0)

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)

21:49:42 NetworkManager[1876]: <info> dhcpcd started with pid 2584

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.

21:49:42 dhcpcd[2584]: sending commands to master dhcpcd process

21:49:42 dhcpcd[1934]: control command: /sbin/dhcpcd -B -K -L -G -c /usr/libexec/nm-dhcp-client.action -h eth0

21:49:42 NetworkManager[1876]: <info> (eth0): DHCPv4 client pid 2584 exited with status 0

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) scheduled...

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) started...

21:49:42 NetworkManager[1876]: <info> (eth0): device state change: 7 -> 9 (reason 5)

21:49:42 NetworkManager[1876]: <info> Marking connection 'System (eth0)' invalid.

21:49:42 NetworkManager[1876]: <warn> Activation (eth0) failed.

21:49:42 NetworkManager[1876]: <info> Activation (eth0) Stage 4 of 5 (IP4 Configure Timeout) complete.

21:49:42 NetworkManager[1876]: <info> (eth0): device state change: 9 -> 3 (reason 0)

21:49:42 NetworkManager[1876]: <info> (eth0): deactivating device (reason: 0).

21:49:42 dhcpcd[1934]: eth0: removing IP address 192.168.0.132/24
```

If I disable NM and manually run 

```
dhcpcd eth0
```

, everything works fine. Not sure what I could be missing, as the other systems connected to the same AP get an IP without issues.

----------

## khayyam

letherion ...

The only thing thats stands out from the logs is "corrupt beacon" which can mean your airspace is polluted, or there is an adjunct adhoc network. The first thing I would suggest is extending the timeout for wpa_supplicant, and/or have it connect to BSSID and not ESSID ... not using NetworkManager I can't say if it can be configured to do this, but you might try disabling NetworkManager and using /etc/conf.d/net instead, at least until the problem is resolved.

Also, D-Link AP's have WPS (and AFAIK it can't be disabled) and if/when bruteforcing the WPS pin you will get similar DoS like symptoms, along with 'corrupt beacons'. You say that you can connect via other machines (I assume, simultaniously) so this may be less likely, but perhaps worth keeping in mind. I'm not sure D-Link has released a firmware update that disables WPS, if they've responded like other vendors then the 'fix' will do nothing but delay the attacker getting the PIN, still, you might want to check.

With airodump-ng (net-wireless/aircrack-ng) you can get some idea of what's in your airspace, the channels in use, and what's currently associating. An attacker will need to associate with the AP prior to sending an 'EAPOL-start' so they will be seen to associate, disassociate, etc .. as fast as the AP can handle (or allows) the transaction (typically about 1 PIN per second, or 1 per minute on "patched" AP's ... hahah, yeah, seriously, that'll stop an attack).

You can also see corrupt beacons when the AP is overloaded, needs a reboot, or is simply clapped out ... anyhow, to debug this I would disble NetworkManager, and look and see whats in the neibourhood as this is the most likely culprit, if you happen to be on the same channel as most of the AP's nearby then try and find a channel "between" the most used channels. At the same time you should look for ad-hoc networks, some printers will default to ad-hoc, and many campus networks are configured as 'roaving' ad-hoc.  

Well, hopefully thats of some help ... best

khay

----------

