iwl3945 delayed scan results after resume

[Dan Nicholson]

On Fri, Sep 5, 2008 at 1:08 PM, Dan Nicholson <dbn.lists at gmail.com> wrote:
>
> Thanks. That patch seems to help, but I think there's still something
> wrong going on. With that patch, association drops from ~30 seconds to
> ~15 seconds. But if I look at the debug log for wpa again, it's doing
> what I want by triggering a full scan immediately, but it still
> doesn't find the AP until wpa reschedules another scan 5 seconds
> later.
>
> What I'm noticing now is that with or without the patch, wpa schedules
> two broadcast scans first that do nothing. It's not until the third
> scan where it scans specifically for my AP.
>
> 1220546429.722841: Setting scan request: 0 sec 0 usec
> 1220546429.722879: State: DISCONNECTED -> SCANNING
> 1220546429.722924: Starting AP scan (broadcast SSID)
> 1220546429.722928: Trying to get current scan results first without
> requesting a new scan to speed up initial association
> ...
> 1220546429.722996: Setting scan request: 0 sec 0 usec
> 1220546429.723006: Starting AP scan (broadcast SSID)
> ...
> 1220546433.440267: No suitable AP found.
> 1220546433.440275: Setting scan request: 5 sec 0 usec
> ...
> 1220546433.444180: State: SCANNING -> DISCONNECTED
> ...
> 1220546438.441164: State: DISCONNECTED -> SCANNING
> 1220546438.441298: Starting AP scan (specific SSID)
> 1220546438.441304: Scan SSID - hexdump_ascii(len=5):
>     64 77 63 61 62                                    dwcab
>
> So now that it scans for my specific AP, it finds it immediately and
> starts associating. So, what's causing the two broadcast scans before
> it scans for my SSID? Why isn't it trying the specific scan
> immediately? I can't quite figure out what's going on in
> wpa_supplicant_scan().

The basic cause of the slowness seems to be: scanning is slow and it's
done excessively. Here is the order of events following an NM wake
event as best as I can tell.

1. NM queries the state of wpa. If it finds it's ready, it initiates a
scan to get fresh results.

2. After doing a broadcast scan, wpa sends out the scan results.

3. NM iterates over the results looking for my AP. If it's found, it
sends an addNetwork/selectNetwork to wpa.

4. Receiving selectNetwork causes wpa to rescan for that specific
SSID. If found, it associates with the AP.

It seems there are a couple issues here.

First, if NM knows that I prefer to connect to a specific SSID, it
would be better if it asked to scan for that specific SSID initially
and not do a broadcast scan. If the specific scan fails, it should
then fallback to the broadcast scan and take action from there. I
don't know if this is a limitation of the wpa dbus interface. I.e., do
we need to initiate a scan first before doing
addNetwork/selectNetwork?

Second, if wpa has just done a broadcast scan and NM sends it a
selectNetwork, it would be better if wpa didn't rescan for that
specific SSID. Instead, it could just check if that SSID is in the
list returned by the previous broadcast scan, falling back to the scan
if it's not there. Possibly it would be good to check that the
broadcast scan had been done recently (e.g., 30 secs) before making
the assumption that those results were still valid.

Those two issues kind of oppose each other. The key here would be to
go from 2 scans to 1 in the case that we have a specific SSID we want
to use. I spent some time looking through the wpa and NM code trying
to decipher the exact order of operations and how they might be fixed,
but it was a little over my head.

Comments? Am I off base in that analysis?

--
Dan