Bug 1411444 - Update from NetworkManager-1.4.2-1.fc25.x86_64 to NetworkManager-1.4.2-2.fc25.x86_64 broke ethernet connection
Summary: Update from NetworkManager-1.4.2-1.fc25.x86_64 to NetworkManager-1.4.2-2.fc25...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 25
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Lubomir Rintel
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-09 18:04 UTC by stan
Modified: 2017-12-12 10:09 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-12-12 10:09:35 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description stan 2017-01-09 18:04:24 UTC
Description of problem:
After the update from NetworkManager-1.4.2-1.fc25.x86_64 to NetworkManager-1.4.2-1.fc25.x86_64, the ethernet network connection on my pc became unreliable.  The device would be found and active, NetworkManager would be up and running, but any network access would return with 'network unavailable'.  I tried unloading and reloading the driver, restarting, or stopping and then starting NetworkManager, but that didn't work.  If I powered down and up the network connection, the link would usually be found.  Sometimes it took more than once.  When I looked in the logs (journalctl -b), I found that a NetworkManager function dhcp4 was timing out.  I tried various versions until NetworkManager-1.4.2-1.fc25.x86_64 fixed the problem.  It seems that this change

Changelog 	* Tue Dec 06 2016 Thomas Haller <thaller> - 1:1.4.2-2
- Rebuild package for vala generation error (rh#1398738)

caused the issue.

Version-Release number of selected component (if applicable):
NetworkManager-1.4.2-2.fc25.x86_64.rpm

How reproducible:
Frequently, though intermittent.  It seems to occur every time if the pc is booted with the network connection already active.

Steps to Reproduce:
1.  Update to NetworkManager-1.4.2-2.fc25.x86_64.rpm or later
2.  Boot with network connection already active.
3.

Actual results:
Attempt to get dhcp address times out.

Expected results:
Network connection is established.

Additional info:

This error also occurs in rawhide, though with the later package that has this same fix in it, NetworkManager-1.5.2-4.fc26.x86_64.rpm.

Workaround - downgrade to package before the vala generation error fix went in.

Comment 1 Thomas Haller 2017-01-09 18:22:22 UTC
it's hard to imagine that 1:1.4.2-2 broke something, because it contains no changes at all (compared to 1:1.4.2-2). It is only a re-build of the exact same code.


please show the output of

  nmcli device
  nmcli connection
  ip link
  ip addr
  ip route
  ping -c 4 8.8.8.8
  traceroute -n 8.8.8.8
  cat /etc/resolv.conf

when the issue happens. Thank you.

Comment 2 stan 2017-01-09 21:32:06 UTC
Placebo effect?  :-)

Maybe I didn't test it extensively enough.  The timing is approximately right, as it was released at about the time I noticed the problem start happening (early December).

The other thing is, I built the src.rpm locally using rpmbuild.  Perhaps that changed something in the binaries.

I'll update to the latest version of NetworkManager from the repositories, where this was definitely happening, and will provide the information the next time I boot after that, when the problem occurs.

Comment 3 stan 2017-01-09 22:58:24 UTC
Well, that was interesting.  I updated, and did all the kinds of network shenanigans that would have previously led to network failure, and the link worked flawlessly.

A possible:  When I downgraded NetworkManager yesterday, I removed some packages that I don't use, along with their dependencies, and added one.  Maybe that made the difference.

From /var/log/dnf.rpm.log:
Jan 08 14:11:16 INFO --- logging initialized ---
Jan 08 14:11:58 INFO Erased: anaconda-25.20.9-1.fc25.x86_64
Jan 08 14:11:59 INFO Erased: anaconda-gui-25.20.9-1.fc25.x86_64
Jan 08 14:11:59 INFO Erased: NetworkManager-bluetooth-1:1.4.2-1.fc25.x86_64
Jan 08 14:12:00 INFO Erased: NetworkManager-wwan-1:1.4.2-1.fc25.x86_64
Jan 08 14:12:00 INFO Erased: NetworkManager-wifi-1:1.4.2-1.fc25.x86_64
Jan 08 14:12:53 INFO --- logging initialized ---
Jan 08 14:13:13 INFO Erased: python3-meh-gui-0.44-2.fc25.noarch
Jan 08 14:13:13 INFO Erased: anaconda-user-help-22.4-4.fc24.noarch
Jan 08 14:13:14 INFO Erased: wpa_supplicant-1:2.6-1.fc25.x86_64
Jan 08 14:13:14 INFO Erased: libtimezonemap-0.4.5-4.fc25.x86_64
Jan 08 14:13:16 INFO Erased: anaconda-widgets-25.20.9-1.fc25.x86_64
Jan 08 14:13:57 INFO --- logging initialized ---
Jan 08 14:14:17 INFO Installed: NetworkManager-tui-1:1.4.2-1.fc25.x86_64

Anyway, it seems there is no longer a problem, so I will be closing this tickes as not a bug.  If I run into the problem again, I'll reopen it with the information you requested.

Thanks for your help.

Comment 4 Thomas Haller 2017-01-10 09:35:22 UTC
(In reply to Thomas Haller from comment #1)
> it's hard to imagine that 1:1.4.2-2 broke something, because it contains no
> changes at all (compared to 1:1.4.2-2). It is only a re-build of the exact
> same code.

... compared to 1:1.4.2-1, of course.


Thanks @stan

Comment 5 stan 2017-01-11 19:24:32 UTC
It happened again.  Here is the info you requested, plus output from journalctl -b that seems to be relevant.  

~  12:00 PM  stan  tty1
$ nmcli device
DEVICE  TYPE      STATE                                  CONNECTION
enp2s0  ethernet  connecting (getting IP configuration)  enp2s0
lo      loopback  unmanaged                              --
~  12:00 PM  stan  tty1
$ nmcli connection
NAME    UUID                                  TYPE            DEVICE
enp2s0  7c6ecd1d-4b29-47c8-a0d7-9091f12e48db  802-3-ethernet  enp2s0
~  12:01 PM  stan  tty1
$ ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: enp2s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP mode DEFAULT group default qlen 1000
    link/ether 10:c4:7b:93:96:26 brd ff:ff:ff:ff:ff:ff
~  12:01 PM  stan  tty1
$ ip addr
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
  link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
  inet 127.0.0.1/8 scope host lo
     valid_lft forever preferred_lft forever
  inet6 ::1/128 scope host
     valid_lft forever preferred_lft forever
2: enp2s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default
qlen 1000
  link/ether 10:c4:7b:93:96:26 brd ff:ff:ff:ff:ff:ff
  inet6 fe80::12c4:7bff:fe93:9626/64 scope link
     valid_lft forever preferred_lft forever
 ~  12:01 PM  stan  tty1
 $ ip route
 ~  12:01 PM  stan  tty1
 $ ping -c 4 8.8.8.8
 connect: Network is unreachable
 ~  12:01 PM  stan  tty1
 $ traceroute -n 8.8.8.8
 traceroute to 8.8.8.8 (8.8.8.8), 30 hops max, 60 byte packets
 connect: Network is unreachable
 ~  12:01 PM  stan  tty1
 $ cat /etc/resolve.conf
 cat: /etc/resolve.conf: No such file or directory
 ~  12:02 PM  stan  tty1
 $

Jan 11 11:59:49 localhost.localdomain NetworkManager[1079]: <info>  [1484161189.8286] dhcp4 (enp2s0): activation: beginning
transaction (timeout in 45 seconds)

Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <warn>  [1484161234.7853] dhcp4 (enp2s0): request timed out
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.7863] dhcp4 (enp2s0): state changed unknown
-> timeout
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8009] dhcp4 (enp2s0): canceled DHCP
transaction
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8010] dhcp4 (enp2s0): state changed timeout
-> done
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8016] device (enp2s0): state change:
ip-config -> failed (reason 'ip-config-unavailable') [70 120 5]
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8019] manager: NetworkManager state is now
DISCONNECTED
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8022] manager: startup complete
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <warn>  [1484161234.8025] device (enp2s0): Activation: failed for
connection 'enp2s0'
Jan 11 12:00:34 localhost.localdomain NetworkManager[1079]: <info>  [1484161234.8042] device (enp2s0): state change: failed
-> disconnected (reason 'none') [120 30 0]

Comment 6 stan 2017-01-15 17:07:12 UTC
I've not seen this again since this one time.  There have been several updates to the system since this happened, and perhaps one of them fixed the problem.

I'll wait another week or so, and then close this if it hasn't happened again.

Comment 7 Thomas Haller 2017-01-15 17:41:12 UTC
looks like a timeout of the DHCP request. Note that the state of the device in `nmcli device` is "connecting".
That is possibly not NetworkManager's fault.

Would need debug logs of NetworkManager, how to get those is described in the comment here: https://cgit.freedesktop.org/NetworkManager/NetworkManager/plain/contrib/fedora/rpm/NetworkManager.conf?id=master

Comment 8 Fedora End Of Life 2017-11-16 19:27:42 UTC
This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '25'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 25 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 9 Fedora End Of Life 2017-12-12 10:09:35 UTC
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


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