Bug 923981

Summary: iwl3945 broken in 3.9.0 kernel
Product: [Fedora] Fedora Reporter: Jeff Bastian <jbastian>
Component: kernelAssignee: Stanislaw Gruszka <sgruszka>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 19CC: gansalmon, itamar, jonathan, kernel-maint, madhu.chinakonda, p.finizio, sgruszka
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard: abrt_hash:8c09b45e5b39ebb95552f30c49647b226ec5c154
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-04-04 12:57:24 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
File: dmesg none

Description Jeff Bastian 2013-03-20 20:27:06 UTC 
Description of problem:
I did a yum update to Fedora 19 and the wireless network failed to work.

Additional info:
WARNING: at drivers/net/wireless/iwlegacy/common.c:3254 il_tx_cmd_complete+0x3cc/0x410 [iwlegacy]()
Hardware name: 6369Y11
wrong command queue 0 (should be 4), sequence 0x0 readp=0 writep=0
Modules linked in: fuse ebtable_nat xt_CHECKSUM bridge stp llc nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 iptable_nat nf_nat_ipv4 nf_nat iptable_mangle nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ebtable_filter ebtables ip6table_filter ip6_tables iTCO_wdt iTCO_vendor_support arc4 iwl3945 snd_hda_codec_analog iwlegacy coretemp btusb microcode bluetooth joydev tpm_tis nsc_ircc i2c_i801 snd_hda_intel irda tpm mac80211 snd_hda_codec tpm_bios thinkpad_acpi crc_ccitt snd_hwdep snd_seq snd_seq_device cfg80211 e1000e rfkill snd_pcm ptp pps_core snd_page_alloc lpc_ich mfd_core snd_timer snd soundcore vhost_net tun macvtap macvlan kvm_intel kvm uinput i915 i2c_algo_bit drm_kms_helper yenta_socket drm i2c_core video
Pid: 556, comm: NetworkManager Not tainted 3.9.0-0.rc3.git0.3.fc19.x86_64 #1
Call Trace:
 <IRQ>  [<ffffffffa0536100>] ? il_tx_cmd_complete+0x370/0x410 [iwlegacy]
 [<ffffffff8105c9d0>] warn_slowpath_common+0x70/0xa0
 [<ffffffff8105ca4c>] warn_slowpath_fmt+0x4c/0x50
 [<ffffffff8108a2a4>] ? __wake_up+0x44/0x50
 [<ffffffffa053615c>] il_tx_cmd_complete+0x3cc/0x410 [iwlegacy]
 [<ffffffffa04ded31>] il3945_irq_tasklet+0x531/0xbc0 [iwl3945]
 [<ffffffff8106525e>] tasklet_action+0x6e/0x110
 [<ffffffff810653ef>] __do_softirq+0xef/0x240
 [<ffffffff810656c5>] irq_exit+0xa5/0xb0
 [<ffffffff8164ff96>] do_IRQ+0x56/0xc0
 [<ffffffff8164626d>] common_interrupt+0x6d/0x6d
 <EOI>  [<ffffffff81645c41>] ? _raw_spin_unlock_irqrestore+0x11/0x20
 [<ffffffffa05333d5>] il_rd_prph+0x75/0x90 [iwlegacy]
 [<ffffffffa04e18d5>] il3945_load_bsm+0x305/0x3b0 [iwl3945]
 [<ffffffffa04dd19a>] __il3945_up+0x15a/0x330 [iwl3945]
 [<ffffffffa04dddb0>] il3945_mac_start+0x540/0xf90 [iwl3945]
 [<ffffffffa027d113>] ? cfg80211_netdev_notifier_call+0x453/0x630 [cfg80211]
 [<ffffffff815a6048>] ? inetdev_event+0x38/0x520
 [<ffffffffa0386061>] ieee80211_do_open+0x2e1/0xbb0 [mac80211]
 [<ffffffff81649ebc>] ? notifier_call_chain+0x4c/0x70
 [<ffffffffa0386999>] ieee80211_open+0x69/0x70 [mac80211]
 [<ffffffff8153c40f>] __dev_open+0xbf/0x140
 [<ffffffff8153c6c2>] __dev_change_flags+0x92/0x170
 [<ffffffff8153c83d>] dev_change_flags+0x1d/0x60
 [<ffffffff81549909>] do_setlink+0x339/0xa00
 [<ffffffff81548f44>] ? rtnl_fill_ifinfo+0x974/0xc10
 [<ffffffff8112ebbd>] ? find_get_page+0x2d/0x100
 [<ffffffff8130d142>] ? nla_parse+0x32/0xe0
 [<ffffffff8130d142>] ? nla_parse+0x32/0xe0
 [<ffffffff8154ac64>] rtnl_newlink+0x394/0x5e0
 [<ffffffff81292dae>] ? selinux_capable+0x2e/0x40
 [<ffffffff81547873>] rtnetlink_rcv_msg+0x113/0x310
 [<ffffffff8128fe75>] ? sock_has_perm+0x75/0x90
 [<ffffffff81547760>] ? rtnetlink_rcv+0x30/0x30
 [<ffffffff81565639>] netlink_rcv_skb+0xa9/0xc0
 [<ffffffff81547758>] rtnetlink_rcv+0x28/0x30
 [<ffffffff81565010>] netlink_unicast+0x180/0x230
 [<ffffffff815653bf>] netlink_sendmsg+0x2ff/0x3c0
 [<ffffffff8152216a>] sock_sendmsg+0xaa/0xe0
 [<ffffffff815222a9>] ? sock_recvmsg+0xb9/0xf0
 [<ffffffff81530266>] ? verify_iovec+0x56/0xd0
 [<ffffffff81522c4e>] __sys_sendmsg+0x39e/0x3b0
 [<ffffffff8152438d>] ? sys_sendto+0x17d/0x1c0
 [<ffffffff815247e2>] sys_sendmsg+0x42/0x80
 [<ffffffff8164e359>] system_call_fastpath+0x16/0x1b

Potential duplicate: bug 870784
Comment 1 Jeff Bastian 2013-03-20 20:27:11 UTC 
Created attachment 713460 [details]
File: dmesg
Comment 2 Jeff Bastian 2013-03-20 20:40:30 UTC 
I'm also seeing this set of messages repeating over and over again every 63 seconds in my dmesg logs while the wifi is enabled:

[  761.564069] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
[  761.564082] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[  761.594165] iwl3945 0000:03:00.0: Microcode SW error detected. Restarting 0x82000008.
[  761.594188] iwl3945 0000:03:00.0: Loaded firmware version: 15.32.2.9
[  761.594229] iwl3945 0000:03:00.0: Start IWL Error Log Dump:
[  761.594241] iwl3945 0000:03:00.0: Status: 0x000202E4, count: 1
[  761.594247] iwl3945 0000:03:00.0: Desc       Time       asrtPC  blink2 ilink1  nmiPC   Line
[  761.594477] iwl3945 0000:03:00.0: SYSASSERT     (0x5) 0000590401 0x008B6 0x00274 0x00320 0x00C92 116

[  761.594495] iwl3945 0000:03:00.0: Error Reply type 0x00000005 cmd C_TX (0x1C) seq 0x0000 ser 0x00740000
[  761.595201] iwl3945 0000:03:00.0: Can't stop Rx DMA.
[  761.596806] ieee80211 phy0: Hardware restart was requested
...
[  824.565080] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
...
[  887.858079] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
...

If I disable wifi, I stop seeing the above messages.
Comment 3 Jeff Bastian 2013-03-20 23:33:55 UTC 
I booted into the Fedora 18 kernel 3.8.3-203.fc18 and the wifi works fine: no dmesg errors, no firmware problems, it just works.

Something broke in the iwl3945 driver with the 3.9.0-0.rc3.git0.3.fc19 kernel.
Comment 4 Stanislaw Gruszka 2013-03-21 12:04:47 UTC 
This will be fixed in 3.9-rc4 or -rc5 kernel, I already posted a fix
http://marc.info/?l=linux-wireless&m=136326173406219&w=2
Comment 5 Jeff Bastian 2013-04-04 12:57:24 UTC 
I installed kernel-3.9.0-0.rc5.git1.301.fc19.x86_64 and wireless is working again.  Thanks!
Comment 6 Piero Finizio 2013-04-08 18:49:34 UTC 
With kernel 3.9.0-0.rc6.git0.1.fc19.i686 I have this by dmesg:

...  
[  683.794219] iwl3945 0000:03:00.0: Queue 2 stuck for 3475 ms.
[  684.018126] iwl3945 0000:03:00.0: Error sending C_REM_STA: time out after 500ms.
[  684.018144] iwl3945 0000:03:00.0: Error removing station 78:f5:fd:d4:28:0d
[  684.295204] iwl3945 0000:03:00.0: Queue 0 stuck for 3512 ms.
[  684.295219] iwl3945 0000:03:00.0: Queue 2 stuck for 3976 ms.
[  684.518112] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
[  684.518129] iwl3945 0000:03:00.0: Error setting new configuration (-110).
[  684.796184] iwl3945 0000:03:00.0: Queue 0 stuck for 4013 ms.
[  684.796194] iwl3945 0000:03:00.0: On demand firmware reload
[  685.018628] iwl3945 0000:03:00.0: Error sending C_RXON_ASSOC: time out after 500ms.
[  685.518186] iwl3945 0000:03:00.0: Error sending C_RXON_ASSOC: time out after 500ms.
[  685.560433] cfg80211: Calling CRDA to update world regulatory domain
[  685.581298] cfg80211: World regulatory domain updated:
[  685.581303] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  685.581306] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  685.581309] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  685.581312] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[  685.581315] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  685.581318] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  685.581336] cfg80211: Calling CRDA for country: IT
[  685.604324] cfg80211: Regulatory domain changed to country: IT
[  685.604330] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  685.604333] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  685.604335] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  685.604338] cfg80211:   (5250000 KHz - 5330000 KHz @ 40000 KHz), (N/A, 2000 mBm)
[  685.604340] cfg80211:   (5490000 KHz - 5710000 KHz @ 40000 KHz), (N/A, 2700 mBm)
[  685.604343] cfg80211:   (57240000 KHz - 65880000 KHz @ 2160000 KHz), (N/A, 4000 mBm)
[  685.630603] ieee80211 phy0: Hardware restart was requested
[  689.081512] wlan0: authenticate with 78:f5:fd:d4:28:0d
[  689.109468] wlan0: send auth to 78:f5:fd:d4:28:0d (try 1/3)
[  689.286091] wlan0: authenticated
[  689.287550] wlan0: associate with 78:f5:fd:d4:28:0d (try 1/3)
[  689.488038] wlan0: associate with 78:f5:fd:d4:28:0d (try 2/3)
[  689.689461] wlan0: associate with 78:f5:fd:d4:28:0d (try 3/3)
[  689.756038] wlan0: RX AssocResp from 78:f5:fd:d4:28:0d (capab=0x401 status=0 aid=1)
[  689.794251] wlan0: associated
[  702.477520] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
[  702.477537] iwl3945 0000:03:00.0: Error clearing ASSOC_MSK on current configuration (-110).
[  703.375060] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
[  703.375070] iwl3945 0000:03:00.0: Error clearing ASSOC_MSK on current configuration (-110).
[  703.783627] iwl3945 0000:03:00.0: Queue 4 stuck for 2007 ms.
[  703.783635] iwl3945 0000:03:00.0: On demand firmware reload
[  704.271912] iwl3945 0000:03:00.0: Error sending C_RXON: time out after 500ms.
[  704.271923] iwl3945 0000:03:00.0: Error clearing ASSOC_MSK on current configuration (-110).
[  704.322323] ieee80211 phy0: Hardware restart was requested
...

This happens everytime I use Second Life viewer on sims with heavy traffic (a 
lot of data are downloaded and uploaded). I notice on traffic monitor widget the frequent disconnections of  Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan]. 
At last I get forced logout.
Comment 7 Stanislaw Gruszka 2013-04-09 08:42:09 UTC 
Different issue, open a separate bug report for it.