[Pkg-utopia-maintainers] Bug#757470: network-manager: after resume from suspend, fails to start dhclient on wired interface
Zack Weinberg
zackw at panix.com
Fri Aug 8 15:13:31 UTC 2014
Package: network-manager
Version: 0.9.10.0-1
Severity: normal
Upon resume from suspend on one particular computer, network-manager fails to
bring up the wired interface, with these error messages in /var/log/daemon.log:
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) starting
connection 'Wired connection 1'
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) scheduled...
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) started...
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): device state change:
disconnected -> prepare (reason 'none') [30 40 0]
Aug 8 10:51:38 othila NetworkManager[716]: <info> NetworkManager state is now
CONNECTING
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) scheduled...
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) complete.
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) starting...
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): device state change:
prepare -> config (reason 'none') [40 50 0]
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) successful.
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) scheduled.
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) complete.
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) started...
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): device state change:
config -> ip-config (reason 'none') [50 70 0]
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Beginning
DHCPv4 transaction (timeout in 45 seconds)
Aug 8 10:51:38 othila NetworkManager[716]: <info> dhclient started with pid
23723
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) complete.
Aug 8 10:51:38 othila dhclient: Internet Systems Consortium DHCP Client 4.3.0
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): DHCPv4 client pid
23723 exited with status -1
Aug 8 10:51:38 othila NetworkManager[716]: <warn> DHCP client died abnormally
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 4 of
5 (IPv4 Configure Timeout) scheduled...
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 4 of
5 (IPv4 Configure Timeout) started...
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): device state change:
ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Aug 8 10:51:38 othila NetworkManager[716]: <info> NetworkManager state is now
DISCONNECTED
Aug 8 10:51:38 othila NetworkManager[716]: <info> Disabling autoconnect for
connection 'Wired connection 1'.
Aug 8 10:51:38 othila NetworkManager[716]: <warn> Activation (eth0) failed for
connection 'Wired connection 1'
Aug 8 10:51:38 othila NetworkManager[716]: <info> Activation (eth0) Stage 4 of
5 (IPv4 Configure Timeout) complete.
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): device state change:
failed -> disconnected (reason 'none') [120 30 0]
Aug 8 10:51:38 othila NetworkManager[716]: <info> (eth0): deactivating device
(reason 'none') [0]
If, as root, I manually invoke 'dhclient eth0', that works fine, and network-
manager notices that the interface has been brought up:
Aug 8 10:52:57 othila dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port
67 interval 8
Aug 8 10:52:57 othila dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Aug 8 10:52:57 othila dhclient: DHCPOFFER from 128.2.142.1
Aug 8 10:52:57 othila dhclient: DHCPACK from 128.2.142.1
Aug 8 10:52:57 othila avahi-daemon[701]: Joining mDNS multicast group on
interface eth0.IPv4 with address 128.2.142.99.
Aug 8 10:52:57 othila avahi-daemon[701]: New relevant interface eth0.IPv4 for
mDNS.
Aug 8 10:52:57 othila avahi-daemon[701]: Registering new address record for
128.2.142.99 on eth0.IPv4.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) starting
connection 'eth0'
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) scheduled...
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) started...
Aug 8 10:52:57 othila NetworkManager[716]: <info> (eth0): device state change:
disconnected -> prepare (reason 'none') [30 40 0]
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) scheduled...
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) complete.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) starting...
Aug 8 10:52:57 othila NetworkManager[716]: <info> (eth0): device state change:
prepare -> config (reason 'none') [40 50 0]
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) successful.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) scheduled.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) complete.
Aug 8 10:52:57 othila dhclient: bound to 128.2.142.99 -- renewal in 211543
seconds.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 5 of
5 (IPv4 Commit) started...
Aug 8 10:52:57 othila NetworkManager[716]: <warn> Could not send ARP for local
address 128.2.142.99: Failed to execute child process "/sbin/arp
ing" (No such file or directory)
Aug 8 10:52:57 othila NetworkManager[716]: <info> (eth0): device state change:
ip-config -> ip-check (reason 'none') [70 80 0]
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0) Stage 5 of
5 (IPv4 Commit) complete.
Aug 8 10:52:57 othila NetworkManager[716]: <info> (eth0): device state change:
ip-check -> secondaries (reason 'none') [80 90 0]
Aug 8 10:52:57 othila NetworkManager[716]: <info> (eth0): device state change:
secondaries -> activated (reason 'none') [90 100 0]
Aug 8 10:52:57 othila NetworkManager[716]: <info> NetworkManager state is now
CONNECTED_LOCAL
Aug 8 10:52:57 othila NetworkManager[716]: <info> NetworkManager state is now
CONNECTED_GLOBAL
Aug 8 10:52:57 othila NetworkManager[716]: <info> Policy set 'eth0' (eth0) as
default for IPv4 routing and DNS.
Aug 8 10:52:57 othila NetworkManager[716]: <info> Activation (eth0)
successful, device activated.
so that looks awfully like n-m is invoking dhclient incorrectly, but I can't
find anything else in the logs to indicate what it did wrong. Note that this
*only* happens on resume from suspend; on a cold boot, it works fine:
Aug 5 13:24:48 othila NetworkManager[763]: <info> (eth0): link connected
Aug 5 13:24:48 othila NetworkManager[763]: <info> (eth0): device state change:
unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Aug 5 13:24:48 othila NetworkManager[763]: <info> Auto-activating connection
'Wired connection 1'.
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) starting
connection 'Wired connection 1'
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) scheduled...
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) started...
Aug 5 13:24:48 othila NetworkManager[763]: <info> (eth0): device state change:
disconnected -> prepare (reason 'none') [30 40 0]
Aug 5 13:24:48 othila NetworkManager[763]: <info> NetworkManager state is now
CONNECTING
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) scheduled...
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) complete.
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) starting...
Aug 5 13:24:48 othila NetworkManager[763]: <info> (eth0): device state change:
prepare -> config (reason 'none') [40 50 0]
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) successful.
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) scheduled.
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 2 of
5 (Device Configure) complete.
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) started...
Aug 5 13:24:48 othila NetworkManager[763]: <info> (eth0): device state change:
config -> ip-config (reason 'none') [50 70 0]
Aug 5 13:24:48 othila NetworkManager[763]: <info> Activation (eth0) Beginning
DHCPv4 transaction (timeout in 45 seconds)
Aug 5 13:24:49 othila NetworkManager[763]: <info> dhclient started with pid
910
Aug 5 13:24:49 othila NetworkManager[763]: <warn> Unable to detect kernel
support for extended IFA_FLAGS. Assume no kernel support.
Aug 5 13:24:49 othila NetworkManager[763]: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) complete.
Aug 5 13:24:49 othila dhclient: Internet Systems Consortium DHCP Client 4.3.0
Aug 5 13:24:49 othila dhclient: Copyright 2004-2014 Internet Systems
Consortium.
Aug 5 13:24:49 othila dhclient: All rights reserved.
Aug 5 13:24:49 othila dhclient: For info, please visit
https://www.isc.org/software/dhcp/
Aug 5 13:24:49 othila dhclient:
Aug 5 13:24:49 othila NetworkManager[763]: Internet Systems Consortium DHCP
Client 4.3.0
Aug 5 13:24:49 othila NetworkManager[763]: Copyright 2004-2014 Internet
Systems Consortium.
Aug 5 13:24:49 othila NetworkManager[763]: All rights reserved.
Aug 5 13:24:49 othila NetworkManager[763]: For info, please visit
https://www.isc.org/software/dhcp/
Aug 5 13:24:49 othila NetworkManager[763]: <info> (eth0): DHCPv4 state changed
nbi -> preinit
Aug 5 13:24:49 othila dhclient: Listening on LPF/eth0/e8:9a:8f:d5:ea:d7
Aug 5 13:24:49 othila dhclient: Sending on LPF/eth0/e8:9a:8f:d5:ea:d7
Aug 5 13:24:49 othila dhclient: Sending on LPF/eth0/e8:9a:8f:d5:ea:d7
Aug 5 13:24:49 othila dhclient: Sending on Socket/fallback
Aug 5 13:24:49 othila dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port
67 interval 7
Aug 5 13:24:49 othila NetworkManager[763]: Listening on
LPF/eth0/e8:9a:8f:d5:ea:d7
Aug 5 13:24:49 othila NetworkManager[763]: Sending on
LPF/eth0/e8:9a:8f:d5:ea:d7
Aug 5 13:24:49 othila NetworkManager[763]: Sending on Socket/fallback
Aug 5 13:24:49 othila NetworkManager[763]: DHCPDISCOVER on eth0 to
255.255.255.255 port 67 interval 7
Aug 5 13:25:19 othila dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port
67 interval 14
Aug 5 13:25:19 othila NetworkManager[763]: DHCPDISCOVER on eth0 to
255.255.255.255 port 67 interval 14
Aug 5 13:25:19 othila dhclient: DHCPREQUEST on eth0 to 255.255.255.255 port 67
Aug 5 13:25:19 othila dhclient: DHCPOFFER from 128.2.142.1
Aug 5 13:25:19 othila NetworkManager[763]: DHCPREQUEST on eth0 to
255.255.255.255 port 67
Aug 5 13:25:19 othila NetworkManager[763]: DHCPOFFER from 128.2.142.1
Aug 5 13:25:19 othila dhclient: DHCPACK from 128.2.142.1
Aug 5 13:25:19 othila NetworkManager[763]: DHCPACK from 128.2.142.1
Aug 5 13:25:19 othila dhclient: bound to 128.2.142.99 -- renewal in 213442
seconds.
Aug 5 13:25:19 othila NetworkManager[763]: <info> (eth0): DHCPv4 state changed
preinit -> bound
Aug 5 13:25:19 othila NetworkManager[763]: <info> address 128.2.142.99
Aug 5 13:25:19 othila NetworkManager[763]: <info> plen 24 (255.255.255.0)
Aug 5 13:25:19 othila NetworkManager[763]: <info> gateway 128.2.142.1
Aug 5 13:25:19 othila NetworkManager[763]: <info> server identifier
128.2.136.32
Aug 5 13:25:19 othila NetworkManager[763]: <info> lease time 432000
Aug 5 13:25:19 othila NetworkManager[763]: <info> hostname
'othila.ece.cmu.edu'
Aug 5 13:25:19 othila NetworkManager[763]: <info> nameserver '128.2.136.10'
Aug 5 13:25:19 othila NetworkManager[763]: <info> nameserver '128.2.136.71'
Aug 5 13:25:19 othila NetworkManager[763]: <info> nameserver '128.2.129.21'
Aug 5 13:25:19 othila NetworkManager[763]: <info> domain name 'ece.cmu.edu'
Aug 5 13:25:19 othila NetworkManager[763]: <info> Activation (eth0) Stage 5 of
5 (IPv4 Configure Commit) scheduled...
Aug 5 13:25:19 othila NetworkManager[763]: <info> Activation (eth0) Stage 5 of
5 (IPv4 Commit) started...
Aug 5 13:25:19 othila avahi-daemon[721]: Joining mDNS multicast group on
interface eth0.IPv4 with address 128.2.142.99.
Aug 5 13:25:19 othila avahi-daemon[721]: New relevant interface eth0.IPv4 for
mDNS.
Aug 5 13:25:19 othila avahi-daemon[721]: Registering new address record for
128.2.142.99 on eth0.IPv4.
Aug 5 13:25:19 othila NetworkManager[763]: <info> (eth0): device state change:
ip-config -> ip-check (reason 'none') [70 80 0]
Aug 5 13:25:19 othila NetworkManager[763]: <info> Activation (eth0) Stage 5 of
5 (IPv4 Commit) complete.
Aug 5 13:25:19 othila NetworkManager[763]: <info> (eth0): device state change:
ip-check -> secondaries (reason 'none') [80 90 0]
Aug 5 13:25:19 othila NetworkManager[763]: bound to 128.2.142.99 -- renewal in
213442 seconds.
Aug 5 13:25:19 othila NetworkManager[763]: <info> (eth0): device state change:
secondaries -> activated (reason 'none') [90 100 0]
Aug 5 13:25:19 othila NetworkManager[763]: <info> NetworkManager state is now
CONNECTED_LOCAL
Aug 5 13:25:19 othila NetworkManager[763]: <info> NetworkManager state is now
CONNECTED_GLOBAL
Aug 5 13:25:19 othila NetworkManager[763]: <info> Policy set 'Wired connection
1' (eth0) as default for IPv4 routing and DNS.
Aug 5 13:25:19 othila NetworkManager[763]: <info> Activation (eth0)
successful, device activated.
Aug 5 13:25:19 othila NetworkManager[763]: <info> startup complete
-- System Information:
Debian Release: jessie/sid
APT prefers unstable
APT policy: (500, 'unstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 3.14-2-amd64 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages network-manager depends on:
ii adduser 3.113+nmu3
ii dbus 1.8.6-1
ii init-system-helpers 1.20
ii isc-dhcp-client 4.3.0+dfsg-2
ii libc6 2.19-7
ii libdbus-1-3 1.8.6-1
ii libdbus-glib-1-2 0.102-1
ii libgcrypt11 1.5.3-5
ii libglib2.0-0 2.40.0-3
ii libgnutls-deb0-28 3.2.16-1
ii libgudev-1.0-0 208-7
ii libmm-glib0 1.2.0-1
ii libndp0 1.4-1
ii libnewt0.52 0.52.17-1
ii libnl-3-200 3.2.24-2
ii libnl-genl-3-200 3.2.24-2
ii libnl-route-3-200 3.2.24-2
ii libnm-glib4 0.9.10.0-1
ii libnm-util2 0.9.10.0-1
ii libpam-systemd 208-7
ii libpolkit-gobject-1-0 0.105-6.1
ii libreadline6 6.3-8
ii libsoup2.4-1 2.46.0-2
ii libsystemd-daemon0 208-7
ii libsystemd-login0 208-7
ii libuuid1 2.20.1-5.8
ii lsb-base 4.1+Debian13
ii policykit-1 0.105-6.1
ii udev 208-7
ii wpasupplicant 1.1-1
Versions of packages network-manager recommends:
ii crda 1.1.2-1
ii dnsmasq-base 2.71-1
ii iptables 1.4.21-2
ii modemmanager 1.2.0-1
ii ppp 2.4.6-2
Versions of packages network-manager suggests:
pn avahi-autoipd <none>
-- Configuration Files:
/etc/NetworkManager/NetworkManager.conf changed:
[main]
plugins=ifupdown,keyfile
no-auto-default=E8:9A:8F:D5:EA:D7,
[ifupdown]
managed=false
-- no debconf information
More information about the Pkg-utopia-maintainers
mailing list