Re: iwl3945 delayed scan results after resume

[Dan Williams <dcbw redhat com>]

On Thu, 2008-09-04 at 09:50 -0700, Dan Nicholson wrote:
> On Thu, Sep 4, 2008 at 8:55 AM, Dan Nicholson <dbn lists gmail com> wrote:
> > On Tue, Sep 2, 2008 at 8:39 AM, Dan Nicholson <dbn lists gmail com> wrote:
> >> On Mon, Aug 25, 2008 at 6:01 PM, Dan Nicholson <dbn lists gmail com> wrote:
> >>> After resuming, NM has an empty list of networks for about 30 seconds
> >>> before the scan results are populated and it reconnects to my AP. This
> >>> is on Fedora 9 with:
> >>>
> >>> NetworkManager-0.7.0-0.9.4.svn3675.fc9.i386
> >>> NetworkManager-gnome-0.7.0-0.9.4.svn3675.fc9.i386
> >>> kernel-2.6.25.14-108.fc9.i686
> >>> wpa_supplicant-0.6.3-6.fc9.i386
> >>> libnl-1.1-3.fc9.i386
> >>>
> >>> $ cat /sys/module/iwl3945/version
> >>> 1.2.26kds
> >>>
> >>> Doing some manual testing without NM, I find that if I run iwlist
> >>> immediately after bringing up the device, I get no results. But, if I
> >>> sleep for about half a second after bringing the device up, I get
> >>> results including my AP. So,
> >>>
> >>> # ifconfig wlan0 up && iwlist wlan0 scan
> >>> Shows no results
> >>>
> >>> # ifconfig wlan0 up && sleep 1 && iwlist wlan0 scan
> >>> Gets results
> >>>
> >>> Any chance this is connected to the delay with NM after resume? Is
> >>> there anything I can do to test further? I'd be willing to build a
> >>> wireless-testing kernel or something if this seems to be a driver
> >>> issue.
> >>
> >> So, the above is apparently not the problem since I can switch the
> >> driver to disable_hw_scan=1 and get scan results immediately after
> >> bringing the device up. Instead, this seems like it's an issue with
> >> wpa_supplicant taking a while to start associating with the AP again.
> >> If I'm connected to an unencrypted AP, NM reconnects immediately after
> >> resuming.
> >>
> >> Is this is an issue in wpa_supplicant? Or is NM waiting too long to
> >> tell wpa_supplicant to do something? If I watch the wpa log, it prints
> >> that there are scan results available for a while before it tries to
> >> reauth with the AP. Any ideas? I don't really understand how NM and
> >> wpa_supplicant interact.
> >
> > Here are logs from NM and wpa_supplicant (-dt). They show a full cycle
> > of sleep/wake sent to NM from dbus-send. This shows the same symptoms
> > as a suspend/resume cycle. I inserted a couple time markers in the wpa
> > log for when I sent the signals to NM.
> >
> > You can see that it takes 6 seconds (from 1220542139 to 1220542145)
> > before wpa starts scanning. I think what happens is that it tries to
> > use the cached set of scan results from the driver and gets nothing
> > back. This is consistent with doing "iwlist wlan0 scan last"
> > immediately after bringing the device up. It then waits 20 more
> > seconds (to 1220542165) before it goes into scanning mode again and
> > finds my AP. What's going on here?
> 
> This seems to fix a bug in wpa_supplicant where the scan request
> setting was not being restored if the initial association failed. This
> makes the reconnection much faster for me. Does this seem reasonable?
> Should I send this to the hostap list?

It can't hurt to see what Jouni says.  Thanks for taking a look at this.
I know there are a few issues with scanning in the supplicant still when
no networks have been configured, and this might be one of them.  I'll
take a closer look at the patch a bit later today too.

Dan