[ltp] Random rfkill toggling on an X201s

Henrique de Moraes Holschuh linux-thinkpad@linux-thinkpad.org
Sat, 25 Jun 2011 21:58:28 -0300


Ok, let me go over this again now that I've reread the driver source to
refresh my memory.

On Sat, 25 Jun 2011, Nathaniel Smith wrote:
> I've attached the kernel log from one of these events. The timeline looks like:
> 22785.396656: wifi card notices that RF_KILL bit has been turned on
> 22785.447378: bluetooth transmitter disappears from the USB bus
> 22785.716392: thinkpad_acpi reports that rfkill has been enabled
> 22785.725497: thinkpad_acpi reports that rfkill has been disabled again
> 22785.815842: wifi card starts trying to do its thing
> 22786.126347: bluetooth transmitter reappears on the USB bus
> 
> So the whole thing is over in less than a second. The kernel seems to
> believe that the hardware is at fault, since if I manage to run
> 'rfkill list' at the right moment, it says:
> 1: tpacpi_bluetooth_sw: Bluetooth
> 	Soft blocked: yes
> 	Hard blocked: yes

Ok.  thinkpad-acpi doesn't mess around with that hard blocked thing, if it
reports that it is hard blocked, it means the ACPI DSDT reported that the
physical radio-kill switch is engaged (killing the radios).

If this is wrong, it is time to do ACPI DSDT debugging as well as driver
debugging.  Also, make sure you're using the latest BIOS, this is the sort
of bug that Lenovo has corrected in the past with a BIOS update.

> 10: phy0: Wireless LAN
> 	Soft blocked: yes
> 	Hard blocked: yes

I am not sure how well the hard-rfkill line is connected in your thinkpad
and wireless card.  Some have it properly connected to the physical switch,
some don't.

> slider seems fairly solid mechnically -- I tried jiggling it around to
> trigger one of these events, but I can't; the only way I've managed to
> turn off the radios is by flipping it all the way, and that's
> definitely not happening during the phantom rfkill events. Shaking the
> laptop doesn't seem to trigger any of these events either.

You can toggle it and record the sequence of log messages, to compare with
the sequence you get when things get strange.  That could give us a hint of
what is happening.

> Jun 25 10:13:19 ged kernel: [22785.396656] iwlagn 0000:02:00.0: RF_KILL bit toggled to disable radio.
> Jun 25 10:13:19 ged kernel: [22785.446542] iwlagn 0000:02:00.0: RF_KILL bit toggled to enable radio.

Hmm... a < 50ms pulse.  NOT good, it does look like hardware.  OTOH, if the
intel wireless module IS hooked to the hardkill line, it could be a problem
in the module (which is much easier and cheaper to replace).

But we're not sure yet.

> Jun 25 10:13:19 ged kernel: [22785.447378] usb 1-1.4: USB disconnect, address 29

USB is slow at reacting, probably...

> Jun 25 10:13:19 ged kernel: [22785.716392] thinkpad_acpi: tpacpi_rfk_hook_set_block: request to change radio state to blocked
> Jun 25 10:13:19 ged kernel: [22785.725497] thinkpad_acpi: tpacpi_rfk_hook_set_block: request to change radio state to unblocked

This could be normal or not, you'll need to add a printk to
tpacpi_send_radiosw_update() or otherwise get the rfkill core to log
something useful, for us to know for sure.

If you have CONFIG_RFKILL_INPUT set, try to give the rfkill module the
parameter "master_switch_mode=0", and check for any behaviour change...

> Jun 25 10:13:20 ged kernel: [22786.126347] usb 1-1.4: new full speed USB device using ehci_hcd and address 30

And USB catches up.

-- 
  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh