Bug 901811 - wired connection stops working when wireless is active, have to manually choose wired or wireless
Summary: wired connection stops working when wireless is active, have to manually choo...
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 18
Hardware: Unspecified
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-01-19 13:14 UTC by Tom Georgoulias
Modified: 2013-05-18 16:09 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-05-17 19:36:42 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Tom Georgoulias 2013-01-19 13:14:15 UTC
Description of problem:
My laptop does not keep a stable network connection if my wireless card is enabled and I am simultaneously plugged into a wired connection.  The wired connection works for about 7 mins, then all of my network connections start hanging.  If I pull the plug on my wired connection, it will switch back to wireless and start working again.  If I do the reverse and kill the radio via the keyboard killswitch, then switch to the wired, it also starts working.

This is the first fedora release where I've seen this behavior, I've had Fedora 15-17 on this laptop and never had any problems.

Version-Release number of selected component (if applicable):
NetworkManager-0.9.7.0-12.git20121004.fc18.i686

How reproducible:
Everytime

Steps to Reproduce:
1. Plug network cable into NIC while wireless is enabled
2. Wait about 7+ minutes
3.
  
Actual results:
Network becomes unstable or unresponsive

Expected results:
Should seamlessly move between network connections, preferring the wired over the wireless when the wired is active.

Additional info:

I used the Fedup tool to upgrade from Fedora 17 to Fedora 18.

lspci -v output:

08:00.0 Ethernet controller: Atheros Communications Inc. AR8151 v2.0 Gigabit Ethernet (rev c0)
	Subsystem: Hewlett-Packard Company Device 1650
	Flags: bus master, fast devsel, latency 0, IRQ 44
	Memory at c1400000 (64-bit, non-prefetchable) [size=256K]
	I/O ports at 2000 [size=128]
	Capabilities: <access denied>
	Kernel driver in use: atl1c

01:00.0 Network controller: Realtek Semiconductor Co., Ltd. RTL8188CE 802.11b/g/n WiFi Adapter (rev 01)
	Subsystem: Hewlett-Packard Company Device 1629
	Flags: bus master, fast devsel, latency 0, IRQ 16
	I/O ports at 4000 [size=256]
	Memory at c2500000 (64-bit, non-prefetchable) [size=16K]
	Capabilities: <access denied>
	Kernel driver in use: rtl8192ce

# tail -f /var/log/messages
Jan 19 07:30:54 teicher dbus[700]: [system] Rejected send message, 2 matched rules; type="method_return", sender=":1.1" (uid=0 pid=689 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.67" (uid=1000 pid=1498 comm="gnome-session ")
Jan 19 07:31:21 teicher dbus-daemon[700]: ** Message: No devices in use, exit
Jan 19 07:32:38 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Jan 19 07:32:38 teicher dbus[700]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Jan 19 07:32:38 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Jan 19 07:32:38 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Jan 19 07:32:46 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Jan 19 07:32:46 teicher dbus[700]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Jan 19 07:32:46 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Jan 19 07:32:46 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Jan 19 07:33:05 teicher kernel: [13826.763961] atl1c 0000:08:00.0: atl1c: eth0 NIC Link is Up<100 Mbps Full Duplex>
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): carrier now ON (device state 20)
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Auto-activating connection 'Wired connection 1'.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) starting connection 'Wired connection 1'
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): device state change: prepare -> config (reason 'none') [40 50 0]
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): device state change: config -> ip-config (reason 'none') [50 70 0]
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Jan 19 07:33:05 teicher NetworkManager[807]: <info> dhclient started with pid 10308
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Jan 19 07:33:05 teicher dhclient[10308]: Internet Systems Consortium DHCP Client 4.2.4-P2
Jan 19 07:33:05 teicher dhclient[10308]: Copyright 2004-2012 Internet Systems Consortium.
Jan 19 07:33:05 teicher dhclient[10308]: All rights reserved.
Jan 19 07:33:05 teicher dhclient[10308]: For info, please visit https://www.isc.org/software/dhcp/
Jan 19 07:33:05 teicher dhclient[10308]: 
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): DHCPv4 state changed nbi -> preinit
Jan 19 07:33:05 teicher dhclient[10308]: Listening on LPF/eth0/10:1f:74:f9:df:82
Jan 19 07:33:05 teicher dhclient[10308]: Sending on   LPF/eth0/10:1f:74:f9:df:82
Jan 19 07:33:05 teicher dhclient[10308]: Sending on   Socket/fallback
Jan 19 07:33:05 teicher dhclient[10308]: DHCPREQUEST on eth0 to 255.255.255.255 port 67 (xid=0x4f6a5d17)
Jan 19 07:33:05 teicher dhclient[10308]: DHCPACK from 192.168.1.254 (xid=0x4f6a5d17)
Jan 19 07:33:05 teicher dhclient[10308]: bound to 192.168.1.145 -- renewal in 41680 seconds.
Jan 19 07:33:05 teicher NetworkManager[807]: <info> (eth0): DHCPv4 state changed preinit -> reboot
Jan 19 07:33:05 teicher NetworkManager[807]: <info>   address 192.168.1.145
Jan 19 07:33:05 teicher NetworkManager[807]: <info>   prefix 24 (255.255.255.0)
Jan 19 07:33:05 teicher NetworkManager[807]: <info>   gateway 192.168.1.254
Jan 19 07:33:05 teicher NetworkManager[807]: <info>   nameserver '192.168.1.254'
Jan 19 07:33:05 teicher NetworkManager[807]: <info>   domain name 'gateway.2wire.net'
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jan 19 07:33:05 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) started...
Jan 19 07:33:05 teicher avahi-daemon[697]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.145.
Jan 19 07:33:05 teicher avahi-daemon[697]: New relevant interface eth0.IPv4 for mDNS.
Jan 19 07:33:05 teicher avahi-daemon[697]: Registering new address record for 192.168.1.145 on eth0.IPv4.
Jan 19 07:33:06 teicher NetworkManager[807]: <info> (eth0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jan 19 07:33:06 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) complete.
Jan 19 07:33:06 teicher NetworkManager[807]: <info> (eth0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jan 19 07:33:06 teicher NetworkManager[807]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS.
Jan 19 07:33:06 teicher NetworkManager[807]: <info> Activation (eth0) successful, device activated.
Jan 19 07:33:06 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:33:06 teicher dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:33:06 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:33:06 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:33:06 teicher systemd[1]: Started LSB: Starts and stops login and scanning of iSCSI devices..
Jan 19 07:33:06 teicher dbus-daemon[700]: Starting iscsi (via systemctl):  [  OK  ]
Jan 19 07:33:06 teicher systemd[1]: Stopping Sendmail Mail Transport Client...
Jan 19 07:33:06 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Jan 19 07:33:06 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Jan 19 07:33:10 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Jan 19 07:33:10 teicher dbus-daemon[700]: Failed to issue method call: Unit winbind.service is not loaded.
Jan 19 07:33:10 teicher NetworkManager[807]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
Jan 19 07:33:10 teicher chronyd[737]: Selected source 72.249.38.88
Jan 19 07:33:10 teicher chronyd[737]: Can't synchronise: no majority
Jan 19 07:33:10 teicher chronyd[737]: Selected source 108.61.73.244
Jan 19 07:33:10 teicher chronyd[737]: System clock wrong by -0.544546 seconds, adjustment started
Jan 19 07:34:07 teicher systemd[1]: Started Sendmail Mail Transport Agent.
Jan 19 07:34:07 teicher systemd[1]: Starting Sendmail Mail Transport Client...
Jan 19 07:35:07 teicher systemd[1]: Started Sendmail Mail Transport Client.
Jan 19 07:40:40 teicher kernel: [14282.074141] atl1c 0000:08:00.0: atl1c: eth0 NIC Link is Down
Jan 19 07:40:40 teicher NetworkManager[807]: <info> (eth0): carrier now OFF (device state 100, deferring action for 4 seconds)
Jan 19 07:40:45 teicher NetworkManager[807]: <info> (eth0): device state change: activated -> unavailable (reason 'carrier-changed') [100 20 40]
Jan 19 07:40:45 teicher NetworkManager[807]: <info> (eth0): deactivating device (reason 'carrier-changed') [40]
Jan 19 07:40:45 teicher NetworkManager[807]: <info> (eth0): canceled DHCP transaction, DHCP client pid 10308
Jan 19 07:40:45 teicher dnsmasq[1310]: reading /etc/resolv.conf
Jan 19 07:40:45 teicher avahi-daemon[697]: Withdrawing address record for 192.168.1.145 on eth0.
Jan 19 07:40:45 teicher avahi-daemon[697]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.145.
Jan 19 07:40:45 teicher avahi-daemon[697]: Interface eth0.IPv4 no longer relevant for mDNS.
Jan 19 07:40:45 teicher NetworkManager[807]: <info> Policy set 'Auto greennet' (wlan1) as default for IPv4 routing and DNS.
Jan 19 07:40:45 teicher dnsmasq[1310]: using nameserver 192.168.1.254#53
Jan 19 07:40:45 teicher dnsmasq[1310]: using nameserver 208.67.222.222#53
Jan 19 07:40:45 teicher dnsmasq[1310]: using nameserver 8.8.8.8#53
Jan 19 07:40:45 teicher dnsmasq[1310]: using local addresses only for unqualified names
Jan 19 07:40:45 teicher dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:40:45 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:40:45 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:40:45 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:40:45 teicher systemd[1]: Stopping Sendmail Mail Transport Client...
Jan 19 07:40:45 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Jan 19 07:40:45 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Jan 19 07:40:49 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Jan 19 07:40:49 teicher dbus-daemon[700]: Failed to issue method call: Unit winbind.service is not loaded.
Jan 19 07:40:49 teicher NetworkManager[807]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
Jan 19 07:41:47 teicher systemd[1]: Started Sendmail Mail Transport Agent.
Jan 19 07:41:47 teicher systemd[1]: Starting Sendmail Mail Transport Client...
Jan 19 07:42:47 teicher systemd[1]: Started Sendmail Mail Transport Client.
Jan 19 07:54:46 teicher kernel: [15126.400931] atl1c 0000:08:00.0: atl1c: eth0 NIC Link is Up<100 Mbps Full Duplex>
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): carrier now ON (device state 20)
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Auto-activating connection 'Wired connection 1'.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) starting connection 'Wired connection 1'
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): device state change: prepare -> config (reason 'none') [40 50 0]
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): device state change: config -> ip-config (reason 'none') [50 70 0]
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Jan 19 07:54:46 teicher NetworkManager[807]: <info> dhclient started with pid 10731
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Jan 19 07:54:46 teicher dhclient[10731]: Internet Systems Consortium DHCP Client 4.2.4-P2
Jan 19 07:54:46 teicher dhclient[10731]: Copyright 2004-2012 Internet Systems Consortium.
Jan 19 07:54:46 teicher dhclient[10731]: All rights reserved.
Jan 19 07:54:46 teicher dhclient[10731]: For info, please visit https://www.isc.org/software/dhcp/
Jan 19 07:54:46 teicher dhclient[10731]: 
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): DHCPv4 state changed nbi -> preinit
Jan 19 07:54:46 teicher dhclient[10731]: Listening on LPF/eth0/10:1f:74:f9:df:82
Jan 19 07:54:46 teicher dhclient[10731]: Sending on   LPF/eth0/10:1f:74:f9:df:82
Jan 19 07:54:46 teicher dhclient[10731]: Sending on   Socket/fallback
Jan 19 07:54:46 teicher dhclient[10731]: DHCPREQUEST on eth0 to 255.255.255.255 port 67 (xid=0x7b6f87ec)
Jan 19 07:54:46 teicher dhclient[10731]: DHCPACK from 192.168.1.254 (xid=0x7b6f87ec)
Jan 19 07:54:46 teicher dhclient[10731]: bound to 192.168.1.145 -- renewal in 42147 seconds.
Jan 19 07:54:46 teicher NetworkManager[807]: <info> (eth0): DHCPv4 state changed preinit -> reboot
Jan 19 07:54:46 teicher NetworkManager[807]: <info>   address 192.168.1.145
Jan 19 07:54:46 teicher NetworkManager[807]: <info>   prefix 24 (255.255.255.0)
Jan 19 07:54:46 teicher NetworkManager[807]: <info>   gateway 192.168.1.254
Jan 19 07:54:46 teicher NetworkManager[807]: <info>   nameserver '192.168.1.254'
Jan 19 07:54:46 teicher NetworkManager[807]: <info>   domain name 'gateway.2wire.net'
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jan 19 07:54:46 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) started...
Jan 19 07:54:46 teicher avahi-daemon[697]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.145.
Jan 19 07:54:46 teicher dnsmasq[1310]: reading /etc/resolv.conf
Jan 19 07:54:46 teicher dnsmasq[1310]: using nameserver 192.168.1.254#53
Jan 19 07:54:46 teicher dnsmasq[1310]: using nameserver 208.67.222.222#53
Jan 19 07:54:46 teicher dnsmasq[1310]: using nameserver 8.8.8.8#53
Jan 19 07:54:46 teicher dnsmasq[1310]: using local addresses only for unqualified names
Jan 19 07:54:46 teicher avahi-daemon[697]: New relevant interface eth0.IPv4 for mDNS.
Jan 19 07:54:46 teicher avahi-daemon[697]: Registering new address record for 192.168.1.145 on eth0.IPv4.
Jan 19 07:54:47 teicher NetworkManager[807]: <info> (eth0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jan 19 07:54:47 teicher NetworkManager[807]: <info> Activation (eth0) Stage 5 of 5 (IPv4 Commit) complete.
Jan 19 07:54:47 teicher NetworkManager[807]: <info> (eth0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jan 19 07:54:47 teicher NetworkManager[807]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS.
Jan 19 07:54:47 teicher NetworkManager[807]: <info> Activation (eth0) successful, device activated.
Jan 19 07:54:47 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:54:47 teicher dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:54:47 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:54:47 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:54:47 teicher systemd[1]: Started LSB: Starts and stops login and scanning of iSCSI devices..
Jan 19 07:54:47 teicher dbus-daemon[700]: Starting iscsi (via systemctl):  [  OK  ]
Jan 19 07:54:47 teicher systemd[1]: Stopping Sendmail Mail Transport Client...
Jan 19 07:54:47 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Jan 19 07:54:47 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Jan 19 07:54:51 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Jan 19 07:54:51 teicher dbus-daemon[700]: Failed to issue method call: Unit winbind.service is not loaded.
Jan 19 07:54:51 teicher NetworkManager[807]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
Jan 19 07:55:05 teicher NetworkManager[807]: <info> WiFi now disabled by radio killswitch
Jan 19 07:55:05 teicher NetworkManager[807]: <info> (wlan1): device state change: activated -> unavailable (reason 'none') [100 20 0]
Jan 19 07:55:05 teicher NetworkManager[807]: <info> (wlan1): deactivating device (reason 'none') [0]
Jan 19 07:55:06 teicher NetworkManager[807]: <info> (wlan1): canceled DHCP transaction, DHCP client pid 9293
Jan 19 07:55:06 teicher kernel: [15146.144504] wlan1: deauthenticating from 3c:ea:4f:3f:ad:11 by local choice (reason=3)
Jan 19 07:55:06 teicher kernel: [15146.165949] cfg80211: Calling CRDA to update world regulatory domain
Jan 19 07:55:06 teicher avahi-daemon[697]: Withdrawing address record for 192.168.1.79 on wlan1.
Jan 19 07:55:06 teicher dnsmasq[1310]: reading /etc/resolv.conf
Jan 19 07:55:06 teicher avahi-daemon[697]: Leaving mDNS multicast group on interface wlan1.IPv4 with address 192.168.1.79.
Jan 19 07:55:06 teicher NetworkManager[807]: <info> Policy set 'Wired connection 1' (eth0) as default for IPv4 routing and DNS.
Jan 19 07:55:06 teicher dnsmasq[1310]: using nameserver 192.168.1.254#53
Jan 19 07:55:06 teicher dnsmasq[1310]: using nameserver 208.67.222.222#53
Jan 19 07:55:06 teicher kernel: [15146.175583] cfg80211: World regulatory domain updated:
Jan 19 07:55:06 teicher kernel: [15146.175587] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Jan 19 07:55:06 teicher kernel: [15146.175590] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 07:55:06 teicher kernel: [15146.175592] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Jan 19 07:55:06 teicher kernel: [15146.175594] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Jan 19 07:55:06 teicher kernel: [15146.175596] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 07:55:06 teicher kernel: [15146.175598] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 07:55:06 teicher dnsmasq[1310]: using nameserver 8.8.8.8#53
Jan 19 07:55:06 teicher dnsmasq[1310]: using local addresses only for unqualified names
Jan 19 07:55:06 teicher avahi-daemon[697]: Interface wlan1.IPv4 no longer relevant for mDNS.
Jan 19 07:55:06 teicher NetworkManager[807]: <info> (wlan1): taking down device.
Jan 19 07:55:06 teicher dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:55:06 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 07:55:06 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:55:06 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 07:55:06 teicher avahi-daemon[697]: Withdrawing address record for fe80::ae81:12ff:feaf:8e42 on wlan1.
Jan 19 07:55:06 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Jan 19 07:55:06 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Jan 19 07:55:06 teicher NetworkManager[807]: <info> WWAN now disabled by radio killswitch
Jan 19 07:55:09 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Jan 19 07:55:09 teicher dbus-daemon[700]: Failed to issue method call: Unit winbind.service is not loaded.
Jan 19 07:55:09 teicher NetworkManager[807]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
Jan 19 07:56:06 teicher systemd[1]: Started Sendmail Mail Transport Agent.
Jan 19 07:56:06 teicher systemd[1]: Starting Sendmail Mail Transport Client...


Jan 19 07:57:07 teicher systemd[1]: Started Sendmail Mail Transport Client.
Jan 19 07:58:39 teicher apcupsd[1017]: Communications with UPS lost.
Jan 19 08:00:01 teicher rsnapshot[10955]: /usr/bin/rsnapshot hourly: ERROR: rsnapshot refuses to create snapshot_root when no_create_root is enabled


Jan 19 08:08:13 teicher NetworkManager[807]: <info> WiFi now enabled by radio killswitch
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1): bringing up device.
Jan 19 08:08:13 teicher kernel: [15932.612991] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1) supports 4 scan SSIDs
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: starting -> ready
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Jan 19 08:08:13 teicher NetworkManager[807]: <warn> Trying to remove a non-existant call id.
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: ready -> inactive
Jan 19 08:08:13 teicher NetworkManager[807]: <info> (wlan1) supports 4 scan SSIDs
Jan 19 08:08:14 teicher NetworkManager[807]: <info> WWAN now enabled by radio killswitch
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Auto-activating connection 'Auto greennet'.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) starting connection 'Auto greennet'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) started...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) scheduled...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) complete.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) starting...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): device state change: prepare -> config (reason 'none') [40 50 0]
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1/wireless): access point 'Auto greennet' has security, but secrets are required.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): device state change: config -> need-auth (reason 'none') [50 60 0]
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) complete.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) started...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) scheduled...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 1 of 5 (Device Prepare) complete.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) starting...
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): device state change: prepare -> config (reason 'none') [40 50 0]
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1/wireless): connection 'Auto greennet' has security, and secrets exist.  No new secrets needed.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: added 'ssid' value 'greennet'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: added 'scan_ssid' value '1'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: added 'psk' value '<omitted>'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: added 'proto' value 'WPA RSN'
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 2 of 5 (Device Configure) complete.
Jan 19 08:08:14 teicher NetworkManager[807]: <info> Config: set interface ap_scan to 1
Jan 19 08:08:14 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: inactive -> scanning
Jan 19 08:08:15 teicher kernel: [15934.512319] wlan1: authenticate with 3c:ea:4f:3f:ad:11
Jan 19 08:08:15 teicher kernel: [15934.531428] wlan1: send auth to 3c:ea:4f:3f:ad:11 (try 1/3)
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Jan 19 08:08:15 teicher kernel: [15934.533867] wlan1: authenticated
Jan 19 08:08:15 teicher kernel: [15934.535145] rtl8192ce 0000:01:00.0 wlan1: disabling HT as WMM/QoS is not supported by the AP
Jan 19 08:08:15 teicher kernel: [15934.535153] rtl8192ce 0000:01:00.0 wlan1: disabling VHT as WMM/QoS is not supported by the AP
Jan 19 08:08:15 teicher kernel: [15934.535727] wlan1: associate with 3c:ea:4f:3f:ad:11 (try 1/3)
Jan 19 08:08:15 teicher kernel: [15934.537427] wlan1: RX AssocResp from 3c:ea:4f:3f:ad:11 (capab=0x431 status=0 aid=3)
Jan 19 08:08:15 teicher kernel: [15934.537633] wlan1: associated
Jan 19 08:08:15 teicher kernel: [15934.537698] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
Jan 19 08:08:15 teicher kernel: [15934.537905] cfg80211: Calling CRDA for country: US
Jan 19 08:08:15 teicher dnsmasq[1310]: reading /etc/resolv.conf
Jan 19 08:08:15 teicher dnsmasq[1310]: using nameserver 192.168.1.254#53
Jan 19 08:08:15 teicher dnsmasq[1310]: using nameserver 208.67.222.222#53
Jan 19 08:08:15 teicher dnsmasq[1310]: using nameserver 8.8.8.8#53
Jan 19 08:08:15 teicher dnsmasq[1310]: using local addresses only for unqualified names
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: authenticating -> associated
Jan 19 08:08:15 teicher kernel: [15934.550210] cfg80211: Regulatory domain changed to country: US
Jan 19 08:08:15 teicher kernel: [15934.550214] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Jan 19 08:08:15 teicher kernel: [15934.550216] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Jan 19 08:08:15 teicher kernel: [15934.550219] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Jan 19 08:08:15 teicher kernel: [15934.550221] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 08:08:15 teicher kernel: [15934.550223] cfg80211:   (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 08:08:15 teicher kernel: [15934.550225] cfg80211:   (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 19 08:08:15 teicher kernel: [15934.550227] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: associated -> 4-way handshake
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): supplicant interface state: 4-way handshake -> completed
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'greennet'.
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 3 of 5 (IP Configure Start) scheduled.
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 3 of 5 (IP Configure Start) started...
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): device state change: config -> ip-config (reason 'none') [50 70 0]
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Beginning DHCPv4 transaction (timeout in 45 seconds)
Jan 19 08:08:15 teicher NetworkManager[807]: <info> dhclient started with pid 11215
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Beginning IP6 addrconf.
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 3 of 5 (IP Configure Start) complete.
Jan 19 08:08:15 teicher dhclient[11215]: Internet Systems Consortium DHCP Client 4.2.4-P2
Jan 19 08:08:15 teicher dhclient[11215]: Copyright 2004-2012 Internet Systems Consortium.
Jan 19 08:08:15 teicher dhclient[11215]: All rights reserved.
Jan 19 08:08:15 teicher dhclient[11215]: For info, please visit https://www.isc.org/software/dhcp/
Jan 19 08:08:15 teicher dhclient[11215]: 
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): DHCPv4 state changed nbi -> preinit
Jan 19 08:08:15 teicher dhclient[11215]: Listening on LPF/wlan1/ac:81:12:af:8e:42
Jan 19 08:08:15 teicher dhclient[11215]: Sending on   LPF/wlan1/ac:81:12:af:8e:42
Jan 19 08:08:15 teicher dhclient[11215]: Sending on   Socket/fallback
Jan 19 08:08:15 teicher dhclient[11215]: DHCPREQUEST on wlan1 to 255.255.255.255 port 67 (xid=0x2760fa6f)
Jan 19 08:08:15 teicher dhclient[11215]: DHCPACK from 192.168.1.254 (xid=0x2760fa6f)
Jan 19 08:08:15 teicher NetworkManager[807]: <info> (wlan1): DHCPv4 state changed preinit -> reboot
Jan 19 08:08:15 teicher NetworkManager[807]: <info>   address 192.168.1.79
Jan 19 08:08:15 teicher NetworkManager[807]: <info>   prefix 24 (255.255.255.0)
Jan 19 08:08:15 teicher NetworkManager[807]: <info>   gateway 192.168.1.254
Jan 19 08:08:15 teicher NetworkManager[807]: <info>   nameserver '192.168.1.254'
Jan 19 08:08:15 teicher NetworkManager[807]: <info>   domain name 'gateway.2wire.net'
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jan 19 08:08:15 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 5 of 5 (IPv4 Commit) started...
Jan 19 08:08:15 teicher dhclient[11215]: bound to 192.168.1.79 -- renewal in 42106 seconds.
Jan 19 08:08:15 teicher avahi-daemon[697]: Joining mDNS multicast group on interface wlan1.IPv4 with address 192.168.1.79.
Jan 19 08:08:15 teicher avahi-daemon[697]: New relevant interface wlan1.IPv4 for mDNS.
Jan 19 08:08:15 teicher avahi-daemon[697]: Registering new address record for 192.168.1.79 on wlan1.IPv4.
Jan 19 08:08:16 teicher NetworkManager[807]: <info> (wlan1): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jan 19 08:08:16 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 5 of 5 (IPv4 Commit) complete.
Jan 19 08:08:16 teicher NetworkManager[807]: <info> (wlan1): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jan 19 08:08:16 teicher NetworkManager[807]: <info> Activation (wlan1) successful, device activated.
Jan 19 08:08:16 teicher dbus-daemon[700]: dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 08:08:16 teicher dbus[700]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Jan 19 08:08:16 teicher dbus-daemon[700]: dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 08:08:16 teicher dbus[700]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 19 08:08:17 teicher systemd[1]: Stopping Sendmail Mail Transport Client...
Jan 19 08:08:17 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Jan 19 08:08:17 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Jan 19 08:08:17 teicher avahi-daemon[697]: Registering new address record for fe80::ae81:12ff:feaf:8e42 on wlan1.*.
Jan 19 08:08:17 teicher dnsmasq[1310]: reading /etc/resolv.conf
Jan 19 08:08:17 teicher dnsmasq[1310]: using nameserver 192.168.1.254#53
Jan 19 08:08:17 teicher dnsmasq[1310]: using nameserver 208.67.222.222#53
Jan 19 08:08:17 teicher dnsmasq[1310]: using nameserver 8.8.8.8#53
Jan 19 08:08:17 teicher dnsmasq[1310]: using local addresses only for unqualified names
Jan 19 08:08:20 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Jan 19 08:08:20 teicher dbus-daemon[700]: Failed to issue method call: Unit winbind.service is not loaded.
Jan 19 08:08:20 teicher NetworkManager[807]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.
Jan 19 08:08:36 teicher NetworkManager[807]: <info> (wlan1): IP6 addrconf timed out or failed.
Jan 19 08:08:36 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Jan 19 08:08:36 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 4 of 5 (IPv6 Configure Timeout) started...
Jan 19 08:08:36 teicher NetworkManager[807]: <info> Activation (wlan1) Stage 4 of 5 (IPv6 Configure Timeout) complete.
Jan 19 08:09:17 teicher systemd[1]: Started Sendmail Mail Transport Agent.
Jan 19 08:09:17 teicher systemd[1]: Starting Sendmail Mail Transport Client...
Jan 19 08:10:18 teicher systemd[1]: Started Sendmail Mail Transport Client.

Comment 1 Tom Georgoulias 2013-02-01 22:24:47 UTC
Anything I can do to help get some eyes on this?  I will run whatever tests are needed, or more data, just let me know.

I just applied the latest errata today, so my laptop is fully patched yet the problem persists.

Comment 2 b.m.kast 2013-02-03 11:03:53 UTC
I've experienced similar behaviour after upgrading the kernel from 3.6.x to 3.7.x. Removing packages 'kernel-3.7.x' and 'kernel-PAE-3.7.x' (substitute 'x' with actual minor version) solved the problem. (You have to reboot to an older kernel in order to do this. Remember that Fedora keeps history of three recently installed kernel versions.).

The bug can be reproduced without waiting for too long by executing (as root):

ping -f -s 65500 -t 00 HOSTNAME

where SERVERNAME is an address of some host on the same subnet (don't try to flood ping servers on the Internet!). For this test to be clean, the wireless interface must be turned off, so all the traffic goes through the wired one.

The bug reproduces on both F17 and F18 after a kernel upgrade.

I've tested the new kernel in another distribution also (namely System Rescue CD, with alternate 3.7.4 kernel, both 32- and 64-bit), and the wired interface worked flawlessly, so the issue seems to be either fixed between 3.7.3 and 3.7.4 (I didn't find anything looking like that in the changelog though) or Fedora-specific.

Also, I have Atheros AR8152 ethernet adapter (PCI codes are 1969:2062) which is driven by atl1c module too (hope it's helpful). The wireless one is Atheros AR9285 (driver: ath9k, PCI ID 168c:002b).

Tom, can you post lspci and uname -a output here?

Comment 3 b.m.kast 2013-02-03 11:15:40 UTC
Oh sorry forgot to mention:

1) I'm not sure that the kernel version history is kept after upgrade using Fedup, so you may need to install a 3.6.x kernel first. It can be done using (for example):

sudo yum install kernel-PAE-3.6.11-5.fc17.i686 kernel-3.6.11-5.fc17.i686

You can find available kernel versions by issuing a command:

yum search --showduplicates kernel|grep '^kernel-\(PAE-\)\?[0-9]'

2) Flood ping prints a dot after every packet emitted and erases one after every response packet received, so if you see some dots flashing near the start of the line, then it's OK, but if you see constantly growing line of dots, then the interface has probably failed.

Comment 4 Tom Georgoulias 2013-02-03 13:22:19 UTC
I'm running the latest kernel now:

$ uname -a
Linux teicher 3.7.4-204.fc18.i686.PAE #1 SMP Wed Jan 23 16:58:41 UTC 2013 i686 i686 i386 GNU/Linux

lscpi ouptut is in the main description.

All I have on my system are 3.7 kernels:

$ rpm -qa | grep kernel
abrt-addon-kerneloops-2.0.20-1.fc18.i686
kernel-PAE-devel-3.7.2-204.fc18.i686
kernel-PAE-3.7.2-201.fc18.i686
kernel-headers-3.7.4-204.fc18.i686
kernel-PAE-devel-3.7.2-201.fc18.i686
kernel-PAE-3.7.2-204.fc18.i686
kernel-PAE-3.7.4-204.fc18.i686
kernel-PAE-devel-3.7.4-204.fc18.i686
libreport-plugin-kerneloops-2.0.20-1.fc18.i686

I'd rather not revert to a 3.6 kernel unless it will be supported going forward, it would be good if this regression was fixed in the 3.7.   It reassuring to know that someone else has seen this and I'm not the only one.

Comment 5 Tom Georgoulias 2013-02-03 14:01:48 UTC
For fun, I tried using the 3.7.5 kernel in updates-testing:

$ uname -r
3.7.5-201.fc18.i686.PAE

I rebooted, plugged in both the wired connection and left wireless enabled, then did some web browsing.  At first the system used the wired connection and everything was fine, then the problem returned.  

syslog was more informative with this kernel:

Feb  3 08:44:40 teicher kernel: [  782.986056] wlan1: deauthenticated from 3c:ea:4f:3f:ad:11 (Reason: 2)
Feb  3 08:44:40 teicher kernel: [  783.012708] cfg80211: Calling CRDA to update world regulatory domain
Feb  3 08:44:40 teicher kernel: [  783.015622] cfg80211: World regulatory domain updated:
Feb  3 08:44:40 teicher kernel: [  783.015626] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Feb  3 08:44:40 teicher kernel: [  783.015628] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:40 teicher kernel: [  783.015630] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:40 teicher kernel: [  783.015632] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:40 teicher kernel: [  783.015634] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:40 teicher kernel: [  783.015636] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:40 teicher NetworkManager[824]: <info> (wlan1): supplicant interface state: completed -> disconnected
Feb  3 08:44:41 teicher NetworkManager[824]: <info> (wlan1): supplicant interface state: disconnected -> scanning
Feb  3 08:44:42 teicher kernel: [  784.350886] wlan1: authenticate with 3c:ea:4f:3f:ad:11
Feb  3 08:44:42 teicher kernel: [  784.370235] wlan1: send auth to 3c:ea:4f:3f:ad:11 (try 1/3)
Feb  3 08:44:42 teicher NetworkManager[824]: <info> (wlan1): supplicant interface state: scanning -> authenticating
Feb  3 08:44:42 teicher kernel: [  784.371546] wlan1: authenticated
Feb  3 08:44:42 teicher kernel: [  784.371738] rtl8192ce 0000:01:00.0 wlan1: disabling HT as WMM/QoS is not supported by the AP
Feb  3 08:44:42 teicher kernel: [  784.371741] rtl8192ce 0000:01:00.0 wlan1: disabling VHT as WMM/QoS is not supported by the AP
Feb  3 08:44:42 teicher kernel: [  784.372594] wlan1: associate with 3c:ea:4f:3f:ad:11 (try 1/3)
Feb  3 08:44:42 teicher kernel: [  784.374423] wlan1: RX AssocResp from 3c:ea:4f:3f:ad:11 (capab=0x431 status=0 aid=3)
Feb  3 08:44:42 teicher kernel: [  784.374569] wlan1: associated
Feb  3 08:44:42 teicher kernel: [  784.374650] cfg80211: Calling CRDA for country: US
Feb  3 08:44:42 teicher kernel: [  784.376502] cfg80211: Regulatory domain changed to country: US
Feb  3 08:44:42 teicher kernel: [  784.376506] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Feb  3 08:44:42 teicher kernel: [  784.376508] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Feb  3 08:44:42 teicher kernel: [  784.376510] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Feb  3 08:44:42 teicher kernel: [  784.376512] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:42 teicher kernel: [  784.376514] cfg80211:   (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:42 teicher kernel: [  784.376516] cfg80211:   (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb  3 08:44:42 teicher kernel: [  784.376517] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
Feb  3 08:44:42 teicher NetworkManager[824]: <info> (wlan1): supplicant interface state: authenticating -> associated
Feb  3 08:44:42 teicher NetworkManager[824]: <info> (wlan1): supplicant interface state: associated -> completed


THen I unplugged the cable:

Feb  3 08:56:15 teicher kernel: [ 1476.925330] atl1c 0000:08:00.0: atl1c: eth0 NIC Link is Down
Feb  3 08:56:15 teicher NetworkManager[824]: <info> (eth0): carrier now OFF (device state 100, deferring action for 4 seconds)
Feb  3 08:56:19 teicher NetworkManager[824]: <info> (eth0): device state change: activated -> unavailable (reason 'carrier-changed') [100 20 40]
Feb  3 08:56:19 teicher NetworkManager[824]: <info> (eth0): deactivating device (reason 'carrier-changed') [40]
Feb  3 08:56:20 teicher NetworkManager[824]: <info> (eth0): canceled DHCP transaction, DHCP client pid 2130
Feb  3 08:56:20 teicher avahi-daemon[701]: Withdrawing address record for 192.168.1.145 on eth0.
Feb  3 08:56:20 teicher avahi-daemon[701]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.145.
Feb  3 08:56:20 teicher avahi-daemon[701]: Interface eth0.IPv4 no longer relevant for mDNS.
Feb  3 08:56:20 teicher NetworkManager[824]: <info> Policy set 'Auto greennet' (wlan1) as default for IPv4 routing and DNS.
Feb  3 08:56:20 teicher dbus[705]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Feb  3 08:56:20 teicher dbus-daemon[705]: dbus[705]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
Feb  3 08:56:20 teicher dbus-daemon[705]: dbus[705]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb  3 08:56:20 teicher dbus[705]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb  3 08:56:20 teicher systemd[1]: Stopping Sendmail Mail Transport Client...
Feb  3 08:56:20 teicher systemd[1]: Stopping Sendmail Mail Transport Agent...
Feb  3 08:56:20 teicher systemd[1]: Starting Sendmail Mail Transport Agent...
Feb  3 08:56:22 teicher nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' took too long; killing it.
Feb  3 08:56:22 teicher dbus-daemon[705]: Failed to issue method call: Unit winbind.service is not loaded.
Feb  3 08:56:22 teicher NetworkManager[824]: <warn> Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/10-sendmail' timed out.

Comment 6 b.m.kast 2013-02-03 15:33:59 UTC
I did another test on F18 on a laptop with non-Atheros wired/wireless NICs:

(sudo lspci -v)

05:00.0 Ethernet controller: Broadcom Corporation NetLink BCM5787M Gigabit Ethernet PCI Express (rev 02)
        Subsystem: Acer Incorporated [ALI] Device 011e
        Flags: bus master, fast devsel, latency 0, IRQ 48
        Memory at 98200000 (64-bit, non-prefetchable) [size=64K]
        Expansion ROM at <ignored> [disabled]
        Capabilities: [48] Power Management version 3
        Capabilities: [50] Vital Product Data
        Capabilities: [58] Vendor Specific Information: Len=78 <?>
        Capabilities: [e8] MSI: Enable+ Count=1/1 Maskable- 64bit+
        Capabilities: [d0] Express Endpoint, MSI 00
        Capabilities: [100] Advanced Error Reporting
        Capabilities: [13c] Virtual Channel
        Capabilities: [160] Device Serial Number ***
        Kernel driver in use: tg3

06:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)
        Subsystem: Intel Corporation PRO/Wireless 3945ABG Network Connection
        Flags: bus master, fast devsel, latency 0, IRQ 46
        Memory at 97100000 (32-bit, non-prefetchable) [size=4K]
        Capabilities: [c8] Power Management version 2
        Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
        Capabilities: [e0] Express Legacy Endpoint, MSI 00
        Capabilities: [100] Advanced Error Reporting
        Capabilities: [140] Device Serial Number ***
        Kernel driver in use: iwl3945

(uname -r)

3.7.4-204.fc18.i686.PAE

Wired connection worked fine, so this issue is probably related to atl1c driver.

Comment 7 Tom Georgoulias 2013-02-17 14:37:27 UTC
Out of desperation, I tried using an older 3.6 kernel.  I didn't have the same success as you, the problem remained.

I'm just going to have to learn to live with this and disable my wireless via the killswitch whenever I need to use a wired connection.

Comment 8 pawlik.dan 2013-02-26 21:44:15 UTC
I have the same problem.

Steps to Reproduce:
1. Plug network cable into NIC while wireless is enabled
2. Wait random time
3. Disconnect from  wired network

lspci -v


02:00.0 Ethernet controller: Atheros Communications Inc. AR8152 v1.1 Fast Ethernet (rev c1)
	Subsystem: Toshiba America Info Systems Device ff1e
	Flags: bus master, fast devsel, latency 0, IRQ 45
	Memory at d5000000 (64-bit, non-prefetchable) [size=256K]
	I/O ports at 3000 [size=128]
	Capabilities: [40] Power Management version 3
	Capabilities: [48] MSI: Enable+ Count=1/1 Maskable- 64bit+
	Capabilities: [58] Express Endpoint, MSI 00
	Capabilities: [6c] Vital Product Data
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [180] Device Serial Number ff-af-fe-1c-00-26-6c-ff
	Kernel driver in use: atl1c

03:00.0 Network controller: Broadcom Corporation BCM4313 802.11b/g/n Wireless LAN Controller (rev 01)
	Subsystem: Askey Computer Corp. Device 7175
	Flags: bus master, fast devsel, latency 0, IRQ 17
	Memory at d4000000 (64-bit, non-prefetchable) [size=16K]
	Capabilities: [40] Power Management version 3
	Capabilities: [58] Vendor Specific Information: Len=78 <?>
	Capabilities: [48] MSI: Enable- Count=1/1 Maskable- 64bit+
	Capabilities: [d0] Express Endpoint, MSI 00
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [13c] Virtual Channel
	Capabilities: [160] Device Serial Number 00-00-9f-ff-ff-45-b4-74
	Capabilities: [16c] Power Budgeting <?>
	Kernel driver in use: bcma-pci-bridge




dmesg



[   16.361120] systemd-udevd[375]: renamed network interface eth0 to em1
[   16.624793] cfg80211: World regulatory domain updated:
[   16.624797] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   16.624799] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   16.624800] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   16.624801] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   16.624802] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   16.624804] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   16.997799] brcmsmac bcma0:0: mfg 4bf core 812 rev 24 class 0 irq 17
[   17.158913] kvm: VM_EXIT_LOAD_IA32_PERF_GLOBAL_CTRL does not work properly. Using workaround
[   17.475390] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   17.701765] snd_hda_intel 0000:00:1b.0: irq 43 for MSI/MSI-X
[   17.960797] fglrx: module license 'Proprietary. (C) 2002 - ATI Technologies, Starnberg, GERMANY' taints kernel.
[   17.960802] Disabling lock debugging due to kernel taint
[   17.969785] <6>[fglrx] Maximum main memory to use for locked dma buffers: 7618 MBytes.
[   17.969912] <6>[fglrx]   vendor: 1002 device: 68c1 count: 1
[   17.970097] <6>[fglrx] ioport: bar 4, base 0x4000, size: 0x100
[   17.970190] <6>[fglrx] Kernel PAT support is enabled
[   17.970209] <6>[fglrx] module loaded - fglrx 9.1.11 [Dec 19 2012] with 1 minors
[   18.151381] ALSA sound/pci/hda/hda_intel.c:2713 0000:01:00.1: Handle VGA-switcheroo audio client
[   18.151386] ALSA sound/pci/hda/hda_intel.c:2902 Using LPIB position fix
[   18.151468] snd_hda_intel 0000:01:00.1: irq 44 for MSI/MSI-X
[   18.155320] ALSA sound/pci/hda/hda_intel.c:1680 Enable sync_write for stable communication
[   18.360363] input: HD-Audio Generic HDMI/DP,pcm=3 as /devices/pci0000:00/0000:00:01.0/0000:01:00.1/sound/card1/input9
[   19.384896] cfg80211: Calling CRDA for country: PL
[   19.386323] cfg80211: Regulatory domain changed to country: PL
[   19.386326] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   19.386328] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   19.386329] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   19.386330] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[   19.386331] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm)
[   19.386333] cfg80211:   (57240000 KHz - 65880000 KHz @ 2160000 KHz), (N/A, 4000 mBm)
[   22.906150] fuse init (API version 7.20)
[   30.004742] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   32.369301] systemd-journald[339]: Received SIGUSR1
[   36.528490] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   36.534914] Ebtables v2.0 registered
[   36.570072] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[   37.381281] atl1c 0000:02:00.0: irq 45 for MSI/MSI-X
[   37.381393] atl1c 0000:02:00.0: atl1c: em1 NIC Link is Up<100 Mbps Full Duplex>
[   37.458702] ieee80211 phy0: brcms_ops_bss_info_changed: qos enabled: false (implement)
[   37.484612] ieee80211 phy0: brcms_ops_config: change power-save mode: false (implement)
[   37.510827] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   38.092656] nf_conntrack: automatic helper assignment is deprecated and it will be removed soon. Use the iptables CT target to attach helpers instead.
[   39.251494] fglrx_pci 0000:01:00.0: irq 46 for MSI/MSI-X
[   39.252544] <6>[fglrx] Firegl kernel thread PID: 1140
[   39.252732] <6>[fglrx] Firegl kernel thread PID: 1141
[   39.252879] <6>[fglrx] Firegl kernel thread PID: 1142
[   39.253111] <6>[fglrx] IRQ 46 Enabled
[   39.278060] <6>[fglrx] Gart USWC size:1280 M.
[   39.278062] <6>[fglrx] Gart cacheable size:508 M.
[   39.278066] <6>[fglrx] Reserved FB block: Shared offset:0, size:1000000 
[   39.278067] <6>[fglrx] Reserved FB block: Unshared offset:f8fc000, size:404000 
[   39.278068] <6>[fglrx] Reserved FB block: Unshared offset:3fff4000, size:c000 




uname -r
3.7.9-201.fc18.x86_64



After unplug wired cable and plug, network work for random time.

Comment 9 Dan Williams 2013-02-26 23:46:46 UTC
This is pretty bizarre; I can't think why NetworkManager would be involved here since this appears to be a kernel issue.  It seems the atl1c driver or device is simply failing to work correctly when a wifi card is enabled too.  Over to kernel for that diagnosis.

All reporters so far have Atheros *ethernet* devices (atl1c perhaps).

Comment 10 Turgut Kalfaoglu 2013-02-28 16:35:57 UTC
I have the exact same symptoms.. It is not network dependent.. Wired LAN at work or at home do the same thing.. When wired is plugged in, network dies after a random amount of time.

Comment 11 Kostya Berger 2013-03-09 21:29:04 UTC
Right, because I have the same thing, but I DON'T enable wireless at all: it is just the wired interface, DHCP, and it dies after a while. Called ISP techsupport guy when it happened, he said smth like:"your interface doesn't seem to pick up the address".

Neither has it anything to do with NetworkManager, cause for debugging purposes I disabled NM and configured it to start from /etc/sysconfig/network-scripts/ifcfg-em1. This way it happened all the same.

And it's NOT the Atheros ethernet device, in my case it's nVidia (Reverse Engineered nForce ethernet driver. Version 0.64).

Started about a week or two before now.

Comment 12 Kostya Berger 2013-03-09 23:06:00 UTC
And some very fresh observations:

1. Just used a USB Apple Ethernet adaptor for a change, which overall works just fine (asix driver: "asix 2-3:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x41E1" as taken from `dmesg`). The same thing happened in some 10-15 minutes!

2. I don't attach any logs because NOTHING showed up in any logs during the event! I kept a terminal open with `tail -f /var/log/messages`, and can confirm that NO MESSAGES appeared when the interface stopped responding. Neither were any registered via `dmesg`.

So, clearly, this DOESN'T depend on 
(1) any particular Ethernet device being used, 
(2) neither on using/not using NetworkManager, 
(3) nor on wireless being ON/OFF. Cause I keep wireless switched off.

kernel version: 3.8.1-201.fc18.x86_64 (system updated to the very last update)

Comment 13 b.m.kast 2013-03-10 08:24:24 UTC
Some updates:

1) the bug is not Fedora-specific, it can be reproduced using openSUSE 12.3 beta live CD with kernel 3.7.x (do not remember the exact version)
2) it does NOT reproduce on Broadcom BCM5787M (tg3 driver) with kernel 3.7.6 on F18.

Comment 14 b.m.kast 2013-03-10 13:38:27 UTC
Also, the problem does not reproduce on ASUS UL20N with Atheros AR8132 (using the same atl1c module):

02:00.0 Ethernet controller: Atheros Communications AR8132 Fast Ethernet (rev c0)
        Subsystem: ASUSTeK Computer Inc. Device 14e5
        Physical Slot: 0
        Flags: bus master, fast devsel, latency 0, IRQ 44
        Memory at febc0000 (64-bit, non-prefetchable) [size=256K]
        I/O ports at ec00 [size=128]
        Capabilities: [40] Power Management version 3
        Capabilities: [48] MSI: Enable+ Count=1/1 Maskable- 64bit+
        Capabilities: [58] Express Endpoint, MSI 00
        Capabilities: [6c] Vital Product Data
        Capabilities: [100] Advanced Error Reporting
        Capabilities: [180] Device Serial Number ff-f2-a1-69-90-e6-ba-ff
        Kernel driver in use: atl1c
        
Tested using both openSUSE live CD with 3.7.x and Fedora 17 local installation with 3.7.9 (all 32-bit).

Comment 15 Kostya Berger 2013-03-10 20:11:13 UTC
All right then, here is mine:

00:0a.0 Ethernet controller: NVIDIA Corporation MCP77 Ethernet (rev a2)
	Subsystem: Hewlett-Packard Company Device 2a7a
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0 (250ns min, 5000ns max)
	Interrupt: pin A routed to IRQ 41
	Region 0: Memory at fcf7c000 (32-bit, non-prefetchable) [size=4K]
	Region 1: I/O ports at c880 [size=8]
	Region 2: Memory at fcf7e400 (32-bit, non-prefetchable) [size=256]
	Region 3: Memory at fcf7e000 (32-bit, non-prefetchable) [size=16]
	Capabilities: [44] Power Management version 2
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=0mA PME(D0+,D1+,D2+,D3hot+,D3cold+)
		Status: D0 NoSoftRst- PME-Enable+ DSel=0 DScale=0 PME-
	Capabilities: [50] MSI: Enable+ Count=1/16 Maskable+ 64bit+
		Address: 00000000fee0300c  Data: 41d1
		Masking: 0000fffe  Pending: 00000000
	Capabilities: [6c] HyperTransport: MSI Mapping Enable+ Fixed+
	Kernel driver in use: forcedeth

And the other one connected to USB:

Bus 002 Device 003: ID 05ac:1402 Apple, Inc. Ethernet Adapter [A1277]

Both experience the reported problem.

Comment 16 b.m.kast 2013-03-10 21:06:03 UTC
Hmmmm... Kostya, what kind of RAM does your system use (DDR2/3)?

I'm running out of ideas on how to find a pattern.

Both laptops which are proven to work have Core 2 Duo CPU, one with Intel PM965 Express, one with GS45 Express, all with DDR2 memory controller.

Tom Georgoulias' laptop seems to be something around HP Pavillion dm4 (am I right?), which is probably equipped with Core i5 and DDR3. So is mine (Lenovo IdeaPad G570).

So is it possible that newer chipsets are affected only? Some code in the kernel fails (loses sync etc.) because CPU/memory/etc. works too fast?

Comment 17 Kostya Berger 2013-03-10 22:26:39 UTC
Don't know about newer chipsets, cause mine is HP-Pavilion NM791AA-ABH s3820nl/NutMeg Slimline desktop,  year of production around 2007 (not sure).

So it is DDR2 RAM and AMD Athlon 64 X2 5000+ (Brisbane, BH-G2).

there is a wireless adaptor as well (ID 15a9:0004 Gemtek WUBR-177G [Ralink RT2571W]), it uses rt73usb driver, but I keep it switched off all the time.

...Tell me, will it help if I install debuginfo for current kernel?? 
I'm ready to do what's needed to give more output.

Comment 18 Kostya Berger 2013-03-11 02:27:35 UTC
Checked it several times. This is exactly what appears in /var/log/messages at the moment when network dies:

Mar 11 06:23:55 localhost dbus-daemon[689]: dbus[689]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Mar 11 06:23:55 localhost dbus[689]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Mar 11 06:23:55 localhost PackageKit: daemon start
Mar 11 06:23:55 localhost dbus-daemon[689]: dbus[689]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Mar 11 06:23:55 localhost dbus[689]: [system] Successfully activated service 'org.freedesktop.PackageKit'

Right after the last message appears the connection gets cut off. It happens at different time after the system boot and user log in, but immediately after this network dies.

Comment 19 Jirka Klimes 2013-03-11 09:56:22 UTC
As already mentioned, the issue is most probably caused by Atheros driver - atl1c, not NM.
When reporting errors, please focus on the driver, kernel. Output of dmesg might reveal something.

alx driver is worth trying:
http://forums.fedoraforum.org/showthread.php?t=283749

These could be related as well:
https://bugzilla.kernel.org/show_bug.cgi?id=54021
http://forums.gentoo.org/viewtopic-p-7231428.html

Comment 20 Kostya Berger 2013-03-11 16:47:40 UTC
(In reply to comment #19)
> As already mentioned, the issue is most probably caused by Atheros driver -
> atl1c, not NM.
> When reporting errors, please focus on the driver, kernel. Output of dmesg
> might reveal something.
> 
> alx driver is worth trying:
> http://forums.fedoraforum.org/showthread.php?t=283749
> 
> These could be related as well:
> https://bugzilla.kernel.org/show_bug.cgi?id=54021
> http://forums.gentoo.org/viewtopic-p-7231428.html

1. Focusing on the driver, I must forward you to my comment #15 , where I mention my Ethernet hardware -- and it has nothing to do with Atheros or atl1c driver. 
It is nVidia and Apple for wired, and Ralink for WiFi. Drivers being used are: forcedeth for nVidia, asix for Apple, rt73usb for wireless. Does it really look like being caused by Atheros driver?

2. Regarding `dmesg` output: as I also mentioned in my comment #12, nothing appears in dmesg when the link dies; the system doesn't even notice anything. `ifconfig` command gives off the "active" interface together with its current address (the one it had before it died), as though nothing happened. 
Even adding "debug ignore_loglevel" to kernel command line doesn't add any relevant information.

Therefore, I'd be VERY glad to know what other debug options I could use in order to get some output either in dmesg or in /var/log/messages. Maybe install debuginfo packages could be of any assistance? You guys know better about debugging, so I rely on your advise here.

I must also add, that in my case networking works OK for about 30 minutes (not 5, like other guys have it). Also, after reactivating the dead link it then works OK without freezing at all.

PS: PackageKit, which I mentioned in comment #18, has nothing to do with it: I removed it from the system, but it didn't help.

Comment 21 Kostya Berger 2013-03-11 17:23:06 UTC
dmesg | grep forcedeth(the interface is dead now):

[    2.691815] forcedeth: Reverse Engineered nForce ethernet driver. Version 0.64.
[    2.692088] forcedeth 0000:00:0a.0: setting latency timer to 64
[    2.821363] forcedeth 0000:00:0a.0: ifname eth0, PHY OUI 0x732 @ 3, addr 00:24:8c:14:5a:7d
[    2.821367] forcedeth 0000:00:0a.0: highdma csum pwrctl mgmt gbit lnktim msi desc-v3
[   28.109655] forcedeth 0000:00:0a.0: irq 41 for MSI/MSI-X
[   28.109695] forcedeth 0000:00:0a.0 em1: MSI enabled
[ 2945.260015] forcedeth 0000:00:0a.0 em1: link down
[ 2947.081388] forcedeth 0000:00:0a.0 em1: link up

and full dmesg at the time of the death:

[ 1700.579940] scsi 5:0:0:0: Direct-Access     Generic  USB SD Reader    1.00 PQ: 0 ANSI: 0
[ 1700.580661] scsi 5:0:0:1: Direct-Access     Generic  USB CF Reader    1.01 PQ: 0 ANSI: 0
[ 1700.581529] scsi 5:0:0:2: Direct-Access     Generic  USB xD/SM Reader 1.02 PQ: 0 ANSI: 0
[ 1700.582344] scsi 5:0:0:3: Direct-Access     Generic  USB MS Reader    1.03 PQ: 0 ANSI: 0
[ 1700.584642] sd 5:0:0:0: Attached scsi generic sg2 type 0
[ 1700.585528] sd 5:0:0:1: Attached scsi generic sg3 type 0
[ 1700.586175] sd 5:0:0:2: Attached scsi generic sg4 type 0
[ 1700.586782] sd 5:0:0:3: Attached scsi generic sg5 type 0
[ 1700.591055] sd 5:0:0:0: [sdb] Attached SCSI removable disk
[ 1700.593135] sd 5:0:0:1: [sdc] Attached SCSI removable disk
[ 1700.593899] sd 5:0:0:2: [sdd] Attached SCSI removable disk
[ 1700.595879] sd 5:0:0:3: [sde] Attached SCSI removable disk
[ 2945.260015] forcedeth 0000:00:0a.0 em1: link down
[ 2947.081388] forcedeth 0000:00:0a.0 em1: link up

NOTE: this doesnt' even change while I reset the link using NM (I'm using it now).

Comment 22 b.m.kast 2013-03-11 19:33:35 UTC
I doubt that kernel debug info will help you unless (a) the kernel crashes, or (b) you want to actually debug it (I mean instruction tracing using a tool like gdb).

One suggestion (more like a wild guess).

Do the following while ethernet is working:

0) become root (e.g. using sudo -i)

1) determine ID of your ethernet card (lspci could help, but you already have it, it's after 'forcedeth' in your dmesg output: 0000:00:0a.0)

2) make an empty file (it's for 'file' command, so it does not try to use any magic numbers and you'll always get 'data' answer on binary files):

touch empty_file

3) execute a command:

find /sys/bus/pci/devices/0000\:00\:0a.0/ -not -type d | while read line; do echo -e "\n\n----------\n$line\n---\n"; if [ "$(file -m empty_file -b $line)" == "data" ]; then hexdump "$line"; else cat "$line"; fi; done > devdump-before

here 0000\:00\:0a.0 is your device id with backslash-escaped colons

After the network dies do this all again, but replace devdump-before with devdump-after in the last command. Ignore the error messages which appear during the dump.

Then you can compare two dumps using diff:

diff devdump-before devdump-after | less

Comment 23 b.m.kast 2013-03-11 19:49:19 UTC
update: there will always be differences in dumps because some of those files contain running device uptime counters, e.g. <devpath>/power/runtime_active_time.

Comment 24 Kostya Berger 2013-03-11 22:25:54 UTC
>.......................
> 
> Then you can compare two dumps using diff:
> 
> diff devdump-before devdump-after | less

The result is:
================start of diff===========
213c213
< 432      #queues/tx-0/byte_queue_limits/limit
---
> 2163
298c298
< 53       #statistics/tx_packets
---
> 1413
368c368
< 4572     #statistics/rx_bytes
---
> 2436121
389c389
< 35       #statistics/rx_packets
---
> 1977
396c396
< 5073     #statistics/tx_bytes
---
> 134764
528c528
< 156854   #power/runtime_active_time
---
> 4193027
================end of diff output==================
Don't quite uderstand what these strings like "528c528" mean, there is nothing like that in "dump" files. 
But the differing numbers are, as you told, statistics, so I just commented here which ones are which. Sure they changed, as some 30 minutes passed between the two measurements and network was in use all the time.

What may this all be suggesting?

Comment 25 b.m.kast 2013-03-11 23:45:29 UTC
Well... I hoped that it could indicate a change in some internal state variable of the driver, but no luck, sorry for bad advice :(

AFAIK, XXXcXXX just shows the line number where the difference was encountered, number before 'c' is a position in the old file, and the number after it is in the new one.

Comment 26 b.m.kast 2013-03-12 00:00:30 UTC
btw, byte queue limits (in the diff) are mentioned here

https://kernel.googlesource.com/pub/scm/linux/kernel/git/chanwoo/charger-manager/+/98260daa184c4a171834463cf85ab3a2c509d983

which happens to be mentioned in this change log

https://www.kernel.org/pub/linux/kernel/projects/backports/stable/v3.7-rc1/ChangeLog-3.7-rc1-6

I don't know if it says something, but can an error in the data queue implementation cause connection to become stuck until we physically disconnect it, thus forcibly emptying the (hardware) queue? So - could a patch merged into master kernel branch in transition from 3.6 to 3.7 break something?

Again - that's just another wild guess.

Also, openSUSE live CD gives me about 10 minutes before the network dies, sometimes I don't even have enough time to download flash player to start watching video on youtube, while on Fedora 18 neither browsing nor streaming videos is enough to kill the connection, even flood pinging a host on my home LAN does not cause it to hang. But starting a massive find/grep on a NFS share does. (FWIW, NFS works via UDP rather than TCP in my configuration.)

Comment 27 Kostya Berger 2013-03-12 05:44:36 UTC
Right, I also thought about queue limits after seeing the diff results.

I'm running Fedora 18 and during the last few tests I purposefully ran flash player watching long youtube videos -- long enough to last until network dies. And when it happens the video just abruptly stops, showing "snow" screen with error message instead.

Tonight will try with 3.6 kernels to make sure.

Comment 28 Kostya Berger 2013-03-12 21:12:18 UTC
OK, done. 
This happens with kernel 3.6.10-4.fc18.x86_64 just as well.
 
And it DIDN'T happen when that was my default kernel, before the later kernel updates became available. Can confirm this because quite recently I did a network installation on a notebook, which was connected to Internet through the computer, where this problem happens. The process took quite some time and I added packages later, too. All the while no networking problems had been noticed. 

Therefore, the cause, it seems, is not in the kernel. At least, it has to do with some later updates.

Comment 29 b.m.kast 2013-03-12 21:43:53 UTC
Try examining /var/log/yum.log for the day since when weird things started to happen.

BTW, my system currently has several pending updates which I uncheck every time I start Apper, including:

* kernel (including source, headers, symbols, PAE and non-PAE flavors, etc.)
* anything VirtualBox-related (it requires a kernel module, which does not build since I've downgraded the kernel to 3.6.11, and I do not have time to find out why, so I stick to an old version, which works well)
* libnl3 (that means Kernel Netlink Sockets, I just unsure if it has anything to do with this situation)

As long as I do not upgrade these packages, network does not fail. I do not know exactly which one of these packages causes ethernet failures.

But that's my 'stable' F17 system, I didn't try downgrading any packages on 'experimental' F18 installed on the same laptop (which suffers from networking problems mentioned here). So I can't tell for sure whether downgrading helps you. Still, I recall that wired connection allowed me to download a gigabyte of updates after initial F18 installation from the DVD, so the original media presumably does not contain the problematic update.

Comment 30 Tom Georgoulias 2013-03-12 22:32:49 UTC
For what it's worth, just in case it gets lost in the updates, I never had this problem on Fedora 17.  As soon as I upgraded my laptop to Fedora 18, using the fedup tool to do the upgrade, I started experiencing it.  My laptop has never worked since I upgraded to Fedora 18.  It doesn't matter what kernel-PAE rpm I've tried, nothing.  The only way I can keep my wired network working is if I use the keyboard kill switch and shut off the wifi radio.

Comment 31 Kostya Berger 2013-03-12 22:55:20 UTC
Well mine isn't yet lost in the updates, but there is another problem. I vaguely recall this problem having started since I installed "KDE Plasma Workspaces". I can identify the yum transaction ID via `yum history` option: it is 405 for KDE installation, but the last and "current" one is 428. 

Will try undoing all the updates between 428 and 405, then try undoing 405 itself.
(The command `yum group remove "KDE Plasma Workspaces"`, offers such a devastating dependency removal, that I tremble at the very thought LOL.)

Comment 32 b.m.kast 2013-03-12 23:19:09 UTC
You don't have to remove packages, yum has a downgrade command:

yum downgrade PACKAGENAME[-VERSION]

If you do not specify VERSION. it will downgrade to previous one (if it's still in repos).

The following command can be used to list all available versions of a package (well, actually all packages starting with PACKAGENAME):

yum list available --showduplicates 'PACKAGENAME*'

showduplicates instructs yum to show all versions of a package (it shows the latest one only by default).

Also, I'd try downgrading system-related packages first, I doubt that WM/DE has anything to do with this.

Comment 33 Kostya Berger 2013-03-15 23:34:18 UTC
Decided not to do the downgrade cause it doesn't give the result I wanted. Instead I'll only add this last stroke to the description of the problem:

If I restart my wired network connection IMMEDIATELY after having logged in my GNOME desktop and BEFORE it dies, it then works ok and the problem never happens. 
Does this suggest anything?

Comment 34 Kostya Berger 2013-03-18 21:17:02 UTC
Well well, it seems I've come up with some result after all. In my case it seems to have been linked to problems with system time. It must have somehow affected the dhclient's function of renewing the dhcp lease, because the time settings were wrong. UTC time was 4 hrs ahead of my local time, while it had to be this much behind.

So, I disabled the GNOME date&time "Network Time" option, then set hardware clock to localtime (hwclock --localtime) , then once again reset the local time to the correct value in GNOME date&time settings.

Now after reboot the thing is working OK. More than 2 hrs passed and network is OK, and now in /var/log/messages I'm seeing the dhclient messages about renewal of the lease, which corresponds with the time reflected in the corresponding /var/lib/NetworkManager/*-em1.lease file.

I'll post if that change for the better doesn't persist, though.

Comment 35 Tom Georgoulias 2013-04-21 12:57:50 UTC
This is still a problem for me, even with the latest kernel.

3.8.7-201.fc18.i686.PAE

What can I do to help this bug report progress?  My wired NIC has been useless since I started using Fedora 18.

Comment 36 b.m.kast 2013-04-21 14:32:43 UTC
Yep, for me too, still here with 3.8.8.

By the way:

* Executing

echo 10 > /proc/sys/kernel/printk

does not add any useful info on that bug to dmesg. (Do I need a debug build of the kernel?)

* Limiting interface speed to 100 Mbps using

ethtool -s em1 speed 100 duplex full autoneg off

does not help too.

Comment 37 Tom Georgoulias 2013-05-01 02:16:55 UTC
Still a problem on kernel-PAE-3.8.8-203.fc18.i686.

Comment 38 b.m.kast 2013-05-01 11:14:40 UTC
I've built 3.10.0-0.rc0.git7.1.fc18.i686.PAE from source RPM downloaded from Koji, the problem is still here.

I've done a quick dump of device parameters tree in /sys using the following command:

find /sys/class/net/em1/device/ -type f|while read line; do echo "$line###$(cat $line)"; done > em1.pre.dev.dump

before the device stopped responding and after that, replacing pre with post.

Then I did the diff of those two files. The most interesting thing was /sys/class/net/em1/device/config, which is binary, so I did some manipulations in Okteta to extract its contents from the dump, then compared the hexdump outputs. The files were differing only in byte with offset 0x3D, which was 0xC0 before the failure and become 0xC1 after that.

Other differing files seem to be just statistic counters:

# diff em1.{pre,post}.dev.dump

37c37
< /sys/class/net/em1/device/net/em1/statistics/rx_fifo_errors###0
---
> /sys/class/net/em1/device/net/em1/statistics/rx_fifo_errors###154
42c42
< /sys/class/net/em1/device/net/em1/statistics/tx_packets###406
---
> /sys/class/net/em1/device/net/em1/statistics/tx_packets###888
44,45c44,45
< /sys/class/net/em1/device/net/em1/statistics/rx_missed_errors###0
< /sys/class/net/em1/device/net/em1/statistics/rx_over_errors###0
---
> /sys/class/net/em1/device/net/em1/statistics/rx_missed_errors###154
> /sys/class/net/em1/device/net/em1/statistics/rx_over_errors###154
52c52
< /sys/class/net/em1/device/net/em1/statistics/rx_bytes###54991
---
> /sys/class/net/em1/device/net/em1/statistics/rx_bytes###446898
55,56c55,56
< /sys/class/net/em1/device/net/em1/statistics/rx_packets###378
< /sys/class/net/em1/device/net/em1/statistics/tx_bytes###56514
---
> /sys/class/net/em1/device/net/em1/statistics/rx_packets###895
> /sys/class/net/em1/device/net/em1/statistics/tx_bytes###110231
76c76
< /sys/class/net/em1/device/power/runtime_active_time###612073
---
> /sys/class/net/em1/device/power/runtime_active_time###840932

Comment 39 b.m.kast 2013-05-01 11:44:22 UTC
Update: sorry, that binary dump seems to be useless because cat utility cuts zero bytes from the stream. Please tell me if that config file (or some other one under /sys or /proc) can contain any useful information, so I can capture and compare its contents.

Also, dmesg does not seem to contain anything relevant, except for the line:

atl1c 0000:07:00.0: vpd r/w failed.  This is likely a firmware bug on this device.  Contact the card vendor for a firmware update.

which appears in the output when I try to read /sys/class/net/em1/device/vpd.

Comment 40 b.m.kast 2013-05-01 19:12:17 UTC
Reverting changes in atl1c driver retrieved by command

git diff v3.6.11..v3.7 drivers/net/ethernet/atheros/atl1c/

from the repo cloned from git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git didn't help either. The kernel with reverse patch applied has the problem too.

Comment 41 Felix Kaechele 2013-05-14 21:16:40 UTC
Seeing similar behavior as well: With WiFi or LAN used exclusively everything works. When using both simultaneously on the same network it stops working. I'll need to test if that still applies when WiFi and LAN are connected to different physical networks.
This Problem started for me with Fedora 18. Fedora 17 worked (and still works, when booted from a live image) well in my current setup.

Kernel: 3.9.1-301.fc19.x86_64

relevant lspci entries:

00:19.0 Ethernet controller: Intel Corporation 82579LM Gigabit Network Connection (rev 04)
	Subsystem: Lenovo Device 21f3
	Flags: bus master, fast devsel, latency 0, IRQ 44
	Memory at f2500000 (32-bit, non-prefetchable) [size=128K]
	Memory at f253b000 (32-bit, non-prefetchable) [size=4K]
	I/O ports at 5080 [size=32]
	Capabilities: [c8] Power Management version 2
	Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
	Capabilities: [e0] PCI Advanced Features
	Kernel driver in use: e1000e

03:00.0 Network controller: Intel Corporation Centrino Advanced-N 6205 [Taylor Peak] (rev 34)
	Subsystem: Intel Corporation Centrino Advanced-N 6205 AGN
	Flags: bus master, fast devsel, latency 0, IRQ 45
	Memory at f1c00000 (64-bit, non-prefetchable) [size=8K]
	Capabilities: [c8] Power Management version 3
	Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
	Capabilities: [e0] Express Endpoint, MSI 00
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [140] Device Serial Number 8c-70-5a-ff-ff-92-da-90
	Kernel driver in use: iwlwifi

Comment 42 Felix Kaechele 2013-05-14 21:38:19 UTC
But I guess my bug is more likely #886312

Comment 43 b.m.kast 2013-05-17 19:35:48 UTC
After upgrade to kernel 3.9.2 the bug seems to be gone. I'll post here later if anything bad happens again.

Comment 44 b.m.kast 2013-05-17 21:12:28 UTC
It fails again :(

Comment 45 Tom Georgoulias 2013-05-18 12:43:47 UTC
Can we reopen this bug?  It remains a problem with the latest kernel for me and even the person who said it was fixed for them is seeing it still.

Comment 46 b.m.kast 2013-05-18 16:09:01 UTC
That's why I thought it's fixed:

https://bugzilla.novell.com/show_bug.cgi?id=812116#c6

It can work for a long time after clean reboot as long as it remains active. The problem is probably related to some kind of power save / suspend state of the NIC, so once it powers down due to inactivity it begins to hang randomly. (Just guessing.)


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