Bug 110831

Summary: iwlwifi: mvm: scheduled scan doesn't report results when no matches are passed - MWG100254662
Product: Drivers Reporter: wzhen12 (wu.zheng)
Component: network-wirelessAssignee: DO NOT USE - assign "network-wireless-intel" component instead (linuxwifi)
Status: CLOSED CODE_FIX    
Severity: normal CC: luca
Priority: P1    
Hardware: Intel   
OS: Linux   
Kernel Version: 4.1.13 Subsystem:
Regression: No Bisected commit-id:
Attachments: sched_scan log
normal scan log
wpa_supplicant's defconfig
sched_scan wpa log
sched_scan tracing log
sched_scan tracing with mac80211 cfg80211 iwlwifi_msg log
proposal patch, reject sched scans with no profiles

Description wzhen12 2016-01-15 06:19:50 UTC
Hardware: Intel edison with Intel 7260 chip.
Software:Connman-1.3, Wpa_supplicant-2.5 and kernel-4.1.13

The firmware of Intel 7260 is iwlwifi-7260-13.ucode.

Step:
1. After wifi is enabled, use the connman cmd of "connmanctl scan wifi" to scan wifi ap.

2. When use the connman cmd of "connmanctl scan wifi", connman will invoke the interfaces of Wpa_supplicant and Wpa_supplicant will trigger sched scan.

3. After trigger sched scan, no NL80211_CMD_SCHED_SCAN_RESULTS events come from kernel with Intel 7260 chip. 

4. Wpa_supplicant will always wait for the events of NL80211_CMD_SCHED_SCAN_RESULTS to get the sched scan results.

Expect:
NL80211_CMD_SCHED_SCAN_RESULTS events come from kernel with Intel 7260 chip.
Comment 1 Emmanuel Grumbach 2016-01-15 07:31:18 UTC
what firmware are you using?

Try to disable scheduled scan and see if it helps.
Comment 2 wzhen12 2016-01-15 07:46:47 UTC
Yes, after disable scheduled scan, it works well.
Comment 3 Emmanuel Grumbach 2016-01-15 07:59:46 UTC
please record tracing.

Look at https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging

I need 2 captures: one with scheduled scan and one without.
Comment 4 Emmanuel Grumbach 2016-01-24 07:09:16 UTC
Ping?

Our policy is to close that are pending for input within 2 weeks.
Comment 5 wzhen12 2016-01-24 14:40:06 UTC
sorry, I am busy for the other issue. I will provide it in next week.
Comment 6 wzhen12 2016-01-25 06:54:30 UTC
Created attachment 201361 [details]
sched_scan log

Add the sched scan log.

In the log, the log is got by the following steps.

After I disable normal scan, then enable sched scan and disable wifi.
Comment 7 wzhen12 2016-01-25 06:55:08 UTC
Created attachment 201371 [details]
normal scan log
Comment 8 Emmanuel Grumbach 2016-01-25 07:03:06 UTC
What do you mean, disable wifi?

If you disable wifi, nothing will work...

Your logs are useless. I asked for tracing, can't you get that?
Comment 9 wzhen12 2016-01-25 07:05:40 UTC
I dmesg > XXX.log to get log.

For tracing, how can I catch it?
Comment 10 wzhen12 2016-01-25 07:07:50 UTC
Kernel-4.1.15 is used in our system.
Comment 11 Emmanuel Grumbach 2016-01-25 07:16:18 UTC
(In reply to wzhen12 from comment #9)
> I dmesg > XXX.log to get log.
> 
> For tracing, how can I catch it?

Look at comment #3:
https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging#tracing

Please also tell me what AP you want to connect to (what profile you added to the scheduled scan).

FWIW: I consider disabling scheduled in upstream kernels and backport this to stable kernels.
Comment 12 wzhen12 2016-01-25 07:32:06 UTC
1. In https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging#tracing,

>To enable tracing, CONFIG_IWLWIFI_TRACING must be set.

CONFIG_IWLWIFI_TRACING has been removed in Kernel-4.1.15.

Can I need to set the other items?

2. >what profile you added to the scheduled scan?
I have no add any profiles to scheduled scan.
I use the standard wpa_supplicant to start scheduled scan.

>FWIW: I consider disabling scheduled in upstream kernels and backport this to
>stable kernels.
In short time, agree.
Comment 13 Emmanuel Grumbach 2016-01-25 07:37:36 UTC
You need to enable CONFIG_IWLWIFI_TRACING

You must have profiles configured to have the wpa_supplicant use scheduled scan...
Comment 14 wzhen12 2016-01-25 07:53:33 UTC
Created attachment 201381 [details]
wpa_supplicant's defconfig
Comment 15 wzhen12 2016-01-25 07:54:17 UTC
Maybe, I misunderstand what you mean.

The attachment is the defconfig of wpa_supplicant.
Comment 16 Emmanuel Grumbach 2016-01-25 08:15:54 UTC
Scheduled scan may be enabled in the config file but as long as you don't have configured profiles, the supplicant will not use scheduled scan since it is useless.
Comment 17 wzhen12 2016-01-25 08:22:56 UTC
Thanks to check.

To my knowledge, to wpa_supplicant, if wpa_supplicant get the info of scheduled scan enabled from kernel, wpa_supplicant will use scheduled scan to replace normal scan at some interval.
Comment 18 wzhen12 2016-01-28 06:15:29 UTC
Hi Emmanuel Grumbach,

Some security reasons, trace-cmd can't run in our system.
I am fixing it and will provide the related log as soon as possible.
Comment 19 wzhen12 2016-02-01 02:55:36 UTC
Created attachment 202541 [details]
sched_scan wpa log
Comment 20 wzhen12 2016-02-01 02:56:18 UTC
Created attachment 202551 [details]
sched_scan tracing log
Comment 21 Luca Coelho 2016-02-01 09:42:35 UTC
I took a quick look at the logs and it doesn't make much sense.  

wpa_supplicant is starting a sched_scan with no profiles, which should be okay if it wants to find any network.  This is a very unusual case, because it's the same as a normal scan, all the results will be returned every time it runs (unless you're in the middle of nowhere with no APs beaconing).

In this case, the driver should enable "any_beacon_notify", as can be seen in the code here:

	SCAN_CLIENT_SCHED_SCAN		= BIT(0),
[...]
	profile_cfg->num_profiles = req->n_match_sets;
[...]
	if (!req->n_match_sets || !req->match_sets[0].ssid.ssid_len)
		profile_cfg->any_beacon_notify = SCAN_CLIENT_SCHED_SCAN;

But this is the profile configuration command I can see in the logs:

837.190378: iwlwifi_dev_hcmd:     SCAN_OFFLOAD_UPDATE_PROFILES_CMD (0x00.0x6e)
                                      * blacklist_len = 0x0
                                      * num_profiles = 0x0
                                      * match_notify = 0x0
                                      * pass_match = 0x0
                                      * active_clients = 0x0
                                      * any_beacon_notify = 0x0
                                      * reserved = 00:00
837.190556: iwlwifi_dev_rx:       SCAN_OFFLOAD_UPDATE_PROFILES_CMD (0x6e)

This would most likely cause the firmware to return no result.

I'll check the exact code in the kernel version you mentioned (4.1.15) to see if there is something wrong there.
Comment 22 Luca Coelho 2016-02-01 09:55:27 UTC
You don't seem to have -e iwlwifi_msg enabled in your traces, could you rerun with that enabled as well? Please run it as described in the wiki:

sudo trace-cmd record -e iwlwifi -e mac80211 -e cfg80211 -e iwlwifi_msg
Comment 23 Luca Coelho 2016-02-01 10:48:03 UTC
Sorry, that problem with all zeros in the SCAN_OFFLOAD_UPDATE_PROFILES_CMD I pointed out above is actually a bug in our trace-cmd parser code.

Regardless, I now suspect that this can be an issue with the TLVs of our firmware (which are flags that tell us about the firmware APIs).  It's possible that we're using the wrong size for this command.
Comment 24 Luca Coelho 2016-02-01 16:07:15 UTC
Okay, after further investigation, I found out that the TLV is not the problem.

The actual problem is that our firmware will not send a notification to our driver when results are found but don't match any "match" entry (in this case, since there are no profiles, there are no match entries).

This use case (i.e. running a scheduled scan without any matches) is a bit useless, so I'm inclined to just reject this in the driver (as Emmanuel suggested).

Still, before I do that, I'll check if there are any other ways this problem could be fixed.
Comment 25 Luca Coelho 2016-02-01 16:18:23 UTC
Renaming the bug to better describe the case.
Comment 26 wzhen12 2016-02-02 02:12:57 UTC
Created attachment 202711 [details]
sched_scan tracing with mac80211 cfg80211 iwlwifi_msg log

sched_scan tracing with mac80211 cfg80211 iwlwifi_msg log.
Done.
Comment 27 Luca Coelho 2016-02-02 13:32:41 UTC
Created attachment 202761 [details]
proposal patch, reject sched scans with no profiles

Thanks!

As I said above, the problem appears to be that our firmware doesn't report that there were any matches, because there is nothing to match.  It passes all beacon/probe_resp up to the driver, and those results can be retrieved with scan dump, but there is no notifications to the userspace.

Can you try this patch? We haven't decided whether to solve it this way (i.e. rejecting "match all" scans), but it would be great if you could give it a spin to see if the system behaves better.
Comment 28 wzhen12 2016-02-03 04:02:43 UTC
I have tested the patches.

It can fix the current issue.

After schedule scan, normal scan of wpa_supplicant still can work well.
Comment 29 wzhen12 2016-02-03 04:03:21 UTC
And after connect AP, it looks like that schedule scan work too.
Comment 30 Luca Coelho 2016-02-03 06:50:39 UTC
Excellent! Thanks for testing!

So we now know that this works (at least with your version of wpa_s).  Maybe we go with this solution for stable kernels and look for a better way to fix it for future releases.
Comment 31 Emmanuel Grumbach 2016-02-07 15:29:41 UTC
The fix will be merged shortly. I'll close the bug then.
Comment 32 Luca Coelho 2016-02-08 07:15:48 UTC
This has been fixed and merged in our internal tree.  We will publish it soon (with CC stable).
Comment 33 wzhen12 2016-02-15 06:40:37 UTC
Can you share the link of the patch in upstream? Thanks.