Bug 1181477 - wired connection because non-functional until I removed its lease file
Summary: wired connection because non-functional until I removed its lease file
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 21
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1179985 1180398 1181329 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-01-13 09:39 UTC by Kamil Páral
Modified: 2015-01-20 12:27 UTC (History)
6 users (show)

Fixed In Version: NetworkManager-0.9.10.1-1.4.20150115git.fc21
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-01-17 23:58:12 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
GNOME Bugzilla 739482 0 None None None 2019-03-04 20:37:44 UTC

Description Kamil Páral 2015-01-13 09:39:57 UTC
Description of problem:
Yesterday I worked from home, I was connected through wire, everything worked OK. Today I came to work, and my wired connection didn't work, only wifi. After I pressed "Enable" in GNOME system menu, the log said:

Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) starting connection 'Wired connection 1'
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) scheduled...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) started...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  NetworkManager state is now CONNECTING
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) scheduled...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) complete.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) starting...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): device state change: prepare -> config (reason 'none') [40 50 0]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) successful.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 3 of 5 (IP Configure Start) scheduled.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) complete.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 3 of 5 (IP Configure Start) started...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): device state change: config -> ip-config (reason 'none') [50 70 0]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Beginning DHCPv4 transaction (timeout in 45 seconds)
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  dhclient started with pid 5311
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 3 of 5 (IP Configure Start) complete.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): DHCPv4 state changed nbi -> preinit
Jan 13 10:25:01 medusa dhclient[5311]: DHCPREQUEST on em1 to 255.255.255.255 port 67 (xid=0x6e09ba21)
Jan 13 10:25:01 medusa dhclient[5311]: DHCPNAK from 10.34.29.254 (xid=0x6e09ba21)
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): DHCPv4 state changed preinit -> expire
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 4 of 5 (IPv4 Configure Timeout) scheduled...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 4 of 5 (IPv4 Configure Timeout) started...
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): device state change: ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  NetworkManager state is now CONNECTED_LOCAL
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Disabling autoconnect for connection 'Wired connection 1'.
Jan 13 10:25:01 medusa NetworkManager[4291]: <warn>  Activation (em1) failed for connection 'Wired connection 1'
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Activation (em1) Stage 4 of 5 (IPv4 Configure Timeout) complete.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': Name or service not known'.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': Name or service not known'.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': Name or service not known'.
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): device state change: failed -> disconnected (reason 'none') [120 30 0]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): deactivating device (reason 'none') [0]
Jan 13 10:25:01 medusa NetworkManager[4291]: <info>  (em1): canceled DHCP transaction, DHCP client pid 5311
Jan 13 10:25:01 medusa NetworkManager[4291]: <warn>  (pid 5311) unhandled DHCP event for interface em1


And GNOME displayed "disconnected" for Wired.

When I stopped NetworkManager service and used `dhclient em1` manually, everything worked. After half an hour, I've found out I need to remove
/var/lib/NetworkManager/dhclient-65bf8b50-fd35-4359-adff-24793c9b77f3-em1.lease

Once I've done that, NetworkManager started to work OK.

The contents of the lease is as follows:
default-duid "\000\001\000\001\034=\003T\360\336\361\371\263\234";
lease {
  interface "em1";
  fixed-address 192.168.0.21;
  option subnet-mask 255.255.255.0;
  option routers 192.168.0.1;
  option dhcp-lease-time 604800;
  option dhcp-message-type 5;
  option domain-name-servers 83.240.0.215,83.240.0.136;
  option dhcp-server-identifier 192.168.0.1;
  option domain-name "cust.nbox.cz";
  renew 4 2015/01/15 18:56:44;
  rebind 0 2015/01/18 17:35:18;
  expire 1 2015/01/19 14:35:18;
}

I guess some of the timestamps are off? Maybe my home router assigned me incorrect lease? (Please note however, that I move my laptop between my home and work very often, and this is the first time I see this).

If this is indeed a router bug, I believe NetworkManager should protect me against it if at all possible. It's very unhelpful if my wired connection stops working completely and I need to wait it a week or so to get it back.

Thanks for looking into this.

Version-Release number of selected component (if applicable):
NetworkManager-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-adsl-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-bluetooth-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-config-connectivity-fedora-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-glib-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-openconnect-0.9.8.6-2.fc21.x86_64
NetworkManager-openvpn-0.9.9.0-3.git20140128.fc21.x86_64
NetworkManager-openvpn-gnome-0.9.9.0-3.git20140128.fc21.x86_64
NetworkManager-pptp-0.9.8.2-6.fc21.x86_64
NetworkManager-pptp-gnome-0.9.8.2-6.fc21.x86_64
NetworkManager-vpnc-0.9.9.0-6.git20140428.fc21.x86_64
NetworkManager-vpnc-gnome-0.9.9.0-6.git20140428.fc21.x86_64
NetworkManager-wifi-0.9.10.1-1.2.20150109git.fc21.x86_64
NetworkManager-wwan-0.9.10.1-1.2.20150109git.fc21.x86_64
dhclient-4.3.1-8.fc21.x86_64
kernel-3.17.8-300.fc21.x86_64


How reproducible:
I can reproduce this if I place the lease file above back to the original location and try to reconnect my wired connection.

Comment 1 Kamil Páral 2015-01-13 09:44:24 UTC
For reference, this is the lease file that gets created when I successfully connect in my work:

$ cat /var/lib/NetworkManager/dhclient-65bf8b50-fd35-4359-adff-24793c9b77f3-em1.lease
lease {
  interface "em1";
  fixed-address 10.34.28.207;
  filename "/pxelinux.0";
  option subnet-mask 255.255.254.0;
  option dhcp-lease-time 86400;
  option routers 10.34.29.254;
  option dhcp-message-type 5;
  option dhcp-server-identifier 10.34.255.7;
  option domain-name-servers 10.34.255.7,10.34.255.6;
  option ntp-servers 10.5.26.10,10.5.27.10,10.11.160.238,10.16.255.1;
  option domain-name "brq.redhat.com englab.brq.redhat.com lab.eng.brq.redhat.com redhat.com";
  renew 5 2013/02/22 19:49:06;
  rebind 6 2013/02/23 05:27:17;
  expire 6 2013/02/23 08:27:17;
}
default-duid "\000\001\000\001\034G\241\016\360\336\361\371\263\234";
lease {
  interface "em1";
  fixed-address 10.34.28.119;
  filename "/pxelinux.0";
  option subnet-mask 255.255.254.0;
  option routers 10.34.29.254;
  option dhcp-lease-time 3600;
  option dhcp-message-type 5;
  option domain-name-servers 10.38.5.26,10.11.5.19;
  option dhcp-server-identifier 10.11.5.19;
  option domain-search "brq.redhat.com.", "redhat.com.";
  option ntp-servers 10.5.26.10,10.5.27.10;
  option domain-name "brq.redhat.com";
  renew 2 2015/01/13 09:49:38;
  rebind 2 2015/01/13 10:18:06;
  expire 2 2015/01/13 10:25:36;
}

Comment 2 Jirka Klimes 2015-01-13 12:35:26 UTC
We have a fix for this in master. It needs to be backported to 0.9.10 and pushed to Fedora. See upstream bug https://bugzilla.gnome.org/show_bug.cgi?id=739482.

Note:
First, I could not reproduce. I got DHCPNAK, but immediately after that dhclient initialized again and obtained a new lease successfully. I found that it was due to IPv6 method being Automatic. When I set IPv6 method to Ignore, the connection failed at once as you observe. So as a temporarily workaround, you could set the IPv6 method to Automatic instead of Ignore.

Comment 3 Jirka Klimes 2015-01-14 17:32:21 UTC
*** Bug 1180398 has been marked as a duplicate of this bug. ***

Comment 4 Jirka Klimes 2015-01-14 17:36:38 UTC
*** Bug 1181329 has been marked as a duplicate of this bug. ***

Comment 5 Jirka Klimes 2015-01-14 17:40:31 UTC
*** Bug 1179985 has been marked as a duplicate of this bug. ***

Comment 6 dominique 2015-01-14 18:46:39 UTC
(In reply to Jirka Klimes from comment #2)
> We have a fix for this in master. It needs to be backported to 0.9.10 and
> pushed to Fedora. See upstream bug
> https://bugzilla.gnome.org/show_bug.cgi?id=739482.
> 
> Note:
> First, I could not reproduce. I got DHCPNAK, but immediately after that
> dhclient initialized again and obtained a new lease successfully. I found
> that it was due to IPv6 method being Automatic. When I set IPv6 method to
> Ignore, the connection failed at once as you observe. So as a temporarily
> workaround, you could set the IPv6 method to Automatic instead of Ignore.

I am the reporter for bug: 1180398

For me the workaround don't work.
My IPv6 method is set to Automatic since I installed Fedora (21, 20, 19...), and I have this bug.

Comment 7 Ronald Verbeek 2015-01-14 21:23:12 UTC
I reported bug 1181329 that was marked and closed as a duplicate of this one.
https://bugzilla.redhat.com/show_bug.cgi?id=1181329

The issue was reported for
Version: 0.9.10.1
Release: 1.git20150105.fc21

Recently this was updated to 
Release: 1.2.20150109git.fc21

And it looks like the update has solved the issue.

Comment 8 dominique 2015-01-15 05:22:04 UTC
Sorry, but I install the 1.2.20150109git.fc21 release and that don't solve the issue.

Comment 9 Fedora Update System 2015-01-15 16:32:56 UTC
NetworkManager-0.9.10.1-1.4.20150115git.fc21 has been submitted as an update for Fedora 21.
https://admin.fedoraproject.org/updates/NetworkManager-0.9.10.1-1.4.20150115git.fc21

Comment 10 dominique 2015-01-16 18:16:37 UTC
I install the update NetworkManager-0.9.10.1-1.4.20150115git.fc21 and that work for me.
Thank.

Comment 11 Andreas M. Kirchwitz 2015-01-16 18:29:24 UTC
The update does *not* solve the DHCP problem, originally reported in bug #1179985. It still takes several attempts (systemctl restart NetworkManager) to get the DHCP-enabled wired interface into "connected" state.

If somebody reports that it "works", then it's just because it's a random bug. Sometimes it works, sometimes not. The bug still exists.

Comment 12 Fedora Update System 2015-01-17 05:45:33 UTC
Package NetworkManager-0.9.10.1-1.4.20150115git.fc21:
* should fix your issue,
* was pushed to the Fedora 21 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing NetworkManager-0.9.10.1-1.4.20150115git.fc21'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2015-0802/NetworkManager-0.9.10.1-1.4.20150115git.fc21
then log in and leave karma (feedback).

Comment 13 Fedora Update System 2015-01-17 23:58:12 UTC
NetworkManager-0.9.10.1-1.4.20150115git.fc21 has been pushed to the Fedora 21 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 14 Kamil Páral 2015-01-20 11:31:50 UTC
(In reply to Andreas M. Kirchwitz from comment #11)
> The update does *not* solve the DHCP problem, originally reported in bug
> #1179985. It still takes several attempts (systemctl restart NetworkManager)
> to get the DHCP-enabled wired interface into "connected" state.
> 
> If somebody reports that it "works", then it's just because it's a random
> bug. Sometimes it works, sometimes not. The bug still exists.

If you can reproduce bug 1179985 with updated NetworkManager, can you please reopen it and attach details? Thanks.

Comment 15 Andreas M. Kirchwitz 2015-01-20 12:27:08 UTC
Sorry, my comment was badly timed and based on the previous update. Please accept my apologies for the confusion this has caused. After the brandnew update I've restarted the new "NetworkManager-0.9.10.1-1.4.20150115git.fc21" about a hundred times, and it worked fine 100%. Not a single failure.

Looks great! Thanks a lot!


Note You need to log in before you can comment on or make changes to this bug.