Bug 804195

Summary: Wifi deauthenticates after IPv4 DHCPREQUEST when IPv6 enabled and present
Product: [Fedora] Fedora Reporter: Pavel Šimerda (pavlix) <psimerda>
Component: NetworkManagerAssignee: Dan Williams <dcbw>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 17CC: dcbw
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-03-20 20:42:45 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Pavel Šimerda (pavlix) 2012-03-16 19:42:28 UTC 
Hello,

I'm researching disconnects and reconnects on Fedora 17
on my Lenovo x61 with iwl3945. It may be hard to reproduce.
Wireless disconnets happen many times a minute, so the network is
unusable.

Reproducability seems to depend on the following circumstances:

* wireless interface
* IPv6 enabled

It may also related to the following (very wild guesses):

* IPv6 (radvd) present on the network
* wireless and wired interfaces are connected to the same network
* I may have some packages from the testing repo (see versions below)

Workarounds:

a) use wired ethernet
b) switch IPv6 to “Ignore”

Versions:

kernel-3.3.0-0.rc6.git0.2.fc17.x86_64
NetworkManager-0.9.3-0.2.git20120215.fc17.x86_64
dhclient-4.2.3-18.P2.fc17.x86_64
wpa_supplicant-1.0-0.2.fc17.x86_64

Debug:

Mar 16 20:14:25 dragon dhclient[16280]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 (xid=0x2876a18d)
Mar 16 20:14:25 dragon kernel: [ 2120.502132] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 133
Mar 16 20:14:26 dragon kernel: [ 2120.928473] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 134
Mar 16 20:14:27 dragon kernel: [ 2121.930928] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 135
Mar 16 20:14:27 dragon kernel: [ 2122.142126] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 136
Mar 16 20:14:28 dragon kernel: [ 2123.156952] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 137
Mar 16 20:14:29 dragon kernel: [ 2123.932475] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 138
Mar 16 20:14:29 dragon kernel: [ 2124.407434] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 139
Mar 16 20:14:29 dragon kernel: [ 2124.416851] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 140
Mar 16 20:14:29 dragon kernel: [ 2124.424859] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 141
Mar 16 20:14:29 dragon kernel: [ 2124.435856] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 142
Mar 16 20:14:29 dragon kernel: [ 2124.446749] ieee80211 phy0: U il_update_qos send QoS cmd with Qos active=0 FLAGS=0x0
Mar 16 20:14:29 dragon kernel: [ 2124.449591] wlan0: deauthenticating from f4:ec:38:a5:4f:84 by local choice (reason=3)
Mar 16 20:14:29 dragon kernel: [ 2124.453266] wlan0: moving STA f4:ec:38:a5:4f:84 to state 2
Mar 16 20:14:29 dragon kernel: [ 2124.453269] wlan0: moving STA f4:ec:38:a5:4f:84 to state 1
Mar 16 20:14:29 dragon kernel: [ 2124.453272] wlan0: moving STA f4:ec:38:a5:4f:84 to state 0
Mar 16 20:14:29 dragon kernel: [ 2124.453671] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 15
Mar 16 20:14:29 dragon kernel: [ 2124.456264] cfg80211: Calling CRDA to update world regulatory domain
Mar 16 20:14:29 dragon kernel: [ 2124.467086] cfg80211: World regulatory domain updated:
Mar 16 20:14:29 dragon kernel: [ 2124.467091] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain

NetworkManager.conf:

[main]
plugins=ifcfg-rh
[logging]
level=DEBUG
domains=IP4,IP6,DHCP4,DHCP6,WIFI,HW,WIFI_SCAN,BT,SUPPLICANT,SUSPEND,CORE,DEVICE

iwl3945:

modprobe iwl3945 debug=0xc0000000
Comment 1 Pavel Šimerda (pavlix) 2012-03-16 19:44:59 UTC 
Debug when IPv6 is set to Ignore and connection is OK:

Mar 16 20:14:39 dragon dhclient[16309]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 (xid=0x1d2eb919)
Mar 16 20:14:39 dragon kernel: [ 2133.883024] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 145
Mar 16 20:14:39 dragon sendmail[16311]: starting daemon (8.14.5): SMTP+queueing@01:00:00
Mar 16 20:14:39 dragon sm-msp-queue[16340]: starting daemon (8.14.5): queueing@01:00:00
Mar 16 20:14:39 dragon sendmail[16367]: starting daemon (8.14.5): SMTP+queueing@01:00:00
Mar 16 20:14:39 dragon systemd[1]: PID file /run/sendmail.pid not readable (yet?) after start.
Mar 16 20:14:40 dragon sm-msp-queue[16394]: starting daemon (8.14.5): queueing@01:00:00
Mar 16 20:14:40 dragon systemd[1]: PID 16340 read from file /run/sm-client.pid does not exist.
Mar 16 20:14:47 dragon dhclient[16309]: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 (xid=0x1d2eb919)
Mar 16 20:14:47 dragon kernel: [ 2141.938856] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 146
Mar 16 20:14:47 dragon dhclient[16309]: DHCPACK from 84.246.161.81 (xid=0x1d2eb919)
Mar 16 20:14:47 dragon dhclient[16309]: bound to 84.246.161.90 -- renewal in 17693 seconds.
Mar 16 20:14:47 dragon rsyslogd-2177: imuxsock lost 6017 messages from pid 15350 due to rate-limiting
Mar 16 20:14:47 dragon NetworkManager[15350]: <info> (wlan0): DHCPv4 state changed preinit -> reboot
Mar 16 20:14:47 dragon NetworkManager[15350]: <debug> [1331925287.223823] [nm-device.c:1435] dhcp4_state_changed(): (wlan0): new DHCPv4 client state 8
Comment 2 Pavel Šimerda (pavlix) 2012-03-16 20:18:16 UTC 
A different debug excerpt (same situation):

Mar 16 21:15:34 dragon kernel: [ 5789.046265] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 60
Mar 16 21:15:34 dragon kernel: [ 5789.046541] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 61
Mar 16 21:15:34 dragon kernel: [ 5789.233310] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 62
Mar 16 21:15:34 dragon kernel: [ 5789.233393] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 63
Mar 16 21:15:36 dragon NetworkManager[19100]: <debug> [1331928936.409883] [nm-netlink-monitor.c:163] link_msg_handler(): netlink link message: iface idx 12 flags 0x1003
Mar 16 21:15:36 dragon kernel: [ 5791.155862] wlan0: deauthenticating from f4:ec:38:a5:4f:84 by local choice (reason=2)
Mar 16 21:15:36 dragon kernel: [ 5791.155926] wlan0: authenticate with f4:ec:38:a5:4f:84 (try 1)
Mar 16 21:15:36 dragon kernel: [ 5791.156753] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 64
Mar 16 21:15:36 dragon kernel: [ 5791.157692] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 65
Mar 16 21:15:36 dragon kernel: [ 5791.158616] wlan0: authenticated
Mar 16 21:15:36 dragon kernel: [ 5791.158782] wlan0: failed to insert Dummy STA entry for the AP (error -17)
Mar 16 21:15:36 dragon NetworkManager[19100]: <info> (wlan0): supplicant interface state: associating -> authenticating
Mar 16 21:15:36 dragon NetworkManager[19100]: <info> (wlan0): supplicant interface state: authenticating -> associating
Mar 16 21:15:36 dragon kernel: [ 5791.289749] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 66
Mar 16 21:15:36 dragon kernel: [ 5791.290388] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 67
Mar 16 21:15:36 dragon kernel: [ 5791.353432] ieee80211 phy0: I il3945_hdl_tx Tx queue reclaim 68
Comment 3 Pavel Šimerda (pavlix) 2012-03-17 02:00:40 UTC 
Update to NetworkManager-0.9.3.995-0.6.git20120314.fc17.x86_64 from updates-testing seems to work.

More specifically, I'm now using the following versions of packages:

kernel-3.3.0-0.rc7.git0.3.fc17.x86_64 (updates-testing)
NetworkManager-0.9.3.995-0.6.git20120314.fc17.x86_64 (updates-testing)
dhclient-4.2.3-18.P2.fc17.x86_64
wpa_supplicant-1.0-0.2.fc17.x86_64
Comment 4 Pavel Šimerda (pavlix) 2012-03-20 20:42:45 UTC 
I'm now using NetworkManager-0.9.3.997-0.7.fc17.x86_64 from updates-testing that is now getting to stable. Even previous version worked well.

All disconnect issues are now fixed except RDNSS expiry as described in bug 753482. Closing.