Arch Linux

meunierd

Member

Registered: 2013-02-10

Posts: 10

Unable to connect via NetworkManager (ip-config-unavailable, DHCPv4)

From journalctl

Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Auto-activating connection 'Friday'.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) starting connection 'Friday'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) started...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) scheduled...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) complete.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) starting...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: prepare -> config (reason 'none') [40 50 0]
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0/wireless): access point 'Friday' has security, but secrets are required.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: config -> need-auth (reason 'none') [50 60 0]
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) complete.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) scheduled...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) started...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) scheduled...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 1 of 5 (Device Prepare) complete.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) starting...
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: prepare -> config (reason 'none') [40 50 0]
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0/wireless): connection 'Friday' has security, and secrets exist.  No new secrets needed
.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: added 'ssid' value 'Friday'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: added 'scan_ssid' value '1'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: added 'auth_alg' value 'OPEN'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: added 'psk' value '<omitted>'
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 2 of 5 (Device Configure) complete.
Apr 03 11:23:17 innsmouth NetworkManager[195]: <info> Config: set interface ap_scan to 1
Apr 03 11:23:18 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: disconnected -> authenticating
Apr 03 11:23:18 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: authenticating -> associating
Apr 03 11:23:18 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: associating -> associated
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: associated -> 4-way handshake
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: 4-way handshake -> completed
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network '
Friday'.
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 3 of 5 (IP Configure Start) started...
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: config -> ip-config (reason 'none') [50 70 0]
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> dhclient started with pid 4939
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Beginning IP6 addrconf.
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 3 of 5 (IP Configure Start) complete.
Apr 03 11:23:19 innsmouth dhclient[4939]: Internet Systems Consortium DHCP Client 4.3.0
Apr 03 11:23:19 innsmouth dhclient[4939]: Copyright 2004-2014 Internet Systems Consortium.
Apr 03 11:23:19 innsmouth dhclient[4939]: All rights reserved.
Apr 03 11:23:19 innsmouth dhclient[4939]: For info, please visit https://www.isc.org/software/dhcp/
Apr 03 11:23:19 innsmouth dhclient[4939]: 
Apr 03 11:23:19 innsmouth NetworkManager[195]: <info> (wlp3s0): DHCPv4 state changed nbi -> preinit
Apr 03 11:23:19 innsmouth dhclient[4939]: Listening on LPF/wlp3s0/8c:70:5a:c8:e8:b0
Apr 03 11:23:19 innsmouth dhclient[4939]: Sending on   LPF/wlp3s0/8c:70:5a:c8:e8:b0
Apr 03 11:23:19 innsmouth dhclient[4939]: Sending on   Socket/fallback
Apr 03 11:23:19 innsmouth dhclient[4939]: DHCPDISCOVER on wlp3s0 to 255.255.255.255 port 67 interval 4
Apr 03 11:23:23 innsmouth dhclient[4939]: DHCPDISCOVER on wlp3s0 to 255.255.255.255 port 67 interval 7
Apr 03 11:23:30 innsmouth dhclient[4939]: DHCPDISCOVER on wlp3s0 to 255.255.255.255 port 67 interval 10
Apr 03 11:23:39 innsmouth NetworkManager[195]: <info> (wlp3s0): IP6 addrconf timed out or failed.
Apr 03 11:23:39 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Apr 03 11:23:39 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv6 Configure Timeout) started...
Apr 03 11:23:39 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Apr 03 11:23:40 innsmouth dhclient[4939]: DHCPDISCOVER on wlp3s0 to 255.255.255.255 port 67 interval 15
Apr 03 11:23:55 innsmouth dhclient[4939]: DHCPDISCOVER on wlp3s0 to 255.255.255.255 port 67 interval 19
Apr 03 11:24:04 innsmouth NetworkManager[195]: <warn> (wlp3s0): DHCPv4 request timed out.
Apr 03 11:24:04 innsmouth dhclient[4939]: Received signal 15, initiating shutdown.
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> (wlp3s0): canceled DHCP transaction, DHCP client pid 4939
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv4 Configure Timeout) started...
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Apr 03 11:24:04 innsmouth NetworkManager[195]: <warn> Activation (wlp3s0) failed for connection 'Friday'
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> Activation (wlp3s0) Stage 4 of 5 (IPv4 Configure Timeout) complete.
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> (wlp3s0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> (wlp3s0): deactivating device (reason 'none') [0]
Apr 03 11:24:04 innsmouth NetworkManager[195]: <warn> Connection disconnected (reason -3)
Apr 03 11:24:04 innsmouth NetworkManager[195]: <info> (wlp3s0): supplicant interface state: completed -> disconnected
Apr 03 11:24:04 innsmouth NetworkManager[195]: <warn> Connection disconnected (reason -3)

So the red flags to me are `ip-config-unavailable` and `Connection disconnected (reason -3)` but I'm really unsure as to how to troubleshoot this.

From dmesg:

[ 1058.468638] wlp3s0: authenticate with ac:22:0b:ce:89:84
[ 1058.472871] wlp3s0: send auth to ac:22:0b:ce:89:84 (try 1/3)
[ 1058.499920] wlp3s0: authenticated
[ 1058.503601] wlp3s0: associate with ac:22:0b:ce:89:84 (try 1/3)
[ 1058.504585] wlp3s0: RX AssocResp from ac:22:0b:ce:89:84 (capab=0x11 status=0 aid=15)
[ 1058.523129] wlp3s0: associated
[ 1105.486542] wlp3s0: deauthenticating from ac:22:0b:ce:89:84 by local choice (reason=3)

Any advice would be much appreciated!

MadTux

Member

Registered: 2009-09-20

Posts: 553

Re: Unable to connect via NetworkManager (ip-config-unavailable, DHCPv4)

I guess some more information would be helpful. Is this a fresh setup? If not, did it work in the past and when did the problems start? From what I see from the log is that it is getting a timeout in IPv4 and then closes the connection and attempts to reconnect. This could, for example, be a problem with signal strength. But since I know nothing about your environment, its difficult to diagnose.

atertillic

Member

Registered: 2014-01-13

Posts: 7

Re: Unable to connect via NetworkManager (ip-config-unavailable, DHCPv4)

I have the same problem with my lan device. It occurs almost every time I connect the cable, reboot doesn't help. I have to disable the device and replug the cable several times (sometimes minutes) until it connects.
After a successful connection NetworkManager works fine. Reboots / reconnections are no problem as long as I don't touch the cable.

Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: config -> ip-config (reason 'none') [50 70 0]
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Beginning DHCPv4 transaction (timeout in 45 seconds)
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> dhcpcd started with pid 2184
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Beginning IP6 addrconf.
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 3 of 5 (IP Configure Start) complete.
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) scheduled...
Apr  7 11:51:10 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) started...
Apr  7 11:51:10 tuxedo dhcpcd[2184]: version 6.3.2 starting
Apr  7 11:51:10 tuxedo dhcpcd[2184]: DUID 00:01:00:01:1a:6a:e9:79:00:90:f5:ef:6b:69
Apr  7 11:51:10 tuxedo dhcpcd[2184]: enp0s25: IAID f5:ef:6b:69
Apr  7 11:51:10 tuxedo dhcpcd[2184]: enp0s25: soliciting an IPv6 router
Apr  7 11:51:10 tuxedo dhcpcd[2184]: enp0s25: soliciting a DHCP lease
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) complete.
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> (enp0s25): DHCPv4 state changed nbi -> preinit
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: secondaries -> activated (reason 'none') [90 100 0]
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> NetworkManager state is now CONNECTED_GLOBAL
Apr  7 11:51:11 tuxedo NetworkManager[354]: <info> Activation (enp0s25) successful, device activated.
Apr  7 11:51:22 tuxedo dhcpcd[2184]: enp0s25: no IPv6 Routers available
Apr  7 11:51:40 tuxedo dhcpcd[2184]: exited
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> (enp0s25): DHCPv4 client pid 2184 exited with status 1
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 4 of 5 (IPv4 Configure Timeout) started...
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: activated -> failed (reason 'ip-config-unavailable') [100 120 5]
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> NetworkManager state is now DISCONNECTED
Apr  7 11:51:40 tuxedo NetworkManager[354]: <warn> Activation (enp0s25) failed for connection 'LAN'
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 4 of 5 (IPv4 Configure Timeout) complete.
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: failed -> disconnected (reason 'none') [120 30 0]
Apr  7 11:51:40 tuxedo NetworkManager[354]: <info> (enp0s25): deactivating device (reason 'none') [0]
Apr  7 11:51:40 tuxedo dbus[371]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr  7 11:51:40 tuxedo systemd[1]: Starting Network Manager Script Dispatcher Service...
Apr  7 11:51:40 tuxedo dbus[371]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr  7 11:51:40 tuxedo systemd[1]: Started Network Manager Script Dispatcher Service.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Auto-activating connection 'LAN'.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) starting connection 'LAN'
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> NetworkManager state is now CONNECTING
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 1 of 5 (Device Prepare) scheduled...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 1 of 5 (Device Prepare) started...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 2 of 5 (Device Configure) scheduled...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 1 of 5 (Device Prepare) complete.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 2 of 5 (Device Configure) starting...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: prepare -> config (reason 'none') [40 50 0]
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 2 of 5 (Device Configure) successful.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 3 of 5 (IP Configure Start) scheduled.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 2 of 5 (Device Configure) complete.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 3 of 5 (IP Configure Start) started...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: config -> ip-config (reason 'none') [50 70 0]
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Beginning DHCPv4 transaction (timeout in 45 seconds)
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> dhcpcd started with pid 2205
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Beginning IP6 addrconf.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 3 of 5 (IP Configure Start) complete.
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) scheduled...
Apr  7 11:51:43 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) started...
Apr  7 11:51:43 tuxedo dhcpcd[2205]: version 6.3.2 starting
Apr  7 11:51:43 tuxedo dhcpcd[2205]: DUID 00:01:00:01:1a:6a:e9:79:00:90:f5:ef:6b:69
Apr  7 11:51:43 tuxedo dhcpcd[2205]: enp0s25: IAID f5:ef:6b:69
Apr  7 11:51:43 tuxedo dhcpcd[2205]: enp0s25: soliciting an IPv6 router
Apr  7 11:51:43 tuxedo dhcpcd[2205]: enp0s25: soliciting a DHCP lease
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> Activation (enp0s25) Stage 5 of 5 (IPv6 Commit) complete.
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> (enp0s25): DHCPv4 state changed nbi -> preinit
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> (enp0s25): device state change: secondaries -> activated (reason 'none') [90 100 0]
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> NetworkManager state is now CONNECTED_GLOBAL
Apr  7 11:51:44 tuxedo NetworkManager[354]: <info> Activation (enp0s25) successful, device activated.

Disabling ipv6 doesn't help. The cable works fine with other notebooks. I disabled all other network services. (NM normally starts dhcpcd to establish a connection, right now I also have dhcpcd enabled as service, same results..)
any ideas what could be the cause for this..?

Jauch

Member

From: Portugal

Registered: 2010-12-14

Posts: 57

Re: Unable to connect via NetworkManager (ip-config-unavailable, DHCPv4)

I'm having the same problem to connect from wired or wireless, wqith the same messages... Someone got a solution?
I'm a little lost here... lol

EDIT

I saw somewhere (or here...) to set IPV6 to local, only, and it make everything work again.
Someone could be kind and explain what this means? rs

Thanks!

Last edited by Jauch (2014-05-24 14:08:10)

n29xm

Member

Registered: 2017-02-11

Posts: 18

Re: Unable to connect via NetworkManager (ip-config-unavailable, DHCPv4)

Although the above solution does let me connect to my router with a wired connection, i still wasn't able to gain internet access. Installing dhclient solved my problem.

sudo pacman -S dhclient