Re: WiFi AP selection

[Clive McCarthy <clivemccarthy gmail com>]

No wonder the thing doesn't work: A supplicant can be a fervently religious person who prays to God for help with a problem.
Praying to god has never worked for me.

On 10/22/19 7:49 PM, Dan Williams wrote:

On Tue, 2019-10-22 at 15:00 -0700, Clive McCarthy wrote:

The only odd thing I see is: current_signal=-54 current_noise=9999

What I think is happening is a wpa_supplicant bug with roaming and
"reassociate" handling. For some reason the supplicant sets a
reassociate flag when a given WiFi network is selected by NM, and that
short-circuits the signal checks in wpa_supplicant_need_to_roam() which
is called by wpas_select_network_from_last_scan() which itself is
called by wpa_supplicant_fast_associate() which is called by
wpa_supplicant_select_network().

We'll need to check with wpa_supplicant to see if this is intended
behavior (I can't think why it would be) or if this analysis is in
error.

Dan

On 10/22/19 2:24 PM, Dan Williams wrote:

On Tue, 2019-10-22 at 13:37 -0700, Clive McCarthy wrote:

I rand the commands you suggested but the response doesn't look
like
a log dump. I guess they just enable logging.

method return time=1571775394.161873 sender=:1.8 ->
destination=:1.507 serial=32493 reply_serial=2
method return time=1571775429.864202 sender=:1.8 ->
destination=:1.508 serial=32496 reply_serial=2
method return time=1571775528.578915 sender=:1.8 ->
destination=:1.510 serial=32636 reply_serial=2

Can you point me to where the log files might be or at least
their
names.

If your distribution uses systemd, they may be available with:

journalctl -b -u wpa_supplicant

if your distro does not uses systemd, then it'll be wherever syslog
dumps that kind of output, like:

/var/log/messages
/var/log/wpa_supplicant.log
/var/log/daemon.log

Dan

On 10/22/19 12:16 PM, Dan Williams wrote:

On Tue, 2019-10-22 at 11:17 -0700, Clive McCarthy wrote:

Thanks for your reply.
My laptop, when first opened, reports (via the Network
Manage, I
suppose) that it is disconnected from the network. After a
second
or
two it reports being connected. And it is. However, as I
noted,
the
manager seems to choose the last known connection. This is a
satisfactory algorithm for a fixed computer and for a
computer
connecting to a single AP. It isn't good for a movable
computer
with
multiple APs.

The Intel WiFi adapter is forced to shutdown when the
computer is
closed because there is a bug in the Intel-WiFi driver that
doesn't
handle suspend correctly. That is why there is a disconnect-
connect
sequence.

In this case we'd need the wpa_supplicant logs described below
to
diagnose why the supplicant is picking that specific AP rather
than
another.

Dan

On 10/22/19 10:05 AM, Dan Williams wrote:

On Mon, 2019-10-21 at 20:42 -0700, Clive McCarthy via
networkmanager-
list wrote:

I have a situation where I have multiple APs in a
building
all
with
the same SSID and WPA key but set to non-clashing
frequencies.
When I
close my laptop and WiFi shuts down and I move to a new
location
the
Network Manager seems to connect to the original AP,
rather
than
one
with a much stronger signal.

The algorithm for AP connection is suboptimal (in other
words
dumb).
The selection process should scan ALL APs, figure out
which
ones
are
known (SSID and WPA); measure their signal strength and
then
choose
the known AP with the strongest signal.

How hard is that?

This is what NetworkManager should already be doing.

Two things to check:

1) NetworkManager depends on being notified by systemd or
upower
that
the laptop has suspended so that it can reconfigure when it
wakes
up.
It should be pretty clear if that's happening through the
NetworkManager logs because it will say that it's going to
sleep
and
waking up. For example:

NetworkManager[1198]: <info>  [1571720491.7590] manager:
sleep:
sleep requested (sleeping: no  enabled: yes)
NetworkManager[1198]: <info>  [1571720491.7599] device
(wlp61s0):
state change: disconnected -> unmanaged (reason 'sleeping',
sys-
iface-state: 'managed')
NetworkManager[1198]: <info>  [1571720491.7615] manager:
NetworkManager state is now ASLEEP
NetworkManager[1198]: <warn>  [1571752873.5481] sup-
iface[0x55f38553aaa0,wlp61s0]: connection disconnected
(reason
-3)
NetworkManager[1198]: <info>  [1571752873.5504] device
(wlp61s0):
supplicant interface state: completed -> disconnected
NetworkManager[1198]: <info>  [1571752873.5803] manager:
sleep:
wake requested (sleeping: yes  enabled: yes)
NetworkManager[1198]: <info>  [1571752873.6556] device
(wlp61s0):
state change: activated -> unmanaged (reason 'sleeping',
sys-
iface-
state: 'managed')

2) enabling debug logging in wpa_supplicant with these two
commands
will show you exactly what's going on:

sudo dbus-send --system --print-reply --
dest=fi.w1.wpa_supplicant1
/fi/w1/wpa_supplicant1 org.freedesktop.DBus.Properties.Set
string:fi.w1.wpa_supplicant1 string:DebugTimestamp
variant:boolean:true
sudo dbus-send --system --print-reply --
dest=fi.w1.wpa_supplicant1
/fi/w1/wpa_supplicant1 org.freedesktop.DBus.Properties.Set
string:fi.w1.wpa_supplicant1 string:DebugLevel
variant:string:"msgdump"

this will dump logs to wherever your system typically sends
system
logs, like the systemd journal or syslog. Once you have
these
logs,
please review them to ensure there is no private
information
and
then
attach them to a reply so that we can figure out what's
going
on.

Thanks!
Dan