** Summary changed:
- DHCP transaction took too long, stopping it
+ "DHCP transaction took too long, stopping it"
** Changed in: network-manager (Ubuntu)
Status: New => Incomplete
--
You received this bug notification because you are a member of Desktop
Packages, which is subscribed to network-manager in Ubuntu.
https://bugs.launchpad.net/bugs/583705
Title:
"DHCP transaction took too long, stopping it"
Status in “network-manager” package in Ubuntu:
Incomplete
Bug description:
Binary package hint: network-manager
When doing a cold start for a lucid slave in virtual box, nm doesn't
obtain an IP address and output the following in /var/log/syslog:
May 21 09:50:30 lucid64 NetworkManager: <info> (eth0): DHCP transaction took
too long, stopping it.
May 21 09:50:30 lucid64 NetworkManager: <info> (eth0): canceled DHCP
transaction, dhcp client pid 756
May 21 09:50:30 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Timeout) scheduled...
May 21 09:50:30 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Timeout) started...
May 21 09:50:30 lucid64 NetworkManager: <info> (eth0): device state change:
7 -> 9 (reason 5)
May 21 09:50:30 lucid64 NetworkManager: <info> Marking connection 'Auto
eth0' invalid.
May 21 09:50:30 lucid64 NetworkManager: <info> Activation (eth0) failed.
May 21 09:50:30 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Timeout) complete.
May 21 09:50:30 lucid64 NetworkManager: <info> (eth0): device state change:
9 -> 3 (reason 0)
May 21 09:50:30 lucid64 NetworkManager: <info> (eth0): deactivating device
(reason: 0).
If I select the 'Auto eth0' in the nm-applet menu it succeeds with:
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) starting
connection 'Auto eth0'
May 21 09:54:24 lucid64 NetworkManager: <info> (eth0): device state change:
3 -> 4 (reason 0)
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) scheduled...
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) started...
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 2 of
5 (Device Configure) scheduled...
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 1 of
5 (Device Prepare) complete.
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 2 of
5 (Device Configure) starting...
May 21 09:54:24 lucid64 NetworkManager: <info> (eth0): device state change:
4 -> 5 (reason 0)
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 2 of
5 (Device Configure) successful.
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) scheduled.
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 2 of
5 (Device Configure) complete.
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) started...
May 21 09:54:24 lucid64 NetworkManager: <info> (eth0): device state change:
5 -> 7 (reason 0)
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Beginning
DHCP transaction (timeout in 45 seconds)
May 21 09:54:24 lucid64 NetworkManager: <info> dhclient started with pid 1419
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP6 Configure Get) scheduled...
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 3 of
5 (IP Configure Start) complete.
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP6 Configure Get) started...
May 21 09:54:24 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP6 Configure Get) complete.
May 21 09:54:24 lucid64 dhclient: Internet Systems Consortium DHCP Client
V3.1.3
May 21 09:54:24 lucid64 dhclient: Copyright 2004-2009 Internet Systems
Consortium.
May 21 09:54:24 lucid64 dhclient: All rights reserved.
May 21 09:54:24 lucid64 dhclient: For info, please visit
https://www.isc.org/software/dhcp/
May 21 09:54:24 lucid64 dhclient:
May 21 09:54:24 lucid64 NetworkManager: <info> DHCP: device eth0 state
changed normal exit -> preinit
May 21 09:54:24 lucid64 dhclient: Listening on LPF/eth0/08:00:27:cf:44:62
May 21 09:54:24 lucid64 dhclient: Sending on LPF/eth0/08:00:27:cf:44:62
May 21 09:54:24 lucid64 dhclient: Sending on Socket/fallback
May 21 09:54:27 lucid64 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255
port 67 interval 5
May 21 09:54:27 lucid64 dhclient: DHCPOFFER of 192.168.0.24 from 192.168.0.254
May 21 09:54:27 lucid64 dhclient: DHCPREQUEST of 192.168.0.24 on eth0 to
255.255.255.255 port 67
May 21 09:54:27 lucid64 dhclient: DHCPACK of 192.168.0.24 from 192.168.0.254
May 21 09:54:27 lucid64 dhclient: bound to 192.168.0.24 -- renewal in 350100
seconds.
May 21 09:54:27 lucid64 NetworkManager: <info> DHCP: device eth0 state
changed preinit -> bound
May 21 09:54:27 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Get) scheduled...
May 21 09:54:27 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Get) started...
May 21 09:54:27 lucid64 NetworkManager: <info> address 192.168.0.24
May 21 09:54:27 lucid64 NetworkManager: <info> prefix 24 (255.255.255.0)
May 21 09:54:27 lucid64 NetworkManager: <info> gateway 192.168.0.254
May 21 09:54:27 lucid64 NetworkManager: <info> nameserver '212.27.40.240'
May 21 09:54:27 lucid64 NetworkManager: <info> nameserver '212.27.40.241'
May 21 09:54:27 lucid64 NetworkManager: <info> Activation (eth0) Stage 5 of
5 (IP Configure Commit) scheduled...
May 21 09:54:27 lucid64 NetworkManager: <info> Activation (eth0) Stage 4 of
5 (IP4 Configure Get) complete.
May 21 09:54:27 lucid64 NetworkManager: <info> Activation (eth0) Stage 5 of
5 (IP Configure Commit) started...
May 21 09:54:27 lucid64 avahi-daemon[745]: Joining mDNS multicast group on
interface eth0.IPv4 with address 192.168.0.24.
May 21 09:54:27 lucid64 avahi-daemon[745]: New relevant interface eth0.IPv4
for mDNS.
May 21 09:54:27 lucid64 avahi-daemon[745]: Registering new address record for
192.168.0.24 on eth0.IPv4.
May 21 09:54:28 lucid64 NetworkManager: <info> (eth0): device state change:
7 -> 8 (reason 0)
May 21 09:54:28 lucid64 NetworkManager: <info> Policy set 'Auto eth0' (eth0)
as default for routing and DNS.
May 21 09:54:28 lucid64 NetworkManager: <info> Activation (eth0) successful,
device activated.
May 21 09:54:28 lucid64 NetworkManager: <info> Activation (eth0) Stage 5 of
5 (IP Configure Commit) complete.
It also succeeds on reboot.
It also succeds if i do 'dhclient eth0'.
Using wireshark with a display filter for the corresponding MAC
address reveals that the DHCP request is not sent during the first
boot.
How can I debug this further ?
Also, reading the dhclient manpage says that it should fallback to a
previsouly acquired lease, this never occurs.
Is there a way to:
- force a fallback address ?
- make dhclient use a previous lease ?
- make nm retry the dhcp request ?
I attributed this bug to nm as it's the only one producing output in
syslog and I'm unclear about which package is really responsible here.
Finally, this bug is transient, *sometimes* the host get its IP address and I
also encounter the problem with a
karmic vm (but less often). I seem to be able to reproduce the problem more
reliably for a couple of days on lucid though.
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/583705/+subscriptions
--
Mailing list: https://launchpad.net/~desktop-packages
Post to : [email protected]
Unsubscribe : https://launchpad.net/~desktop-packages
More help : https://help.launchpad.net/ListHelp
