Bug 1199098

Summary: Wired networking does not work on Lenovo T540p
Product: [Fedora] Fedora Reporter: Stephen Gallagher <sgallagh>
Component: NetworkManagerAssignee: Dan Williams <dcbw>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 22CC: dcbw, jreznik, psimerda, robatino, satellitgo, sgallagh
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard: AcceptedBlocker
Fixed In Version: NetworkManager-1.0.0-7.fc22 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-03-07 00:08:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1193127    
Bug Blocks: 1043121    

Description Stephen Gallagher 2015-03-05 13:16:45 UTC
Description of problem:
This is split from BZ #1193127

The issue is that booting on wired network results in no usable network. From the logs, it appears that dhclient hangs forever and NetworkManager goes into a tight loop attempting to contact the connectivity site. At this point, I cannot use 'nmcli' either, as all actions except the help text hang indefinitely.

Version-Release number of selected component (if applicable):
NetworkManager-1.0.0-5.fc22.x86_64

How reproducible:
Every time


Steps to Reproduce:
1. Boot Fedora 22 with a network cable plugged into a Lenovo T540p (may affect other hardware)

Actual results:
At boot, the network-online.target times out. When the machine is started, it has no network connection and the GNOME top bar shows the "connecting" icon. The machine has no IP address and /etc/resolv.conf is a broken symlink to 
/var/run/NetworkManager/resolv.conf

NetworkManager ends up in a tight loop trying to reach the connectivity check website.

Expected results:
Networking should work normally.

Additional info:


-- Logs begin at Thu 2015-02-19 15:56:17 EST, end at Thu 2015-03-05 08:04:30 EST. --
Mar 05 08:00:07 sgallagh540.sgallagh.rht systemd[1]: Starting Network Manager...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager (version 1.0.0-5.fc22) is starting...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Read config: /etc/NetworkManager/NetworkManager.conf and conf.d: 20-connectivity-fedora.conf
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WEXT support is enabled
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  VPN: loaded org.freedesktop.NetworkManager.openvpn
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  VPN: loaded org.freedesktop.NetworkManager.openconnect
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  VPN: loaded org.freedesktop.NetworkManager.vpnc
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  VPN: loaded org.freedesktop.NetworkManager.pptp
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Acquired D-Bus service com.redhat.ifcfgrh1
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded plugin ifcfg-rh: (c) 2007 - 2013 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded plugin keyfile: (c) 2007 - 2013 Red Hat, Inc.  To report bugs please use the NetworkManager mailing list.
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  parsing /etc/sysconfig/network-scripts/ifcfg-Red_Hat ...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>      read connection 'Red Hat'
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  parsing /etc/sysconfig/network-scripts/ifcfg-Heathrow ...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>      read connection 'Heathrow'
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  parsing /etc/sysconfig/network-scripts/ifcfg-lo ...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  parsing /etc/sysconfig/network-scripts/ifcfg-enp0s25 ...
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>      read connection 'enp0s25'
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  new connection /etc/NetworkManager/system-connections/Red Hat OpenVPN
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  monitoring kernel firmware directory '/lib/firmware'.
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  rfkill2: found WiFi radio killswitch (at /sys/devices/pci0000:00/0000:00:1c.1/0000:04:00.0/ieee80211/phy0/rfkill2) (driver iwlwifi)
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WiFi hardware radio set enabled
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WWAN hardware radio set enabled
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-bluetooth.so
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-adsl.so
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-wifi.so
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-team.so
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Loaded device plugin: /usr/lib64/NetworkManager/libnm-device-plugin-wwan.so
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WiFi enabled by radio killswitch; enabled by state file
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WWAN enabled by radio killswitch; enabled by state file
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  WiMAX enabled by radio killswitch; enabled by state file
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Networking is enabled by state file
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (lo): link connected
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (lo): carrier is ON
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (lo): new Generic device (driver: 'unknown' ifindex: 1)
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (lo): exported as /org/freedesktop/NetworkManager/Devices/0
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): carrier is OFF
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): new Ethernet device (driver: 'e1000e' ifindex: 2)
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): exported as /org/freedesktop/NetworkManager/Devices/1
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 05 08:00:07 sgallagh540.sgallagh.rht systemd[1]: Started Network Manager.
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): preparing device
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): using nl80211 for WiFi device control
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): driver supports Access Point (AP) mode
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): new 802.11 WiFi device (driver: 'iwlwifi' ifindex: 3)
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): exported as /org/freedesktop/NetworkManager/Devices/2
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): preparing device
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  use BlueZ version 5
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  wpa_supplicant started
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0) supports 5 scan SSIDs
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): supplicant interface state: starting -> ready
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): supplicant interface state: ready -> disconnected
Mar 05 08:00:07 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0) supports 5 scan SSIDs
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): supplicant interface state: disconnected -> inactive
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Auto-activating connection 'Red Hat'.
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: starting connection 'Red Hat'
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 1 of 5 (Device Prepare) scheduled...
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 1 of 5 (Device Prepare) started...
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 2 of 5 (Device Configure) scheduled...
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 1 of 5 (Device Prepare) complete.
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 2 of 5 (Device Configure) starting...
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: prepare -> config (reason 'none') [40 50 0]
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: (wifi) access point 'Red Hat' has security, but secrets are required.
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: config -> need-auth (reason 'none') [50 60 0]
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): Activation: Stage 2 of 5 (Device Configure) complete.
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <warn>  (wlp4s0): No agents were available for this request.
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: need-auth -> failed (reason 'no-secrets') [60 120 7]
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now DISCONNECTED
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <warn>  (wlp4s0): Activation: failed for connection 'Red Hat'
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Mar 05 08:00:09 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): deactivating device (reason 'none') [0]
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): link connected
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Auto-activating connection 'enp0s25'.
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: starting connection 'enp0s25'
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 1 of 5 (Device Prepare) scheduled...
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 1 of 5 (Device Prepare) started...
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 2 of 5 (Device Configure) scheduled...
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 1 of 5 (Device Prepare) complete.
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 2 of 5 (Device Configure) starting...
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: prepare -> config (reason 'none') [40 50 0]
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 2 of 5 (Device Configure) successful.
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 2 of 5 (Device Configure) complete.
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 3 of 5 (IP Configure Start) scheduled.
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 3 of 5 (IP Configure Start) started...
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: config -> ip-config (reason 'none') [50 70 0]
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Activation (enp0s25) Beginning DHCPv4 transaction (timeout in 45 seconds)
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  dhclient started with pid 1490
Mar 05 08:00:10 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 3 of 5 (IP Configure Start) complete.
Mar 05 08:00:11 sgallagh540.sgallagh.rht dhclient[1490]: DHCPDISCOVER on enp0s25 to 255.255.255.255 port 67 interval 8 (xid=0x9742160d)
Mar 05 08:00:15 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (wlp4s0): supplicant interface state: inactive -> scanning
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 5 of 5 (IPv6 Commit) scheduled...
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 5 of 5 (IPv6 Commit) started...
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: ip-config -> ip-check (reason 'none') [70 80 0]
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: Stage 5 of 5 (IPv6 Commit) complete.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: ip-check -> secondaries (reason 'none') [80 90 0]
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): device state change: secondaries -> activated (reason 'none') [90 100 0]
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_LOCAL
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Policy set 'enp0s25' (enp0s25) as default for IPv6 routing and DNS.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  (enp0s25): Activation: successful, device activated.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:00:16 sgallagh540.sgallagh.rht NetworkManager[1084]: <info>  NetworkManager state is now CONNECTED_SITE
<this repeats forever, filling up my log directory>

Comment 1 Fedora Blocker Bugs Application 2015-03-05 13:20:53 UTC
Proposed as a Blocker for 22-alpha by Fedora user sgallagh using the blocker tracking app because:

 Violates criterion: "The installed system must be able to download and install updates with the default console package manager."

Thus far, this appears to be limited to certain hardware and can be worked around by only using the wireless connection, which is non-ideal but may be acceptable for *Alpha*.

Comment 2 Dan Williams 2015-03-05 13:39:24 UTC
Stephen, can you check these things for me when you get into this situation?

ls -al /etc/resolv.conf
cat /etc/resolv.conf
ip addr
ip route

THanks!

Comment 3 Stephen Gallagher 2015-03-05 13:49:05 UTC
"The machine has no IP address and /etc/resolv.conf is a broken symlink to 
/var/run/NetworkManager/resolv.conf" was in the original message :)

/var/run/NetworkManager/resolv.conf is nonexistent, so cat /etc/resolv.conf returns nothing.

I'll get you 'ip addr' and 'ip route' momentarily.

Comment 4 Stephen Gallagher 2015-03-05 14:01:56 UTC
It turns out I was incorrect about the original degree of reproducibility. It happened consistently on two boots, but when I just booted for this information, it didn't happen until I pulled the cable and replaced it (with about a 1-2s pause between pulling and replacing). So it seems like there may be an easy-to-hit race somewhere. Anyway, here's the info you requested, plus a systemctl status NetworkManager showing the hung dhclient call.




[sgallagh@sgallagh540:~]$ ip addr
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default 
    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: enp0s25: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
    link/ether 54:ee:75:10:2a:8e brd ff:ff:ff:ff:ff:ff
    inet6 2620:52:0:1218:56ee:75ff:fe10:2a8e/64 scope global noprefixroute dynamic 
       valid_lft 2591997sec preferred_lft 604797sec
    inet6 fe80::56ee:75ff:fe10:2a8e/64 scope link 
       valid_lft forever preferred_lft forever
3: wlp4s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq state DOWN group default qlen 1000
    link/ether e8:2a:ea:08:3e:c8 brd ff:ff:ff:ff:ff:ff
4: virbr0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN group default 
    link/ether 52:54:00:b2:62:5c brd ff:ff:ff:ff:ff:ff
    inet 192.168.124.1/24 brd 192.168.124.255 scope global virbr0
       valid_lft forever preferred_lft forever
5: virbr0-nic: <BROADCAST,MULTICAST> mtu 1500 qdisc fq_codel master virbr0 state DOWN group default qlen 500
    link/ether 52:54:00:b2:62:5c brd ff:ff:ff:ff:ff:ff
[sgallagh@sgallagh540:~]$ ip route
192.168.124.0/24 dev virbr0  proto kernel  scope link  src 192.168.124.1


[sgallagh@sgallagh540:~]$ systemctl status NetworkManager
● NetworkManager.service - Network Manager
   Loaded: loaded (/usr/lib/systemd/system/NetworkManager.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2015-03-05 08:51:17 EST; 2min 40s ago
 Main PID: 1083 (NetworkManager)
   CGroup: /system.slice/NetworkManager.service
           ├─1083 /usr/sbin/NetworkManager --no-daemon
           └─3386 /sbin/dhclient -d -q -sf /usr/libexec/nm-dhcp-helper -pf /var/run/dhclient-enp0s25.pid -lf /var/lib/NetworkManager/dhclient-0077bd39-0b06-4536-a07c-0f60d709a1a5-enp0s25.lease -cf /var/lib/NetworkManager/dhclient-enp0s25.conf enp0s25

Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTING
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  Connectivity check for uri 'https://fedoraproject.org/static/hotspot.txt' failed with 'Error resolving 'fedoraproject.org': No address associated with hostname'.
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTED_SITE
Mar 05 08:53:58 sgallagh540.sgallagh.rht NetworkManager[1083]: <info>  NetworkManager state is now CONNECTING

Comment 5 Dan Williams 2015-03-05 14:09:52 UTC
I'm building http://koji.fedoraproject.org/koji/taskinfo?taskID=9142905 with a backport to fix the connectivity loop thing, which might help reduce the noise.

Comment 6 Dan Williams 2015-03-05 14:13:27 UTC
Stephen, so what's going on here (and why NM says you are connected) is because you have IPv6 connectivity.  So in reality, you do have internet connectivity because you have a global IPv6 address.  You just don't have IPv4 connectivity yet, because DHCP is still happening...  the original logs had too much connectivity checking spew to show the continuing DHCPv4 requests and any replies.

I think the connectivity loop thing is getting in the way a bit, so lets get that update posted and then get some clean logs if you have a bit of time?

Comment 7 Fedora Update System 2015-03-05 15:26:55 UTC
NetworkManager-1.0.0-7.fc22 has been submitted as an update for Fedora 22.
https://admin.fedoraproject.org/updates/NetworkManager-1.0.0-7.fc22

Comment 8 Fedora Update System 2015-03-05 17:12:04 UTC
Package NetworkManager-1.0.0-7.fc22:
* should fix your issue,
* was pushed to the Fedora 22 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing NetworkManager-1.0.0-7.fc22'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2015-3298/NetworkManager-1.0.0-7.fc22
then log in and leave karma (feedback).

Comment 9 Jaroslav Reznik 2015-03-06 12:58:39 UTC
Discussed at yesterday's Go/No-Go meeting.

This bug was accepted as Alpha Blocker - This bug is a clear violation of the alpha criterion: "The installed system must be able to download and install updates with the default console package manager."

Comment 10 Fedora Update System 2015-03-07 00:08:36 UTC
NetworkManager-1.0.0-7.fc22 has been pushed to the Fedora 22 stable repository.  If problems still persist, please make note of it in this bug report.