454422 – iwl4965 kill switch bugs kernel

Bug 454422 - iwl4965 kill switch bugs kernel

Summary: iwl4965 kill switch bugs kernel

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	kernel
Sub Component:
Version:	9
Hardware:	x86_64
OS:	Linux
Priority:	low
Severity:	medium
Target Milestone:	---
Assignee:	John W. Linville
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2008-07-08 12:29 UTC by Axel
Modified:	2008-12-11 18:53 UTC (History)
CC List:	2 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2008-12-11 18:53:29 UTC
Type:	---
Dependent Products:

Attachments	(Terms of Use)
Commented log file documenting the bug (15.80 KB, text/plain) 2008-07-08 12:33 UTC, Axel	no flags	Details
Add an attachment (proposed patch, testcase, etc.)

Description Axel 2008-07-08 12:29:37 UTC

Description of problem:

Certain sequences of iwl4965 kill switch and wlan activation / deactivation lead
to kernel oops.  Iwl4965 becomes disfunctional.

Version-Release number of selected component (if applicable):

uname -a
Linux localhost.localdomain 2.6.25.9-76.fc9.x86_64 #1 SMP Fri Jun 27 15:58:30
EDT 2008 x86_64 x86_64 x86_64 GNU/Linux

How reproducible:

Well (did not try it all to often)

Steps to Reproduce:

The following is an except of /var/log/messages with annotations of what I did.
 I started with a freshly booted kernel, NetworkManager on, kill switch on. 
There was no wireless connection available, so the interface never connected to
anything.

service NetworkManager restart

Jul  6 00:08:59 localhost NetworkManager: <WARN>  nm_signal_handler(): Caught
signal 15, shutting down normally.
Jul  6 00:08:59 localhost NetworkManager: <info>  (eth0): now unmanaged
Jul  6 00:08:59 localhost NetworkManager: <info>  (eth0): device state change: 2
-> 1
Jul  6 00:08:59 localhost NetworkManager: <info>  (eth0): cleaning up...
Jul  6 00:08:59 localhost NetworkManager: <info>  (eth0): taking down device.
Jul  6 00:08:59 localhost kernel: sky2 eth0: disabling interface
Jul  6 00:08:59 localhost NetworkManager: <info>  (wlan0): now unmanaged
Jul  6 00:08:59 localhost NetworkManager: <info>  (wlan0): device state change:
3 -> 1
Jul  6 00:08:59 localhost NetworkManager: <info>  (wlan0): cleaning up...
Jul  6 00:08:59 localhost NetworkManager: <info>  (wlan0): taking down device.
Jul  6 00:09:02 localhost kernel: ACPI: PCI interrupt for device 0000:03:00.0
disabled
Jul  6 00:09:02 localhost NetworkManager: <info>  starting...
Jul  6 00:09:02 localhost NetworkManager: <info>  Found radio killswitch
/org/freedesktop/Hal/devices/ipw_wlan_switch
Jul  6 00:09:02 localhost NetworkManager: <info>  eth0: Device is
fully-supported using driver 'sky2'.
Jul  6 00:09:02 localhost NetworkManager: <info>  Found new Ethernet device 'eth0'.
Jul  6 00:09:02 localhost NetworkManager: <info>  (eth0): exported as
/org/freedesktop/Hal/devices/net_00_0b_97_55_82_24
Jul  6 00:09:02 localhost NetworkManager: <info>  wlan0: Device is
fully-supported using driver 'iwl4965'.
Jul  6 00:09:02 localhost NetworkManager: <info>  wlan0: driver supports SSID
scans (scan_capa 0x01).
Jul  6 00:09:02 localhost NetworkManager: <info>  Found new wireless (802.11)
device 'wlan0'.
Jul  6 00:09:02 localhost NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/Hal/devices/net_00_1f_3b_71_d2_a5
Jul  6 00:09:06 localhost kernel: sky2 eth0: enabling interface
Jul  6 00:09:06 localhost NetworkManager: <info>  (eth0): device state change: 1
-> 2
Jul  6 00:09:06 localhost NetworkManager: <info>  (eth0): bringing up device.
Jul  6 00:09:06 localhost kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  6 00:09:06 localhost NetworkManager: <info>  (eth0): preparing device.
Jul  6 00:09:06 localhost NetworkManager: <info>  (eth0): deactivating device.
Jul  6 00:09:06 localhost kernel: ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 18
(level, low) -> IRQ 18
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): device state change:
1 -> 2
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): bringing up device.
Jul  6 00:09:06 localhost kernel: Registered led device: iwl-phy0:radio
Jul  6 00:09:06 localhost kernel: Registered led device: iwl-phy0:assoc
Jul  6 00:09:06 localhost kernel: Registered led device: iwl-phy0:RX
Jul  6 00:09:06 localhost kernel: Registered led device: iwl-phy0:TX
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): preparing device.
Jul  6 00:09:06 localhost kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): deactivating device.
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): device state change:
2 -> 3
Jul  6 00:09:06 localhost NetworkManager: <info>  (wlan0): supplicant interface
state change: 1 -> 2.
Jul  6 00:09:08 localhost NetworkManager: <WARN>  killswitch_getpower_reply():
Error getting killswitch power: hal-ipw-killswitch-linux returned 255.

I (kill) switch wlan off

Jul  6 00:09:25 localhost kernel: iwl4965: Radio Frequency Kill Switch is On:
Jul  6 00:09:25 localhost kernel: Kill switch must be turned off for wireless
networking to work.

I (kill) switch wlan on

Jul  6 00:09:32 localhost kernel: Registered led device: iwl-phy0:radio
Jul  6 00:09:32 localhost kernel: Registered led device: iwl-phy0:assoc
Jul  6 00:09:32 localhost kernel: Registered led device: iwl-phy0:RX
Jul  6 00:09:32 localhost kernel: Registered led device: iwl-phy0:TX

service NetworkManager restart

Jul  6 00:09:44 localhost NetworkManager: <WARN>  nm_signal_handler(): Caught
signal 15, shutting down normally.
Jul  6 00:09:44 localhost NetworkManager: <info>  (eth0): now unmanaged
Jul  6 00:09:44 localhost NetworkManager: <info>  (eth0): device state change: 2
-> 1
Jul  6 00:09:44 localhost NetworkManager: <info>  (eth0): cleaning up...
Jul  6 00:09:44 localhost NetworkManager: <info>  (eth0): taking down device.
Jul  6 00:09:44 localhost kernel: sky2 eth0: disabling interface
Jul  6 00:09:44 localhost NetworkManager: <info>  (wlan0): now unmanaged
Jul  6 00:09:44 localhost NetworkManager: <info>  (wlan0): device state change:
3 -> 1
Jul  6 00:09:44 localhost NetworkManager: <info>  (wlan0): cleaning up...
Jul  6 00:09:44 localhost NetworkManager: <info>  (wlan0): taking down device.
Jul  6 00:09:46 localhost kernel: ACPI: PCI interrupt for device 0000:03:00.0
disabled
Jul  6 00:09:47 localhost NetworkManager: <info>  starting...
Jul  6 00:09:48 localhost NetworkManager: <info>  Found radio killswitch
/org/freedesktop/Hal/devices/ipw_wlan_switch
Jul  6 00:09:48 localhost NetworkManager: <info>  eth0: Device is
fully-supported using driver 'sky2'.
Jul  6 00:09:48 localhost NetworkManager: <info>  Found new Ethernet device 'eth0'.
Jul  6 00:09:48 localhost NetworkManager: <info>  (eth0): exported as
/org/freedesktop/Hal/devices/net_00_0b_97_55_82_24
Jul  6 00:09:48 localhost NetworkManager: <info>  wlan0: Device is
fully-supported using driver 'iwl4965'.
Jul  6 00:09:48 localhost NetworkManager: <info>  wlan0: driver supports SSID
scans (scan_capa 0x01).
Jul  6 00:09:48 localhost NetworkManager: <info>  Found new wireless (802.11)
device 'wlan0'.
Jul  6 00:09:48 localhost NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/Hal/devices/net_00_1f_3b_71_d2_a5
Jul  6 00:09:52 localhost kernel: sky2 eth0: enabling interface
Jul  6 00:09:52 localhost NetworkManager: <info>  (eth0): device state change: 1
-> 2
Jul  6 00:09:52 localhost NetworkManager: <info>  (eth0): bringing up device.
Jul  6 00:09:52 localhost kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  6 00:09:52 localhost NetworkManager: <info>  (eth0): preparing device.
Jul  6 00:09:52 localhost NetworkManager: <info>  (eth0): deactivating device.
Jul  6 00:09:52 localhost kernel: ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 18
(level, low) -> IRQ 18
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): device state change:
1 -> 2
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): bringing up device.
Jul  6 00:09:52 localhost kernel: Registered led device: iwl-phy0:radio
Jul  6 00:09:52 localhost kernel: Registered led device: iwl-phy0:assoc
Jul  6 00:09:52 localhost kernel: Registered led device: iwl-phy0:RX
Jul  6 00:09:52 localhost kernel: Registered led device: iwl-phy0:TX
Jul  6 00:09:52 localhost kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): preparing device.
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): deactivating device.
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): device state change:
2 -> 3
Jul  6 00:09:52 localhost NetworkManager: <info>  (wlan0): supplicant interface
state change: 1 -> 2.
Jul  6 00:09:54 localhost NetworkManager: <WARN>  killswitch_getpower_reply():
Error getting killswitch power: hal-ipw-killswitch-linux returned 255.

Note that there is a problem here already with hal-ipw-killswitch-linux, but
this might be unrelated to the kernel oops in the end.

I (kill) switch wlan off

Jul  6 00:10:51 localhost kernel: iwl4965: Radio Frequency Kill Switch is On:
Jul  6 00:10:51 localhost kernel: Kill switch must be turned off for wireless
networking to work.

service NetworkManager restart

Jul  6 00:11:09 localhost NetworkManager: <WARN>  nm_signal_handler(): Caught
signal 15, shutting down normally.
Jul  6 00:11:09 localhost NetworkManager: <info>  (eth0): now unmanaged
Jul  6 00:11:09 localhost NetworkManager: <info>  (eth0): device state change: 2
-> 1
Jul  6 00:11:09 localhost NetworkManager: <info>  (eth0): cleaning up...
Jul  6 00:11:09 localhost NetworkManager: <info>  (eth0): taking down device.
Jul  6 00:11:09 localhost kernel: sky2 eth0: disabling interface
Jul  6 00:11:09 localhost NetworkManager: <info>  (wlan0): now unmanaged
Jul  6 00:11:09 localhost NetworkManager: <info>  (wlan0): device state change:
3 -> 1
Jul  6 00:11:09 localhost NetworkManager: <info>  (wlan0): cleaning up...
Jul  6 00:11:09 localhost NetworkManager: <info>  (wlan0): taking down device.
Jul  6 00:11:10 localhost kernel: iwl4965: WARNING: Requesting MAC access during
RFKILL wakes up NIC
Jul  6 00:11:10 localhost kernel: iwl4965: WARNING: Requesting MAC access during
RFKILL wakes up NIC
Jul  6 00:11:10 localhost kernel: iwl4965: WARNING: Requesting MAC access during
RFKILL wakes up NIC
Jul  6 00:11:10 localhost kernel: iwl4965: WARNING: Requesting MAC access during
RFKILL wakes up NIC
Jul  6 00:11:10 localhost kernel: ACPI: PCI interrupt for device 0000:03:00.0
disabled
Jul  6 00:11:11 localhost NetworkManager: <info>  starting...
Jul  6 00:11:11 localhost NetworkManager: <info>  Found radio killswitch
/org/freedesktop/Hal/devices/ipw_wlan_switch
Jul  6 00:11:11 localhost NetworkManager: <info>  eth0: Device is
fully-supported using driver 'sky2'.
Jul  6 00:11:11 localhost NetworkManager: <info>  Found new Ethernet device 'eth0'.
Jul  6 00:11:11 localhost NetworkManager: <info>  (eth0): exported as
/org/freedesktop/Hal/devices/net_00_0b_97_55_82_24
Jul  6 00:11:11 localhost NetworkManager: <info>  wlan0: Device is
fully-supported using driver 'iwl4965'.
Jul  6 00:11:11 localhost NetworkManager: <info>  wlan0: driver supports SSID
scans (scan_capa 0x01).
Jul  6 00:11:11 localhost NetworkManager: <info>  Found new wireless (802.11)
device 'wlan0'.
Jul  6 00:11:11 localhost NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/Hal/devices/net_00_1f_3b_71_d2_a5
Jul  6 00:11:13 localhost kerneloops: Submitted 1 kernel oopses to
www.kerneloops.org
Jul  6 00:11:15 localhost kernel: sky2 eth0: enabling interface
Jul  6 00:11:15 localhost NetworkManager: <info>  (eth0): device state change: 1
-> 2
Jul  6 00:11:15 localhost NetworkManager: <info>  (eth0): bringing up device.
Jul  6 00:11:15 localhost kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  6 00:11:15 localhost NetworkManager: <info>  (eth0): preparing device.
Jul  6 00:11:15 localhost NetworkManager: <info>  (eth0): deactivating device.
Jul  6 00:11:15 localhost NetworkManager: <info>  (wlan0): device state change:
1 -> 2
Jul  6 00:11:15 localhost NetworkManager: <info>  (wlan0): bringing up device.
Jul  6 00:11:15 localhost kernel: ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 18
(level, low) -> IRQ 18
Jul  6 00:11:15 localhost kernel: iwl4965: Radio disabled by HW RF Kill switch
Jul  6 00:11:15 localhost kernel: ACPI: PCI interrupt for device 0000:03:00.0
disabled
Jul  6 00:11:15 localhost NetworkManager: <WARN>  nm_device_hw_bring_up():
(wlan0): device not up after timeout!
Jul  6 00:11:15 localhost NetworkManager: <info>  (wlan0): deactivating device.
Jul  6 00:11:15 localhost NetworkManager: <info>  (wlan0): device state change:
2 -> 3
Jul  6 00:11:17 localhost NetworkManager: <WARN>  killswitch_getpower_reply():
Error getting killswitch power: hal-ipw-killswitch-linux returned 255.
Jul  6 00:11:23 localhost kerneloops: Submitted 1 kernel oopses to
www.kerneloops.org

I switch wlan on .. no messages
I switch wlan off .. no messages
I switch wlan on .. no messages
service NetworkManager restart

Jul  6 00:19:58 localhost NetworkManager: <WARN>  nm_signal_handler(): Caught
signal 15, shutting down normally.
Jul  6 00:19:58 localhost NetworkManager: <info>  (eth0): now unmanaged
Jul  6 00:19:58 localhost NetworkManager: <info>  (eth0): device state change: 2
-> 1
Jul  6 00:19:58 localhost NetworkManager: <info>  (eth0): cleaning up...
Jul  6 00:19:58 localhost NetworkManager: <info>  (eth0): taking down device.
Jul  6 00:19:58 localhost kernel: sky2 eth0: disabling interface
Jul  6 00:19:58 localhost NetworkManager: <info>  (wlan0): now unmanaged
Jul  6 00:19:58 localhost NetworkManager: <info>  (wlan0): device state change:
3 -> 1
Jul  6 00:19:58 localhost NetworkManager: <info>  starting...
Jul  6 00:19:58 localhost NetworkManager: <info>  Found radio killswitch
/org/freedesktop/Hal/devices/ipw_wlan_switch
Jul  6 00:19:58 localhost NetworkManager: <info>  eth0: Device is
fully-supported using driver 'sky2'.
Jul  6 00:19:58 localhost NetworkManager: <info>  Found new Ethernet device 'eth0'.
Jul  6 00:19:58 localhost NetworkManager: <info>  (eth0): exported as
/org/freedesktop/Hal/devices/net_00_0b_97_55_82_24
Jul  6 00:19:58 localhost NetworkManager: <info>  wlan0: Device is
fully-supported using driver 'iwl4965'.
Jul  6 00:19:58 localhost NetworkManager: <info>  wlan0: driver supports SSID
scans (scan_capa 0x01).
Jul  6 00:19:58 localhost NetworkManager: <info>  Found new wireless (802.11)
device 'wlan0'.
Jul  6 00:19:58 localhost NetworkManager: <info>  (wlan0): exported as
/org/freedesktop/Hal/devices/net_00_1f_3b_71_d2_a5
Jul  6 00:20:02 localhost kernel: sky2 eth0: enabling interface
Jul  6 00:20:02 localhost NetworkManager: <info>  (eth0): device state change: 1
-> 2
Jul  6 00:20:02 localhost NetworkManager: <info>  (eth0): bringing up device.
Jul  6 00:20:02 localhost kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jul  6 00:20:02 localhost NetworkManager: <info>  (eth0): preparing device.
Jul  6 00:20:02 localhost NetworkManager: <info>  (eth0): deactivating device.
Jul  6 00:20:02 localhost kernel: ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 18
(level, low) -> IRQ 18
Jul  6 00:20:02 localhost NetworkManager: <info>  (wlan0): device state change:
1 -> 2
Jul  6 00:20:02 localhost NetworkManager: <info>  (wlan0): bringing up device.
Jul  6 00:20:04 localhost kernel: iwl4965: START_ALIVE timeout after 2000ms.
Jul  6 00:20:04 localhost kernel: ACPI: PCI interrupt for device 0000:03:00.0
disabled
Jul  6 00:20:04 localhost kerneloops: Submitted 1 kernel oopses to
www.kerneloops.org
Jul  6 00:20:04 localhost NetworkManager: <WARN>  nm_device_hw_bring_up():
(wlan0): device not up after timeout!
Jul  6 00:20:04 localhost NetworkManager: <info>  (wlan0): deactivating device.
Jul  6 00:20:04 localhost NetworkManager: <info>  (wlan0): device state change:
2 -> 3
Jul  6 00:20:04 localhost NetworkManager: <WARN>  killswitch_getpower_reply():
Error getting killswitch power: hal-ipw-killswitch-linux returned 255.
Jul  6 00:20:13 localhost kerneloops: Submitted 1 kernel oopses to
www.kerneloops.org

Message from syslogd@localhost at Jul  6 00:20:32 ...
 kernel: Disabling IRQ #18
Jul  6 00:20:32 localhost kernel: irq 18: nobody cared (try booting with the
"irqpoll" option)
Jul  6 00:20:32 localhost kernel: Pid: 0, comm: swapper Not tainted
2.6.25.9-76.fc9.x86_64 #1
Jul  6 00:20:32 localhost kernel: 
Jul  6 00:20:32 localhost kernel: Call Trace:
Jul  6 00:20:32 localhost kernel:  <IRQ>  [<ffffffff8102788e>] ?
__update_rq_clock+0x1a/0xd0
Jul  6 00:20:32 localhost kernel:  [<ffffffff8107180f>] __report_bad_irq+0x38/0x7c
Jul  6 00:20:32 localhost kernel:  [<ffffffff81071a35>] note_interrupt+0x1e2/0x249
Jul  6 00:20:32 localhost kernel:  [<ffffffff81072145>] handle_fasteoi_irq+0xab/0xd0
Jul  6 00:20:32 localhost kernel:  [<ffffffff8100e48f>] do_IRQ+0xf7/0x167
Jul  6 00:20:32 localhost kernel:  [<ffffffff8100c3f1>] ret_from_intr+0x0/0xa
Jul  6 00:20:32 localhost kernel:  <EOI>  [<ffffffff8102ff27>] ?
finish_task_switch+0x2f/0xb3
Jul  6 00:20:32 localhost kernel:  [<ffffffff8128d1ea>] ? thread_return+0x3d/0xa7
Jul  6 00:20:32 localhost kernel:  [<ffffffff811edbf4>] ? cpuidle_idle_call+0x0/0xba
Jul  6 00:20:32 localhost kernel:  [<ffffffff8100aff0>] ? default_idle+0x0/0x5f
Jul  6 00:20:32 localhost kernel:  [<ffffffff8100afeb>] ? cpu_idle+0xbb/0xc0
Jul  6 00:20:32 localhost kernel:  [<ffffffff8127f136>] ? rest_init+0x5a/0x5c
Jul  6 00:20:32 localhost kernel: 
Jul  6 00:20:32 localhost kernel: handlers:
Jul  6 00:20:32 localhost kernel: [<ffffffff811be414>] (usb_hcd_irq+0x0/0x63)
Jul  6 00:20:32 localhost kernel: [<ffffffff811be414>] (usb_hcd_irq+0x0/0x63)
Jul  6 00:20:32 localhost kernel: Disabling IRQ #18
Jul  6 00:20:43 localhost kerneloops: Submitted 1 kernel oopses to
www.kerneloops.org


Actual results:

kerneloops / interface disfunctional

Expected results:

no kernel oops / interface functional as it IS after reboot.

Thank you!

Comment 1 Axel 2008-07-08 12:33:27 UTC

Created attachment 311260 [details]
Commented log file documenting the bug

Comment 2 John W. Linville 2008-11-24 18:11:24 UTC

Are you still experiencing this with current kernels?

Comment 3 Axel 2008-11-25 13:53:01 UTC

Many thanks. With kernel 2.6.27.5-41.fc9.x86_64 #1 SMP I do not get kernel error messages anymore.  

A minor problem that remains is that when starting the NetworkManager with wlan disabled by killswitch, there is no reaction when switching the killswitch to the other position.  Restarting NetworkManager fixes this.

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