Bug#525315: connect/disconnect loops with ifupdown and wpa_supplicant in roaming mode
Paride Legovini
Version: 0.7~alpha3
Severity: normal
When I connect to a wireless network it happens quite often that
wpa_supplicant connects/disconnects a couple of times before the link
becomes stable. This is not a major issue when my network is configured
in this way (/etc/network/interfaces):
iface ath0 inet manual
wpa-driver wext
wpa-roam /etc/wpa_supplicant.conf
iface default inet manual
I can bring the interface up with 'ifup ath0', wpa_supplicant does what
I just described but then the link is stable, and I can manually run
'dhclient ath0' to get an IP address.
Things go differently when I try to automatize the call to dhclient. I
modified the logical interface 'default' in /etc/network/interfaces this
way:
iface default inet dhcp
and again I try to run 'ifup ath0'. In the rare cases in which
wpa_supplicant CONNECTs just one time, without weird cycles, everything
works fine: dhclient is called and the interface gets its IP address.
But too often wpa_supplicant doesn't work so neatly, and causes the
ifupdown/wpa_supplicant/dhclient machinery to enter an endless loop of
CONNECTs and DISCONNECTs.
What it's strange is that even wpa_supplicant loses the association to
the access point. Here is a piece of syslog, more or less a 'period' of
the loop:
Apr 23 17:34:50 moth wpa_supplicant[16299]: Associated with 00:16:e3:6b:0f:93
Apr 23 17:34:50 moth wpa_supplicant[16299]: CTRL-EVENT-CONNECTED - Connection to 00:16:e3:6b:0f:93 completed (reauth) [id=2 id_str=]
Apr 23 17:34:50 moth kernel: ath0: RX AssocResp from 00:16:e3:6b:0f:93 (capab=0x411 status=0 aid=2)
Apr 23 17:34:50 moth kernel: ath0: associated Apr 23 17:34:50 moth kernel: ADDRCONF(NETDEV_CHANGE): ath0: link becomes ready
Note that what probably already running, called by a precedent
connection attemp.
Apr 23 17:35:00 moth dhclient: DHCPDISCOVER on ath0 to 255.255.255.255 port 67 interval 15
Apr 23 17:35:00 moth dhclient: DHCPOFFER from 192.168.1.1
Apr 23 17:35:00 moth dhclient: DHCPREQUEST on ath0 to 255.255.255.255 port 67
Apr 23 17:35:00 moth kernel: ath0: no IPv6 routers present
Apr 23 17:35:08 moth dhclient: DHCPREQUEST on ath0 to 255.255.255.255 port 67
Apr 23 17:35:08 moth dhclient: DHCPACK from 192.168.1.1
Apr 23 17:35:08 moth dhclient: bound to 192.168.1.16 -- renewal in 33870 seconds.
Got an IP! PLEASE PLEASE stop here! Don't you see, damned machine, that
you got everything you need? But no. See what happens: it seems that
another dhclient is called and told to DHCPRELEASE the IP.
Apr 23 17:35:08 moth dhclient: There is already a pid file /var/run/dhclient.ath0.pid with pid 21021
Apr 23 17:35:08 moth dhclient: killed old client process, removed PID file
Apr 23 17:35:08 moth dhclient: Internet Systems Consortium DHCP Client V3.1.2
Apr 23 17:35:08 moth dhclient: Copyright 2004-2008 Internet Systems Consortium.
Apr 23 17:35:08 moth dhclient: All rights reserved.
Apr 23 17:35:08 moth dhclient: For info, please visit http://www.isc.org/sw/dhcp/
Apr 23 17:35:08 moth dhclient:
Apr 23 17:35:08 moth dhclient: Listening on LPF/ath0/00:0e:9b:9d:96:1e
Apr 23 17:35:08 moth dhclient: Sending on LPF/ath0/00:0e:9b:9d:96:1e
Apr 23 17:35:08 moth dhclient: Sending on Socket/fallback
Apr 23 17:35:08 moth dhclient: DHCPRELEASE on ath0 to 192.168.1.1 port 67
Apr 23 17:35:08 moth wpa_supplicant[16299]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_supplicant got disconnected, as if that dhclient process that
released the IP provoked also this disconnection. Strange.
Can this really happen?
Apr 23 17:35:08 moth kernel: ath0: deauthenticating by local choice (reason=3) Apr 23 17:35:08 moth kernel: ADDRCONF(NETDEV_UP): ath0: link is not ready
Yet another dhclient is started?
Apr 23 17:35:08 moth dhclient: Internet Systems Consortium DHCP Client V3.1.2
Apr 23 17:35:08 moth dhclient: Copyright 2004-2008 Internet Systems Consortium.
Apr 23 17:35:08 moth dhclient: All rights reserved.
Apr 23 17:35:08 moth dhclient: For info, please visit http://www.isc.org/sw/dhcp/
Apr 23 17:35:08 moth dhclient:
Apr 23 17:35:09 moth dhclient: Listening on LPF/ath0/00:0e:9b:9d:96:1e
Apr 23 17:35:09 moth dhclient: Sending on LPF/ath0/00:0e:9b:9d:96:1e
Apr 23 17:35:09 moth dhclient: Sending on Socket/fallback
Apr 23 17:35:11 moth dhclient: DHCPDISCOVER on ath0 to 255.255.255.255 port 67 interval 8
Apr 23 17:35:19 moth dhclient: DHCPDISCOVER on ath0 to 255.255.255.255 port 67 interval 10
Apr 23 17:35:19 moth wpa_supplicant[16299]: CTRL-EVENT-SCAN-RESULTS
Apr 23 17:35:19 moth wpa_supplicant[16299]: Trying to associate with 00:16:e3:6b:0f:93 (SSID='dorfmatratze' freq=2462 MHz)
Then, after a couple of attempts wpa_supplicant connects again, dhclient
gets an IP that is immediately released, wpa_supplicant disconnects, and
so on.
I try to stop this mess with 'wpa_action ath0 stop', which should be the
right thing to do. It doesn't work well: after I run if ifupdown
considers the interface deconfigured, but there are still some processes
running in background, e.g. dhclient3 and 'ifup -v ath0' (or default?).
Killing dhclient3 cleans everything.
I tried to modify the hysteresis time interval, both trying to disable
it and to increase it to 8 seconds, but with no benefit at all.
Now I'm using 0.7~alpha3, but I encountered the same behavior with
0.6.8+nmu1 from sid.
I'd really like to help fixing this, but I'm running out of good ideas.
What could I try?
Thank you,
pl
-- System Information:
Debian Release: squeeze/sid
APT prefers unstable
APT policy: (500, 'unstable'), (1, 'experimental')
Architecture: i386 (i686)
Kernel: Linux 2.6.30-rc3 (SMP w/2 CPU cores; PREEMPT)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/bash
Versions of packages ifupdown depends on:
ii debconf [debconf-2.0] 1.5.26 Debian configuration management sy
ii iproute 20090324-1 networking and traffic control too
ii libc6 2.9-7 GNU C Library: Shared libraries
ii lsb-base 3.2-22 Linux Standard Base 3.2 init scrip
ii net-tools 1.60-23 The NET-3 networking toolkit
ifupdown recommends no packages.
Versions of packages ifupdown suggests:
ii dhcp3-client 3.1.2-1 DHCP client
pn ppp <none> (no description available)
-- debconf information:
ifupdown/convert-interfaces: true
--
To UNSUBSCRIBE, email to debian-bugs-...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Hagen Fuchs
Version: 0.8.35+b1
Followup-For: Bug #525315
Hey,
I'm pretty sure this should be filed as a bug to wpasupplicant.
In my case (same phenomena on display as OP reported), increasing the
hysteresis timeout to 10 seconds was enough to stop the cycling reliably.
For the record that would be 10 seconds (instead of 4) in
wpa_hysteresis_check() in /etc/wpa_supplicant/functions.sh (a
pro-forma patch is attached).
The actual question here is: how do I debug this cycle properly?