Bug 111361 - iwlwifi: mvm: can't load firmware with HW rfkill is asserted - MWG100254508
Summary: iwlwifi: mvm: can't load firmware with HW rfkill is asserted - MWG100254508
Status: CLOSED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: network-wireless (show other bugs)
Hardware: x86-64 Linux
: P1 normal
Assignee: DO NOT USE - assign "network-wireless-intel" component instead
URL:
Keywords:
: 110871 (view as bug list)
Depends on:
Blocks:
 
Reported: 2016-01-27 06:21 UTC by Wolfram Schlich
Modified: 2016-02-17 15:59 UTC (History)
3 users (show)

See Also:
Kernel Version: 4.3.5-gentoo
Subsystem:
Regression: No
Bisected commit-id:


Attachments
dmesg using debug=0xffffffff with rfkill hw switch activated (85.28 KB, text/plain)
2016-01-28 17:42 UTC, Wolfram Schlich
Details
dmesg using debug=0xffffffff with rfkill hw switch deactivated (540.04 KB, text/plain)
2016-01-28 17:43 UTC, Wolfram Schlich
Details
trace.dat of trace-cmd record session (3.25 MB, application/octet-stream)
2016-01-29 14:03 UTC, Wolfram Schlich
Details
dump stack when disabling interrupt (619 bytes, patch)
2016-01-31 07:22 UTC, Emmanuel Grumbach
Details | Diff
fix candidate (3.83 KB, patch)
2016-01-31 13:09 UTC, Emmanuel Grumbach
Details | Diff
fix that applies on 4.3 (2.90 KB, patch)
2016-01-31 13:11 UTC, Emmanuel Grumbach
Details | Diff
fix try 2 (5.34 KB, patch)
2016-01-31 21:46 UTC, Emmanuel Grumbach
Details | Diff
fix take 3 (5.39 KB, patch)
2016-02-01 13:38 UTC, Emmanuel Grumbach
Details | Diff
trace.dat of trace-cmd record session #2 (4.62 MB, application/octet-stream)
2016-02-01 19:54 UTC, Wolfram Schlich
Details
trace.dat of trace-cmd record session #3 (3.42 MB, application/octet-stream)
2016-02-01 20:00 UTC, Wolfram Schlich
Details
fixup (1.95 KB, patch)
2016-02-11 17:42 UTC, Emmanuel Grumbach
Details | Diff

Description Wolfram Schlich 2016-01-27 06:21:05 UTC
Hi!

When booting up the system with the rfkill hw switch (accidently) turned on, iwlwifi fails to load the firmware:

--8<--
[   22.080505] iwlwifi 0000:03:00.0: enabling device (0000 -> 0002)
[   22.092123] iwlwifi 0000:03:00.0: loaded firmware version 17.228510.0 op_mode iwlmvm
[   22.098023] iwlwifi 0000:03:00.0: Detected Intel(R) Dual Band Wireless AC 7260, REV=0x144
[   22.098089] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   22.098314] iwlwifi 0000:03:00.0: RF_KILL bit toggled to disable radio.
[   22.098337] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   27.099345] iwlwifi 0000:03:00.0: Failed to load firmware chunk!
[   27.099348] iwlwifi 0000:03:00.0: Could not load the [0] uCode section
[   27.099357] iwlwifi 0000:03:00.0: Failed to start INIT ucode: -110
[   27.099646] iwlwifi 0000:03:00.0: Failed to run INIT ucode: -110
[   27.099688] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
--8<--

Unblocking the rfkill hw switch of course doesn't help.
rmmod + modprobe iwlwifi (etc.) is required, then it works fine.

Hardware:
- Dell Precision M4800
- Intel Dual Band Wireless-AC 7260 7260HMW (8086:08b1)

Software:
- Kernel: Linux zephyr 4.3.4-gentoo #1 SMP Tue Jan 26 14:57:11 CET 2016 x86_64 Intel(R) Core(TM) i7-4910MQ CPU @ 2.90GHz GenuineIntel GNU/Linux

Cheers,
Wolfram
Comment 1 Wolfram Schlich 2016-01-27 06:55:26 UTC
I have tried with the following firmware blobs:
1. iwlwifi-7260-17.ucode (17.228510.0)
2. iwlwifi-7260-17.ucode (17.275772.0)
Comment 2 Emmanuel Grumbach 2016-01-28 07:14:27 UTC
*** Bug 110871 has been marked as a duplicate of this bug. ***
Comment 3 Emmanuel Grumbach 2016-01-28 07:16:42 UTC
Please reproduce with debug=0xffffffff as a module parameter to iwlwifi and attach the dmesg output.

This seems to be a race between the RFKILL interrupt and the INIT flow which I can't reproduce here.
It might take time and reproduction cycles to fix, so if you want to get this fixed, I'll need your cooperation.

Thanks.
Comment 4 Wolfram Schlich 2016-01-28 17:39:36 UTC
Here's all of the iwlwifi kernel messages with debug=0xffffffff when booting up with the rfkill hw switch activated:
--8<--
[    7.856084] iwlwifi 0000:03:00.0: enabling device (0000 -> 0002)
[    7.856129] iwlwifi 0000:03:00.0: U iwl_disable_interrupts Disabled interrupts
[    7.856231] iwlwifi 0000:03:00.0: U iwl_pcie_alloc_ict ict dma addr fffff000 ict vir addr ffff88080331f000
[    7.857370] iwlwifi 0000:03:00.0: U iwl_request_firmware attempting to load firmware EXPERIMENTAL 'iwlwifi-7260-exp.ucode'
[    7.857393] iwlwifi 0000:03:00.0: U set_dflt_pwr_limit SPL method not found
[    7.858778] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-7260-exp.ucode failed with error -2
[    7.859703] iwlwifi 0000:03:00.0: U iwl_request_firmware attempting to load firmware 'iwlwifi-7260-17.ucode'
[    7.867045] iwlwifi 0000:03:00.0: U iwl_req_fw_callback Loaded firmware file 'iwlwifi-7260-17.ucode' (1049340 bytes).
[    7.867051] iwlwifi 0000:03:00.0: api_index larger than supported by driver
[    7.868002] iwlwifi 0000:03:00.0: U iwl_parse_tlv_firmware unknown TLV: 48
[    7.868225] iwlwifi 0000:03:00.0: loaded firmware version 17.275772.0 op_mode iwlmvm
[    7.872706] iwlwifi 0000:03:00.0: Detected Intel(R) Dual Band Wireless AC 7260, REV=0x144
[    7.872708] iwlwifi 0000:03:00.0: U iwl_mvm_tt_initialize Initialize Thermal Throttling
[    7.872709] iwlwifi 0000:03:00.0: U iwl_op_mode_mvm_start working without external nvm file
[    7.872710] iwlwifi 0000:03:00.0: U iwl_pcie_prepare_card_hw iwl_trans_prepare_card_hw enter
[    7.872734] iwlwifi 0000:03:00.0: U iwl_pcie_set_hw_ready hardware ready
[    7.872753] iwlwifi 0000:03:00.0: U iwl_pcie_apm_init Init card's basic functions
[    7.872789] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[    7.872998] iwlwifi 0000:03:00.0: U iwl_enable_rfkill_int Enabling rfkill interrupt
[    7.873005] iwlwifi 0000:03:00.0: U iwl_pcie_prepare_card_hw iwl_trans_prepare_card_hw enter
[    7.873014] iwlwifi 0000:03:00.0: U iwl_pcie_set_hw_ready hardware ready
[    7.873015] iwlwifi 0000:03:00.0: U iwl_enable_rfkill_int Enabling rfkill interrupt
[    7.873030] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler ISR inta 0x00000080, enabled 0x00000080(sw), enabled(hw) 0x00000000, fh 0x00000000
[    7.873035] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler inta 0x00000080, enabled 0x00000000
[    7.873039] iwlwifi 0000:03:00.0: RF_KILL bit toggled to disable radio.
[    7.874110] iwlwifi 0000:03:00.0: U iwl_pcie_apm_init Init card's basic functions
[    7.874132] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[    7.874277] iwlwifi 0000:03:00.0: U iwl_mvm_nic_config Radio type=0x0-0x2-0x1
[    7.874871] iwlwifi 0000:03:00.0: U iwl_pcie_nic_init Enabling shadow registers in device
[    7.874875] iwlwifi 0000:03:00.0: U iwl_enable_interrupts Enabling interrupts
[    7.874876] iwlwifi 0000:03:00.0: U iwl_pcie_load_given_ucode working with Single CPU
[    7.874877] iwlwifi 0000:03:00.0: U iwl_pcie_load_section [0] uCode section being loaded...
[   12.876016] iwlwifi 0000:03:00.0: Failed to load firmware chunk!
[   12.876036] iwlwifi 0000:03:00.0: Could not load the [0] uCode section
[   12.876058] iwlwifi 0000:03:00.0: Failed to start INIT ucode: -110
[   12.876077] iwlwifi 0000:03:00.0: U iwl_enable_interrupts Enabling interrupts
[   12.876088] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler ISR inta 0x08000000, enabled 0xbb00008b(sw), enabled(hw) 0xbb00008b, fh 0x00000001
[   12.876093] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler inta 0x08000000, enabled 0xbb00008b
[   12.876094] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler uCode load interrupt
[   12.876095] iwlwifi 0000:03:00.0: U iwl_enable_interrupts Enabling interrupts
[   12.876103] iwlwifi 0000:03:00.0: U iwl_disable_interrupts Disabled interrupts
[   12.876104] iwlwifi 0000:03:00.0: U _iwl_trans_pcie_stop_device DEVICE_ENABLED bit was set and is now cleared
[   12.876182] iwlwifi 0000:03:00.0: U iwl_pcie_apm_stop Stop card, put in low power state
[   12.876189] iwlwifi 0000:03:00.0: U iwl_pcie_apm_stop_master stop master
[   12.876377] iwlwifi 0000:03:00.0: U iwl_disable_interrupts Disabled interrupts
[   12.876378] iwlwifi 0000:03:00.0: U iwl_enable_rfkill_int Enabling rfkill interrupt
[   12.876398] iwlwifi 0000:03:00.0: U iwl_pcie_prepare_card_hw iwl_trans_prepare_card_hw enter
[   12.876415] iwlwifi 0000:03:00.0: U iwl_pcie_set_hw_ready hardware ready
[   12.876416] iwlwifi 0000:03:00.0: Failed to run INIT ucode: -110
[   12.876432] iwlwifi 0000:03:00.0: U iwl_disable_interrupts Disabled interrupts
[   12.876433] iwlwifi 0000:03:00.0: U iwl_pcie_apm_stop Stop card, put in low power state
[   12.876434] iwlwifi 0000:03:00.0: U iwl_pcie_apm_init Init card's basic functions
[   12.876471] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   12.881708] iwlwifi 0000:03:00.0: U iwl_pcie_apm_stop_master stop master
[   12.881875] iwlwifi 0000:03:00.0: U iwl_disable_interrupts Disabled interrupts
--8<--

Cheers,
Wolfram
Comment 5 Wolfram Schlich 2016-01-28 17:42:35 UTC
Created attachment 202171 [details]
dmesg using debug=0xffffffff with rfkill hw switch activated
Comment 6 Wolfram Schlich 2016-01-28 17:43:01 UTC
Created attachment 202181 [details]
dmesg using debug=0xffffffff with rfkill hw switch deactivated
Comment 7 Emmanuel Grumbach 2016-01-28 18:12:12 UTC
Can you please run lspci -xxxx -vvvv after fresh boot while rfkill hw switch is activated, and with rfkill hw switch deactivated.

Thanks.
Comment 8 Emmanuel Grumbach 2016-01-28 19:53:02 UTC
lspci not needed. The firmware is loaded, but the interrupt is missing.. interesting.

[    7.874871] iwlwifi 0000:03:00.0: U iwl_pcie_nic_init Enabling shadow registers in device
[    7.874875] iwlwifi 0000:03:00.0: U iwl_enable_interrupts Enabling interrupts
[    7.874876] iwlwifi 0000:03:00.0: U iwl_pcie_load_given_ucode working with Single CPU
[    7.874877] iwlwifi 0000:03:00.0: U iwl_pcie_load_section [0] uCode section being loaded...
[   12.876016] iwlwifi 0000:03:00.0: Failed to load firmware chunk!
[   12.876036] iwlwifi 0000:03:00.0: Could not load the [0] uCode section
[   12.876058] iwlwifi 0000:03:00.0: Failed to start INIT ucode: -110
[   12.876077] iwlwifi 0000:03:00.0: U iwl_enable_interrupts Enabling interrupts
[   12.876088] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler ISR inta 0x08000000, enabled 0xbb00008b(sw), enabled(hw) 0xbb00008b, fh 0x00000001
[   12.876093] iwlwifi 0000:03:00.0: U iwl_pcie_irq_handler inta 0x08000000, enabled 0xbb00008b

here we do get the interrupt (0x08000000 is the interrupt we are waiting for).

Are you comfortable with applying debug patches?
If not, I'd need tracing:
sudo trace-cmd -e iwlwifi -e iwlwifi_msg -e iwlwifi_io

Since you can't run tracing when you load the module, you'd have to load the module with hw rkill de-activated, unbind the device, start tracing, and re-bind the device.

thanks.
Comment 9 Emmanuel Grumbach 2016-01-28 20:02:24 UTC
FWIW - I tried to reproduce on the only platform I have with a hw rfkill switch but couldn't.
Comment 10 Wolfram Schlich 2016-01-29 07:40:33 UTC
> Are you comfortable with applying debug patches?

Sure :) Shoot!

(I'm also fine with tracing, whatever you prefer...)
Comment 11 Emmanuel Grumbach 2016-01-29 08:33:47 UTC
Week end here :)

Let's start with tracing.
Comment 12 Wolfram Schlich 2016-01-29 08:44:47 UTC
> Week end here :)
> 
> Let's start with tracing.

:P Okay :)

> Since you can't run tracing when you load the module, you'd have
> to load the module with hw rkill de-activated, unbind the device,
> start tracing, and re-bind the device.

How exactly do I do that (unbind/rebind)?
Comment 13 Emmanuel Grumbach 2016-01-29 11:32:52 UTC
sudo modprobe -r iwlwifi
echo 0 > /sys/bus/pci/drivers_autoprobe

<start tracing>

sudo modprobe iwlwifi
echo "0000:03:00.0" > /sys/bus/pci/drivers_probe 


stop tracing
Comment 14 Wolfram Schlich 2016-01-29 14:03:33 UTC
Created attachment 202261 [details]
trace.dat of trace-cmd record session

I've attached the trace.dat as requested.
Comment 15 Wolfram Schlich 2016-01-29 14:07:35 UTC
The required steps had to be done a bit differently from your suggestion though:

1. Blacklist iwlwifi
echo 'blacklist iwlwifi' >/etc/modprobe.d/iwlwifi.conf

2. Reboot with rfkill switch activated

3. Disable drivers_autoprobe
echo 0 > /sys/bus/pci/drivers_autoprobe 

4. Load iwlwifi module so that tracing stuff is registered
modprobe iwlwifi

5. Start tracing in screen window 1
trace-cmd record -e iwlwifi -e iwlwifi_msg -e iwlwifi_io

6. Probe iwlwifi pci device in screen window 2
echo 0000:03:00.0 > /sys/bus/pci/drivers_probe

7. Stop tracing after all expected kernel messages regarding the errors appeared

Cheers,
Wolfram
Comment 16 Emmanuel Grumbach 2016-01-29 14:13:16 UTC
I'll look at the trace on Sunday.

Thanks
Comment 17 Wolfram Schlich 2016-01-29 14:35:54 UTC
Ok, thanks :) Have a nice weekend!

Cheers,
Wolfram
Comment 18 Emmanuel Grumbach 2016-01-31 07:22:22 UTC
Created attachment 202431 [details]
dump stack when disabling interrupt

Someone is disabling the interrupts. Not clear why, since it is the not the thread that brings up the device.
Can you please record tracing again just like you did with the patch attached applied?

thanks.
Comment 19 Emmanuel Grumbach 2016-01-31 09:25:26 UTC
I have been able to reproduce... I am pretty sure that this "problem" is not in iwlwifi though since the latest driver with 4.2 kernel (using backport) doesn't have any issues. If I take 4.3.4 vanilla, then I can reproduce the bug.
Comment 20 Emmanuel Grumbach 2016-01-31 13:09:46 UTC
Created attachment 202441 [details]
fix candidate

This is a fix candidate, please test.
Comment 21 Emmanuel Grumbach 2016-01-31 13:11:28 UTC
Created attachment 202451 [details]
fix that applies on 4.3

The patch previously attached won't apply on 4.3. This patch will.
Comment 22 Emmanuel Grumbach 2016-01-31 15:09:04 UTC
Ouch, I rebooted my system and the bug is still there. Weird, the bug seemed to be fixed when I reloaded the module. More work needed.
Comment 23 Emmanuel Grumbach 2016-01-31 21:46:08 UTC
Created attachment 202501 [details]
fix try 2

Ok - it was more complicated that what I thought.
Here is the fix that applies to 4.3.

Please test.
Comment 24 Emmanuel Grumbach 2016-02-01 13:38:15 UTC
Created attachment 202641 [details]
fix take 3

Ok - last version. No functional change in the fix, but it is simpler.

Any chance you give it a try?
Comment 25 Wolfram Schlich 2016-02-01 14:16:31 UTC
I applied your "fix take 3" now to my (new) kernel version 4.3.5-gentoo.

Booting up with rfkill switch activated works fine now.
The firmware is being loaded and the activated rfkill switch is recognized properly:

zephyr ~ # dmesg | grep iwlwifi
[    7.832052] iwlwifi 0000:03:00.0: enabling device (0000 -> 0002)
[    7.834972] iwlwifi 0000:03:00.0: Direct firmware load for iwlwifi-7260-exp.ucode failed with error -2
[    7.844447] iwlwifi 0000:03:00.0: api_index larger than supported by driver
[    7.845543] iwlwifi 0000:03:00.0: loaded firmware version 17.275772.0 op_mode iwlmvm
[    7.851055] iwlwifi 0000:03:00.0: Detected Intel(R) Dual Band Wireless AC 7260, REV=0x144
[    7.851121] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[    7.851359] iwlwifi 0000:03:00.0: RF_KILL bit toggled to disable radio.
[    7.851961] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[    7.959894] iwlwifi 0000:03:00.0 wlp3s0: renamed from wlan0
zephyr ~ # rfkill list
0: phy0: Wireless LAN
        Soft blocked: no
        Hard blocked: yes
zephyr ~ # 

Deactivting the rfkill switch also works fine:

[   89.309097] iwlwifi 0000:03:00.0: RF_KILL bit toggled to enable radio.
[   89.309104] atkbd serio0: Unknown key pressed (translated set 2, code 0x88 on isa0060/serio0).
[   89.309107] atkbd serio0: Use 'setkeycodes e008 <keycode>' to make it known.
[   89.310881] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   89.311143] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   89.508551] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   89.508818] iwlwifi 0000:03:00.0: L1 Enabled - LTR Enabled
[   89.524071] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[   89.551349] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[   89.738957] usb 4-1.5: new full-speed USB device number 4 using ehci-pci
[   89.826244] usb 4-1.5: New USB device found, idVendor=8087, idProduct=07dc
[   89.826247] usb 4-1.5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   89.839509] Bluetooth: hci0: read Intel version: 3707100180012d0d00
[   89.843799] Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.7.10-fw-1.80.1.2d.d.bseq
[   90.025610] Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated
[   92.879734] wlp3s0: authenticate with c4:e9:84:91:2f:46
[   92.882647] wlp3s0: send auth to c4:e9:84:91:2f:46 (try 1/3)
[   92.884982] wlp3s0: authenticated
[   92.885638] wlp3s0: associate with c4:e9:84:91:2f:46 (try 1/3)
[   92.889220] wlp3s0: RX AssocResp from c4:e9:84:91:2f:46 (capab=0x431 status=0 aid=1)
[   92.890051] wlp3s0: associated
[   92.890074] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
[   92.891729] cfg80211: Regulatory domain changed to country: US
[   92.891731] cfg80211:  DFS Master region: unset
[   92.891732] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   92.891733] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
[   92.891734] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (N/A)
[   92.891736] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (0 s)
[   92.891736] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2300 mBm), (0 s)
[   92.891737] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[   92.891738] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)

But, when I now re-activate the rfkill switch, nothing happens (except that the bluetooth hci0 vanishes) :(

zephyr ~ # rfkill list
0: phy0: Wireless LAN
        Soft blocked: no
        Hard blocked: no
zephyr ~ # 

So, iwlwifi does not recognize the rfkill switch reactivation :(
Comment 26 Emmanuel Grumbach 2016-02-01 14:20:18 UTC
works fine here...

Can you record tracing of the step 3?
Comment 27 Wolfram Schlich 2016-02-01 19:54:04 UTC
Created attachment 202661 [details]
trace.dat of trace-cmd record session #2

I created another full trace of:
1. Booted up with rfkill switch activated
2. Deactivated rfkill switch after some seconds
3. Reactivated rfkill switch after some seconds

I'll crate another trace of just the rfkill switch reactivation.
Comment 28 Wolfram Schlich 2016-02-01 20:00:25 UTC
Created attachment 202671 [details]
trace.dat of trace-cmd record session #3

trace.dat of trace-cmd record session #3

I created a trace of just step 3 of the following steps:
1. Booted up with rfkill switch activated
2. Deactivated rfkill switch after some seconds
3. Reactivated rfkill switch after some seconds
Comment 29 Emmanuel Grumbach 2016-02-01 21:31:00 UTC
in trace from comment #27, I can't see where you reactivated the rfkill switch
It seems like you booted with RFkill switch activated an deactivated it.

In capture from comment #28, I can see that the RFKill interrupt is enabled, so we should get the interrupt. And we don't...
I don't know what to say here, I can't do much if I can't get an interrupt that is not masked.
Comment 30 Wolfram Schlich 2016-02-03 08:56:37 UTC
Regarding comment #27: Interesting... I *did* reactivate it, for sure.

Regarding comment #28: Hmm. So what kind of issue could we have here? System BIOS/firmware issue? iwlwifi firmware issue?
Comment 31 Emmanuel Grumbach 2016-02-03 09:10:40 UTC
I guess you can try to dump the CSR registers (there is a debugfs hook for that) and paste / attach the output after you reactivate the switch. It will rule out the interrupt masking.
Comment 32 Wolfram Schlich 2016-02-04 16:00:44 UTC
How do I do that? :)
Comment 33 Emmanuel Grumbach 2016-02-07 06:51:50 UTC
(In reply to Wolfram Schlich from comment #32)
> How do I do that? :)

Sorry for the delay:

echo 1 > /sys/kernel/debug/iwlwifi/0000\:03\:00.0/trans/csr

then check the dmesg output
Comment 34 Wolfram Schlich 2016-02-08 08:39:56 UTC
Rebuilding my kernel with CONFIG_IWLWIFI_DEBUGFS=y :P

When exactly in the following sequence should I be doing that echo command?

1. Boot up with rfkill switch activated
2. Deactivate rfkill switch after some seconds
3. Reactivate rfkill switch after some seconds
Comment 35 Emmanuel Grumbach 2016-02-08 08:42:24 UTC
When you feel that the rfkill switch doesn't take action.

I guess after 3 then :)
Comment 36 Emmanuel Grumbach 2016-02-08 08:42:31 UTC
When you feel that the rfkill switch doesn't take action.

I guess after 3 then :)
Comment 37 Wolfram Schlich 2016-02-08 15:42:31 UTC
Because I was curious, I've taken the CSR dump after each of the 3 steps ;)

booted up with rfkill enabled:

CSR values:
(2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
       CSR_HW_IF_CONFIG_REG: 0X40400000
         CSR_INT_COALESCING: 0X80000000
                    CSR_INT: 0X00000000
               CSR_INT_MASK: 0X00000080
          CSR_FH_INT_STATUS: 0X00000000
                CSR_GPIO_IN: 0X00000000
                  CSR_RESET: 0X00000001
               CSR_GP_CNTRL: 0X000003d0
                 CSR_HW_REV: 0X00000144
             CSR_EEPROM_REG: 0X00000000
              CSR_EEPROM_GP: 0X80000000
             CSR_OTP_GP_REG: 0X803a0000
                CSR_GIO_REG: 0X00080042
           CSR_GP_UCODE_REG: 0X00000000
          CSR_GP_DRIVER_REG: 0X00000000
          CSR_UCODE_DRV_GP1: 0X00000000
          CSR_UCODE_DRV_GP2: 0X00000000
                CSR_LED_REG: 0X00000018
       CSR_DRAM_INT_TBL_REG: 0X00000000
       CSR_GIO_CHICKEN_BITS: 0X27800200
            CSR_ANA_PLL_CFG: 0Xd55555d5
     CSR_MONITOR_STATUS_REG: 0X0000019c
          CSR_HW_REV_WA_REG: 0X0001001a
       CSR_DBG_HPET_MEM_REG: 0X82000500

rfkill deactivated:

CSR values:
(2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
       CSR_HW_IF_CONFIG_REG: 0X40489204
         CSR_INT_COALESCING: 0X80000040
                    CSR_INT: 0X00000000
               CSR_INT_MASK: 0Xbb00008b
          CSR_FH_INT_STATUS: 0X00000000
                CSR_GPIO_IN: 0X00000000
                  CSR_RESET: 0X00000000
               CSR_GP_CNTRL: 0X080403c5
                 CSR_HW_REV: 0X00000144
             CSR_EEPROM_REG: 0X00000000
              CSR_EEPROM_GP: 0X80000000
             CSR_OTP_GP_REG: 0X803a0000
                CSR_GIO_REG: 0X001f0042
           CSR_GP_UCODE_REG: 0X00000000
          CSR_GP_DRIVER_REG: 0X00000000
          CSR_UCODE_DRV_GP1: 0X00000000
          CSR_UCODE_DRV_GP2: 0X00000000
                CSR_LED_REG: 0X00000060
       CSR_DRAM_INT_TBL_REG: 0X880fffff
       CSR_GIO_CHICKEN_BITS: 0X27800200
            CSR_ANA_PLL_CFG: 0Xd55555d5
     CSR_MONITOR_STATUS_REG: 0X3d0801bd
          CSR_HW_REV_WA_REG: 0X0001001a
       CSR_DBG_HPET_MEM_REG: 0Xffff0000

rfkill reactivated:

CSR values:
(2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
       CSR_HW_IF_CONFIG_REG: 0X40489204
         CSR_INT_COALESCING: 0X80000040
                    CSR_INT: 0X00000000
               CSR_INT_MASK: 0Xbb00008b
          CSR_FH_INT_STATUS: 0X00000000
                CSR_GPIO_IN: 0X00000000
                  CSR_RESET: 0X00000000
               CSR_GP_CNTRL: 0X080403c5
                 CSR_HW_REV: 0X00000144
             CSR_EEPROM_REG: 0X00000000
              CSR_EEPROM_GP: 0X80000000
             CSR_OTP_GP_REG: 0X803a0000
                CSR_GIO_REG: 0X001f0042
           CSR_GP_UCODE_REG: 0X00000000
          CSR_GP_DRIVER_REG: 0X00000000
          CSR_UCODE_DRV_GP1: 0X00000000
          CSR_UCODE_DRV_GP2: 0X00000000
                CSR_LED_REG: 0X00000060
       CSR_DRAM_INT_TBL_REG: 0X880fffff
       CSR_GIO_CHICKEN_BITS: 0X27800200
            CSR_ANA_PLL_CFG: 0Xd55555d5
     CSR_MONITOR_STATUS_REG: 0X3c08019d
          CSR_HW_REV_WA_REG: 0X0001001a
       CSR_DBG_HPET_MEM_REG: 0Xffff0000
Comment 38 Wolfram Schlich 2016-02-11 11:45:06 UTC
Emmanuel? :)
Comment 39 Emmanuel Grumbach 2016-02-11 13:02:25 UTC
Somehow, I saw that only now... OK thanks. I am traveling but I'll take a look.
Comment 40 Emmanuel Grumbach 2016-02-11 17:23:38 UTC
Yes - so it seems really clear that the rfkill state didn't change in the device even (regardless of the interrupt):

CSR_GP_CNTRL: 0X080403c5

bit 27 set means that RFKILL is de-activated. Nothing I can do from here.
Comment 41 Emmanuel Grumbach 2016-02-11 17:42:47 UTC
Created attachment 203531 [details]
fixup

found a bug in the patch.

can you please apply this on top of the previous fix?
I don't think it will fix the problem you were reporting though.
Comment 42 Wolfram Schlich 2016-02-12 07:10:02 UTC
(In reply to Emmanuel Grumbach from comment #40)
> Yes - so it seems really clear that the rfkill state didn't change in the
> device even (regardless of the interrupt):
> 
> CSR_GP_CNTRL: 0X080403c5
> 
> bit 27 set means that RFKILL is de-activated. Nothing I can do from here.

Hrmz. Thanks for your investigation!
So is this something I should contact Dell about instead?

(In reply to Emmanuel Grumbach from comment #41)
> Created attachment 203531 [details]
> fixup
> 
> found a bug in the patch.
> 
> can you please apply this on top of the previous fix?
> I don't think it will fix the problem you were reporting though.

Applied. Anything specific I should test?
Comment 43 Emmanuel Grumbach 2016-02-12 11:12:50 UTC
Make sure it didn't break and the original bug is still fixed :)
Comment 44 Emmanuel Grumbach 2016-02-14 08:20:35 UTC
You can try to blacklist dell_wmi dell_laptop and friends.
Not sure it'll help though.
Comment 45 Wolfram Schlich 2016-02-15 16:17:26 UTC
Ok, it still works with your latest version of the patch.

I also enabled CONFIG_DELL_RBTN and now the rfkill stuff works flawless (booting up with rfkill activated, deactivating rfkill, reactivating rfkill etc.).

Here's the description of CONFIG_DELL_RBTN:
> Say Y here if you want to support Dell Airplane Mode
> Switch ACPI device on Dell laptops. Sometimes it has
> names: DELLABCE or DELRBTN.
> This driver register rfkill device or input hotkey
> device depending on hardware type (hw switch slider
> or keyboard toggle button).
> For rfkill devices it receive HW switch events and
> set correct hard rfkill state.

Seems that finally fixed it in conjunction with your patch :)
Comment 46 Wolfram Schlich 2016-02-15 16:17:55 UTC
Oh, I almost forgot: THANK YOU! :)
Comment 47 Emmanuel Grumbach 2016-02-15 16:37:46 UTC
The fix has been sent upstream today. It will be included in the final version of 4.5. It is too big to be sent to stable.
Comment 48 Wolfram Schlich 2016-02-17 15:59:31 UTC
Thanks! :-)

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