First STA scan results are ignored if P2P_FIND is issued immediately after STA scan
Sreenath
sreenats
Tue Mar 26 00:21:36 PDT 2013
Hello All,
With the latest wpa_supplicant I have found an issue that the first STA
scan results are not processed if P2P_FIND is issued immediately in P2P
interface after issuing a STA scan in STA interface. However the
subsequent STA scan results are processed during ongoing P2P_FIND operation.
In the attached log STA scan log message is around line number:14 and
P2P_FIND log message is around line number:30. Around line number:49, it
can be seen that during the processing of STA scan results as
'wpa_s->sta_scan_pending' is zero, pending P2P_FIND is started
immediately without processing received STA scan results. Because of
this behaviour no STA scan results are coming to 'wpa_cli'. However for
subsequent STA scans as P2P_FIND is in progress,
'wpa_s->sta_scan_pending' is set to one and because of that processing
of pending P2P operation won't happen and processing of STA scan results
will happen. The same can be verified around line number:108 in the
attached log.
So as a work around / fix, if the processing of pending P2P operation is
removed from function - '_wpa_supplicant_event_scan_results()'
everything works fine as STA results will be processed always and
pending P2P operation will be taken cared by the function -
"wpas_p2p_continue_after_scan()" called after
"wpa_supplicant_event_scan_results()" inside 'EVENT_SCAN_RESULTS' event
handling in "wpa_supplicant_event()".
So kindly verify and update me, if the above modification is valid.
*NB:*/Somehow I can't send mail to HostAP mailing list with attachment.
So I have pasted trimmed log file as in line. /
Regards,
Sreenath
--------- beginning of /dev/log/main
01-26 15:35:31.775 2688 2688 I wpa_supplicant: Successfully
initialized wpa_supplicant
01-26 15:35:31.780 2688 2688 D wpa_supplicant: nl80211: interface
wlan0 in phy phy0
01-26 15:35:31.880 2688 2688 D wpa_supplicant: wlan0: Added interface
wlan0
<---CLIPPED--->
01-26 15:35:31.880 2688 2688 D wpa_supplicant: nl80211: interface p2p0
in phy phy0
01-26 15:35:31.945 2688 2688 D wpa_supplicant: p2p0: Added interface p2p0
<---CLIPPED--->
<---First SCAN command issued--->
01-26 15:35:44.980 2689 2689 D wpa_supplicant: wlan0: Control
interface command 'SCAN'
01-26 15:35:44.980 2689 2689 D wpa_supplicant: wlan0: Setting scan
request: 0 sec 0 usec
01-26 15:35:44.980 2689 2689 D wpa_supplicant: wlan0: State:
DISCONNECTED -> SCANNING
01-26 15:35:44.980 2689 2689 D wpa_supplicant: wlan0: Starting AP scan
for wildcard SSID
01-26 15:35:44.985 2689 2689 D wpa_supplicant: wlan0: nl80211: scan
request
01-26 15:35:45.020 2689 2689 D wpa_supplicant: Scan requested (ret=0)
- scan timeout 10 seconds
01-26 15:35:45.020 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:45.020 2689 2689 D wpa_supplicant: wlan0: nl80211: Scan
trigger
01-26 15:35:45.805 2689 2689 D wpa_supplicant: RX ctrl_iface -
hexdump(len=8): 50 32 50 5f 46 49 4e 44
<---CLIPPED--->
<---P2P_FIND command issued--->
01-26 15:35:45.805 2689 2689 D wpa_supplicant: p2p0: Control interface
command 'P2P_FIND'
01-26 15:35:45.805 2689 2689 D wpa_supplicant: p2p0: P2P: Starting
find (type=0)
01-26 15:35:45.805 2689 2689 D wpa_supplicant: p2p0: P2P: Clear
timeout (state=IDLE)
01-26 15:35:45.805 2689 2689 D wpa_supplicant:
wpa_driver_set_ap_wps_p2p_ie: Entry
01-26 15:35:45.805 2689 2689 D wpa_supplicant: p2p0: P2P: State IDLE
-> SEARCH
01-26 15:35:45.805 2689 2689 D wpa_supplicant: p2p0: nl80211: scan request
01-26 15:35:45.805 2689 2689 D wpa_supplicant: nl80211: P2P probe -
mask SuppRates
01-26 15:35:45.810 2689 2689 D wpa_supplicant: nl80211: Scan trigger
failed: ret=-16 (Device or resource busy)
01-26 15:35:45.810 2689 2689 D wpa_supplicant: p2p0: P2P: Could not
start p2p_scan at this point - will try again after previous scan completes
01-26 15:35:45.810 2689 2689 D wpa_supplicant: p2p0: P2P: State SEARCH
-> SEARCH_WHEN_READY
01-26 15:35:47.440 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:47.440 2689 2689 D wpa_supplicant: wlan0: nl80211: New
scan results available
01-26 15:35:47.440 2689 2689 D wpa_supplicant: wlan0: Event
SCAN_RESULTS (3) received
01-26 15:35:47.440 2689 2689 D wpa_supplicant: wlan0: own_request=1,
wpa_s->global->p2p_cb_on_scan_complete=1, wpa_s->global->p2p_disabled=0,
wpa_s->global->p2p=0x0x402bea30, wpa_s->sta_scan_pending=0,
wpa_s->scan_res_handler=0x0x0
<---Processing pending P2P operation before STA scan results processing--->
01-26 15:35:47.440 2689 2689 D wpa_supplicant: p2p0: P2P: Starting
pending P2P find now that previous scan was completed
01-26 15:35:47.440 2689 2689 D wpa_supplicant: p2p0: P2P: Starting
find (type=0)
01-26 15:35:47.440 2689 2689 D wpa_supplicant: p2p0: P2P: Clear
timeout (state=SEARCH_WHEN_READY)
01-26 15:35:47.440 2689 2689 D wpa_supplicant:
wpa_driver_set_ap_wps_p2p_ie: Entry
01-26 15:35:47.440 2689 2689 D wpa_supplicant: p2p0: P2P: State
SEARCH_WHEN_READY -> SEARCH
01-26 15:35:47.440 2689 2689 D wpa_supplicant: p2p0: nl80211: scan request
01-26 15:35:47.440 2689 2689 D wpa_supplicant: nl80211: P2P probe -
mask SuppRates
01-26 15:35:47.480 2689 2689 D wpa_supplicant: Scan requested (ret=0)
- scan timeout 10 seconds
01-26 15:35:47.480 2689 2689 D wpa_supplicant: p2p0: P2P: Running p2p_scan
01-26 15:35:47.480 2689 2689 D wpa_supplicant: wlan0: P2P: Pending P2P
operation stopped scan processing
01-26 15:35:47.480 2689 2689 D wpa_supplicant: wlan0: Setting scan
request: 5 sec 0 usec
01-26 15:35:47.480 2689 2689 D wpa_supplicant: wlan0: P2P: Station
mode scan operation not pending anymore (sta_scan_pending=1
p2p_cb_on_scan_complete=0)
01-26 15:35:47.480 2689 2689 D wpa_supplicant: p2p0: nl80211: Scan trigger
01-26 15:35:48.420 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:48.420 2689 2689 D wpa_supplicant: p2p0: nl80211: New scan
results available
01-26 15:35:48.420 2689 2689 D wpa_supplicant: p2p0: Event
SCAN_RESULTS (3) received
01-26 15:35:48.420 2689 2689 D wpa_supplicant: p2p0: own_request=1,
wpa_s->global->p2p_cb_on_scan_complete=0, wpa_s->global->p2p_disabled=0,
wpa_s->global->p2p=0x0x402bea30, wpa_s->sta_scan_pending=0,
wpa_s->scan_res_handler=0x0x400477ed
01-26 15:35:48.425 2689 2689 D wpa_supplicant: nl80211: Received scan
results (35 BSSes)
01-26 15:35:48.425 2689 2689 D wpa_supplicant: nl80211: Survey data
missing
01-26 15:35:48.425 2689 2689 D wpa_supplicant: p2p0: BSS: Start scan
result update 1
<---CLIPPED--->
<---Second SCAN command issued--->
01-26 15:35:56.375 2689 2689 D wpa_supplicant: wlan0: Control
interface command 'SCAN'
01-26 15:35:56.375 2689 2689 D wpa_supplicant: wlan0: Setting scan
request: 0 sec 0 usec
01-26 15:35:56.375 2689 2689 D wpa_supplicant: wlan0: Delay station
mode scan while P2P operation is in progress
01-26 15:35:56.375 2689 2689 D wpa_supplicant: wlan0: Setting scan
request: 5 sec 0 usec
01-26 15:35:56.435 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:56.435 2689 2689 D wpa_supplicant: nl80211:
Remain-on-channel event (cancel=1 freq=2462 channel_type=0 duration=0
cookie=0x4bae (match))
01-26 15:35:56.435 2689 2689 D wpa_supplicant: p2p0: Event
CANCEL_REMAIN_ON_CHANNEL (23) received
01-26 15:35:56.435 2689 2689 D wpa_supplicant: P2P: Cancel
remain-on-channel callback (p2p_long_listen=0 ms pending_action_tx=0x0)
01-26 15:35:56.435 2689 2689 D wpa_supplicant: p2p0: P2P: Driver ended
Listen state (freq=2462)
01-26 15:35:56.435 2689 2689 D wpa_supplicant: p2p0: P2P: Timeout
(state=SEARCH)
01-26 15:35:56.435 2689 2689 D wpa_supplicant:
wpa_driver_set_ap_wps_p2p_ie: Entry
01-26 15:35:56.435 2689 2689 D wpa_supplicant: nl80211: Disable Probe
Request reporting nl_preq=0x402c3330
01-26 15:35:56.435 2689 2689 D wpa_supplicant: p2p0: P2P: Starting search
01-26 15:35:56.435 2689 2689 D wpa_supplicant: Delaying P2P scan to
allow pending station mode scan to be completed on interface wlan0
01-26 15:35:56.435 2689 2689 D wpa_supplicant: wlan0: Setting scan
request: 0 sec 0 usec
01-26 15:35:56.435 2689 2689 D wpa_supplicant: p2p0: P2P: Could not
start p2p_scan at this point - will try again after previous scan completes
01-26 15:35:56.440 2689 2689 D wpa_supplicant: p2p0: P2P: State SEARCH
-> CONTINUE_SEARCH_WHEN_READY
01-26 15:35:56.440 2689 2689 D wpa_supplicant: wlan0: Process pending
station mode scan during P2P search
01-26 15:35:56.440 2689 2689 D wpa_supplicant: wlan0: State: INACTIVE
-> SCANNING
01-26 15:35:56.440 2689 2689 D wpa_supplicant: wlan0: Starting AP scan
for wildcard SSID
01-26 15:35:56.440 2689 2689 D wpa_supplicant: wlan0: nl80211: scan
request
01-26 15:35:56.470 2689 2689 D wpa_supplicant: Scan requested (ret=0)
- scan timeout 30 seconds
01-26 15:35:56.470 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:56.475 2689 2689 D wpa_supplicant: wlan0: nl80211: Scan
trigger
01-26 15:35:58.485 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:58.485 2689 2689 D wpa_supplicant: wlan0: nl80211: New
scan results available
01-26 15:35:58.485 2689 2689 D wpa_supplicant: wlan0: Event
SCAN_RESULTS (3) received
<---Processing STA scan results before pending P2P operation processing--->
01-26 15:35:58.485 2689 2689 D wpa_supplicant: wlan0: own_request=1,
wpa_s->global->p2p_cb_on_scan_complete=1, wpa_s->global->p2p_disabled=0,
wpa_s->global->p2p=0x0x402bea30, wpa_s->sta_scan_pending=1,
wpa_s->scan_res_handler=0x0x0
01-26 15:35:58.490 2689 2689 D wpa_supplicant: nl80211: Received scan
results (44 BSSes)
01-26 15:35:58.490 2689 2689 D wpa_supplicant: nl80211: Survey data
missing
01-26 15:35:58.490 2689 2689 D wpa_supplicant: wlan0: BSS: Start scan
result update 1
<--CLIPPED--->
01-26 15:35:58.510 2689 2689 D wpa_supplicant: wlan0: No suitable
network found
01-26 15:35:58.510 2689 2689 D wpa_supplicant: wlan0: Short-circuit
new scan request since there are no enabled networks
01-26 15:35:58.510 2689 2689 D wpa_supplicant: wlan0: State: SCANNING
-> INACTIVE
01-26 15:35:58.510 2689 2689 D wpa_supplicant: wlan0: Checking for
other virtual interfaces sharing same radio (phy0) in event_scan_results
01-26 15:35:58.510 2689 2689 D wpa_supplicant: p2p0: Updating scan
results from sibling
01-26 15:35:58.510 2689 2689 D wpa_supplicant: p2p0: own_request=0,
wpa_s->global->p2p_cb_on_scan_complete=1, wpa_s->global->p2p_disabled=0,
wpa_s->global->p2p=0x0x402bea30, wpa_s->sta_scan_pending=0,
wpa_s->scan_res_handler=0x0x0
01-26 15:35:58.510 2689 2689 D wpa_supplicant: nl80211: Received scan
results (44 BSSes)
01-26 15:35:58.510 2689 2689 D wpa_supplicant: nl80211: Survey data
missing
01-26 15:35:58.510 2689 2689 D wpa_supplicant: p2p0: BSS: Start scan
result update 17
01-26 15:35:58.510 2689 2689 D wpa_supplicant: p2p0: BSS: Add new id
34 BSSID 00:90:4c:13:02:51 SSID 'Broadcom_5g_36'
<--CLIPPED--->
01-26 15:35:58.515 2689 2689 D wpa_supplicant: p2p0: No suitable
network found
01-26 15:35:58.515 2689 2689 D wpa_supplicant: p2p0: Short-circuit new
scan request since there are no enabled networks
01-26 15:35:58.515 2689 2689 D wpa_supplicant: p2p0: State:
DISCONNECTED -> INACTIVE
01-26 15:35:58.520 2689 2689 D wpa_supplicant: wlan0: P2P: Station
mode scan operation not pending anymore (sta_scan_pending=0
p2p_cb_on_scan_complete=1)
01-26 15:35:58.520 2689 2689 D wpa_supplicant: p2p0: P2P: State
CONTINUE_SEARCH_WHEN_READY -> SEARCH
01-26 15:35:58.520 2689 2689 D wpa_supplicant:
wpa_driver_set_ap_wps_p2p_ie: Entry
01-26 15:35:58.520 2689 2689 D wpa_supplicant: p2p0: P2P: Starting search
<--CLIPPED--->
01-26 15:35:58.520 2689 2689 D wpa_supplicant: p2p0: nl80211: scan request
01-26 15:35:58.520 2689 2689 D wpa_supplicant: nl80211: Scan frequency
2412 MHz
01-26 15:35:58.520 2689 2689 D wpa_supplicant: nl80211: Scan frequency
2437 MHz
01-26 15:35:58.520 2689 2689 D wpa_supplicant: nl80211: Scan frequency
2462 MHz
01-26 15:35:58.520 2689 2689 D wpa_supplicant: nl80211: P2P probe -
mask SuppRates
01-26 15:35:58.550 2689 2689 D wpa_supplicant: Scan requested (ret=0)
- scan timeout 30 seconds
01-26 15:35:58.550 2689 2689 D wpa_supplicant: p2p0: P2P: Running p2p_scan
01-26 15:35:58.550 2689 2689 D wpa_supplicant: wlan0: P2P: Pending P2P
operation continued after successful connection
01-26 15:35:58.550 2689 2689 D wpa_supplicant: p2p0: nl80211: Scan trigger
01-26 15:35:58.695 2689 2689 D wpa_supplicant: nl80211: Event message
available
01-26 15:35:58.695 2689 2689 D wpa_supplicant: p2p0: nl80211: New scan
results available
01-26 15:35:58.695 2689 2689 D wpa_supplicant: p2p0: Event
SCAN_RESULTS (3) received
01-26 15:35:58.695 2689 2689 D wpa_supplicant: p2p0: own_request=1,
wpa_s->global->p2p_cb_on_scan_complete=0, wpa_s->global->p2p_disabled=0,
wpa_s->global->p2p=0x0x402bea30, wpa_s->sta_scan_pending=0,
wpa_s->scan_res_handler=0x0x400477ed
01-26 15:35:58.695 2689 2689 D wpa_supplicant: nl80211: Received scan
results (44 BSSes)
01-26 15:35:58.695 2689 2689 D wpa_supplicant: nl80211: Survey data
missing
01-26 15:35:58.700 2689 2689 D wpa_supplicant: p2p0: BSS: Start scan
result update 18
01-26 15:35:58.700 2689 2689 D wpa_supplicant: BSS:
last_scan_res_used=43/64 last_scan_full=0
01-26 15:35:58.700 2689 2689 D wpa_supplicant: P2P: Scan results
received (44 BSS)
1-26 15:36:03.180 2689 2689 D wpa_supplicant: p2p0: nl80211: Scan trigger
<--CLIPPED--->
More information about the Hostap
mailing list