wicd unable to reconnect, although I can do it "by hand"

[zsd]

wicd 1.7.0 on Slackware-64 13.0, 2.6.32.4
Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02)

On initial boot, and some otherr times, wicd connects to my wireless router very reliably.
Other times, particularly (but not always) after a resume from suspend to RAM, it will not reconnect.

Looking at the logs, it tries pinging the router and after 10 failures it gives up. I can press the "connect" button in the wicd-client gui as many times as I like, but repetition does not seem to help.

However (and this is the weird thing), if I run the wpa_supplicant, ifconfig and route commands 'by hand" in
a terminal window, the connection is successful.

I am at a bit of a loss as to why running the commands myself works, and yet wicd fails; the only thing that comes to mind is a race condition, but...

Any ideas? A portion of a wicd when this happened is shown below

Thanks.

-------------------

2010/03/05 20:55:24 :: Connecting to wireless network abcde
2010/03/05 20:55:24 :: /sbin/dhcpcd -k wlan0
err, wlan0: dhcpcd not running
2010/03/05 20:55:24 :: ifconfig wlan0 0.0.0.0
2010/03/05 20:55:24 :: /sbin/ip route flush dev wlan0
2010/03/05 20:55:24 :: ifconfig wlan0 down
2010/03/05 20:55:24 :: ifconfig wlan0 up
2010/03/05 20:55:24 :: wpa_cli -i wlan0 terminate
2010/03/05 20:55:24 :: /sbin/dhcpcd -k eth0
err, eth0: dhcpcd not running
2010/03/05 20:55:24 :: ifconfig eth0 0.0.0.0
2010/03/05 20:55:24 :: /sbin/ip route flush dev eth0
2010/03/05 20:55:24 :: ifconfig eth0 down
2010/03/05 20:55:24 :: ifconfig eth0 up
2010/03/05 20:55:24 :: Putting interface down
2010/03/05 20:55:24 :: ifconfig wlan0 down
2010/03/05 20:55:24 :: Releasing DHCP leases...
2010/03/05 20:55:24 :: /sbin/dhcpcd -k wlan0
err, wlan0: dhcpcd not running
2010/03/05 20:55:24 :: Setting false IP...
2010/03/05 20:55:24 :: ifconfig wlan0 0.0.0.0
2010/03/05 20:55:24 :: Stopping wpa_supplicant
2010/03/05 20:55:24 :: wpa_cli -i wlan0 terminate
Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
2010/03/05 20:55:24 :: Flushing the routing table...
2010/03/05 20:55:24 :: /sbin/ip route flush dev wlan0
2010/03/05 20:55:24 :: iwconfig wlan0 mode managed
2010/03/05 20:55:24 :: Putting interface up...
2010/03/05 20:55:24 :: ifconfig wlan0 up
2010/03/05 20:55:26 :: enctype is wep-hex
2010/03/05 20:55:26 :: Attempting to authenticate...
2010/03/05 20:55:26 :: ['wpa_supplicant', '-B', '-i', 'wlan0', '-c', '/var/lib/w
icd/configurations/0024012c5b16', '-D', 'wext']
2010/03/05 20:55:26 :: ['iwconfig', 'wlan0', 'essid', 'abcde']
2010/03/05 20:55:26 :: iwconfig wlan0 channel 8
2010/03/05 20:55:26 :: iwconfig wlan0 ap 00:24:01:2C:5B:16
2010/03/05 20:55:26 :: WPA_CLI RESULT IS COMPLETED
2010/03/05 20:55:26 :: Setting static IP : 192.168.1.3
2010/03/05 20:55:26 :: ifconfig wlan0 192.168.1.3 netmask 255.255.255.0
2010/03/05 20:55:26 :: Setting default gateway : 192.168.1.1
2010/03/05 20:55:26 :: route add default gw 192.168.1.1 dev wlan0
2010/03/05 20:55:26 :: Setting DNS : 142.177.2.130
2010/03/05 20:55:26 :: Setting DNS : 142.166.145.137
2010/03/05 20:55:26 :: Setting DNS : 142.177.129.11
2010/03/05 20:55:26 :: Verifying AP association...
2010/03/05 20:55:26 :: Attempt 1 of 10...
2010/03/05 20:55:26 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:30 :: Attempt 2 of 10...
2010/03/05 20:55:30 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:34 :: Attempt 3 of 10...
2010/03/05 20:55:34 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:37 :: Attempt 4 of 10...
2010/03/05 20:55:37 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:41 :: Attempt 5 of 10...
2010/03/05 20:55:41 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:45 :: Attempt 6 of 10...
2010/03/05 20:55:45 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:49 :: Attempt 7 of 10...
2010/03/05 20:55:49 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:53 :: Attempt 8 of 10...
2010/03/05 20:55:53 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:55:57 :: Attempt 9 of 10...
2010/03/05 20:55:57 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:56:01 :: Attempt 10 of 10...
2010/03/05 20:56:01 :: ping -q -w 3 -c 1 192.168.1.1
2010/03/05 20:56:05 :: Connection Failed: Failed to ping the access point!
2010/03/05 20:56:05 :: ifconfig wlan0 0.0.0.0
2010/03/05 20:56:05 :: /sbin/ip route flush dev wlan0
2010/03/05 20:56:05 :: wpa_cli -i wlan0 terminate
2010/03/05 20:56:05 :: exiting connection thread
2010/03/05 20:56:06 :: canceling connection attempt
2010/03/05 20:56:06 :: /sbin/dhcpcd -k wlan0
err, wlan0: dhcpcd not running
2010/03/05 20:56:06 :: running kill dhcp.
2010/03/05 20:56:06 :: wpa_cli -i wlan0 terminate
Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory
2010/03/05 20:56:06 :: Forced disconnect on
2010/03/05 20:56:06 :: Sending connection attempt result aborted
2010/03/05 20:56:06 :: ifconfig eth0
2010/03/05 20:56:06 :: ifconfig wlan0
2010/03/05 20:56:06 :: iwconfig wlan0
2010/03/05 20:56:08 :: ifconfig eth0
2010/03/05 20:56:08 :: ifconfig wlan0
2010/03/05 20:56:10 :: ifconfig eth0

[chconnor (t-launchpad-caseyconnor-org)]

Similar issue here... wicd 1.7.0 on Kubuntu 10.04, Actiontec DSL wireless router (with an internal dd-wrt "bridged" router as well; connecting to either produces the same result, described below:)

For me, almost every time I boot (I never sleep or hibernate) it goes through 2 or 3 cycles like this:

2010/08/23 23:12:46 :: trying to automatically connect to...MYESSID
2010/08/23 23:12:46 :: Connecting to wireless network MYESSID
2010/08/23 23:12:46 :: Putting interface down
2010/08/23 23:12:46 :: Releasing DHCP leases...
2010/08/23 23:12:46 :: Setting false IP...
2010/08/23 23:12:46 :: Stopping wpa_supplicant
2010/08/23 23:12:46 :: Flushing the routing table...
2010/08/23 23:12:46 :: Putting interface up...
2010/08/23 23:12:48 :: Attempting to authenticate...
2010/08/23 23:12:49 :: Setting static IP : 192.168.1.252
2010/08/23 23:12:49 :: Setting default gateway : 192.168.1.1
2010/08/23 23:12:49 :: Verifying AP association...
2010/08/23 23:12:49 :: Attempt 1 of 10...
2010/08/23 23:12:53 :: Attempt 2 of 10...
2010/08/23 23:12:57 :: Attempt 3 of 10...
2010/08/23 23:13:01 :: Attempt 4 of 10...
2010/08/23 23:13:05 :: Attempt 5 of 10...
2010/08/23 23:13:08 :: Attempt 6 of 10...
2010/08/23 23:13:12 :: Attempt 7 of 10...
2010/08/23 23:13:16 :: Attempt 8 of 10...
2010/08/23 23:13:19 :: Attempt 9 of 10...
2010/08/23 23:13:22 :: Attempt 10 of 10...
2010/08/23 23:13:26 :: Connection Failed: Failed to ping the access point!
2010/08/23 23:13:26 :: exiting connection thread
2010/08/23 23:13:28 :: Sending connection attempt result association_failed

Eventually it will connect, usually on the third attempt, though sometimes not, and I have to open up wicd and click "connect" and then it will usually work. Whenever it does connect, it's always on the first try, i.e. never after "Attempt 4" or any other...:

2010/08/23 23:13:53 :: Connecting to wireless network MYESSID
2010/08/23 23:13:54 :: Putting interface down
2010/08/23 23:13:54 :: Releasing DHCP leases...
2010/08/23 23:13:54 :: Setting false IP...
2010/08/23 23:13:54 :: Stopping wpa_supplicant
2010/08/23 23:13:54 :: Flushing the routing table...
2010/08/23 23:13:54 :: Putting interface up...
2010/08/23 23:13:56 :: Attempting to authenticate...
2010/08/23 23:13:57 :: Setting static IP : 192.168.1.252
2010/08/23 23:13:57 :: Setting default gateway : 192.168.1.1
2010/08/23 23:13:57 :: Verifying AP association...
2010/08/23 23:13:57 :: Attempt 1 of 10...
2010/08/23 23:13:57 :: Successfully associated.
2010/08/23 23:13:57 :: Connecting thread exiting.
2010/08/23 23:13:57 :: Sending connection attempt result Success

I've used wicd with this router unchanged for a couple of years without trouble. I think it was the 10.04 update that started the issues. This happens with dhcpd or dhclient, and with "external" or ioctl backend. If I deselect "ping static gateways after connecting", the Attempts go away and it looks as if it's connected (in the log, also the icon shows green) but no data goes through.

Very happy to pursue any debugging if anyone has any ideas, as it's pretty annoying to have to wait an extra couple minutes on every boot until connecting.

Thanks!

[chconnor (t-launchpad-caseyconnor-org)]

When I turn wicd's debug logging on, I notice that the final connection cycle just before connecting successfully shows the following additional lines in the log (the additional lines are prefaced with a *, the other lines occur every cycle, successful or not, until the "Attempt"s begin):

[...log lines the same as usual failing cycle...]
2010/08/26 21:21:26 :: /sbin/ip route flush dev eth1
2010/08/26 21:21:26 :: iwconfig eth1 mode managed
2010/08/26 21:21:26 :: Putting interface up...
2010/08/26 21:21:26 :: ifconfig eth1 up
*2010/08/26 21:21:27 :: Forced disconnect on
*2010/08/26 21:21:27 :: /sbin/dhcpcd-bin -k eth1
*2010/08/26 21:21:27 :: ifconfig eth1 0.0.0.0
*2010/08/26 21:21:27 :: /sbin/ip route flush dev eth1
*2010/08/26 21:21:27 :: ifconfig eth1 down
*2010/08/26 21:21:27 :: ifconfig eth1 up
*2010/08/26 21:21:27 :: wpa_cli -i eth1 terminate
*2010/08/26 21:21:27 :: /sbin/dhcpcd-bin -k eth0
*2010/08/26 21:21:27 :: ifconfig eth0 0.0.0.0
*2010/08/26 21:21:27 :: /sbin/ip route flush dev eth0
*2010/08/26 21:21:27 :: ifconfig eth0 down
*2010/08/26 21:21:27 :: ifconfig eth0 up
2010/08/26 21:21:28 :: enctype is wep-hex
2010/08/26 21:21:28 :: Attempting to authenticate...
2010/08/26 21:21:28 :: ['wpa_supplicant', '-B', '-i', 'eth1', '-c', '/var/lib/wicd/configurations/0214bfa6e655', '-D', 'wext']
2010/08/26 21:21:28 :: ['iwconfig', 'eth1', 'essid', '--', 'PANDA2']
2010/08/26 21:21:28 :: iwconfig eth1 channel 9
2010/08/26 21:21:28 :: iwconfig eth1 ap 02:14:BF:A6:E6:55
2010/08/26 21:21:28 :: WPA_CLI RESULT IS DISCONNECTED
2010/08/26 21:21:29 :: WPA_CLI RESULT IS COMPLETED
2010/08/26 21:21:29 :: Setting static IP : 192.168.1.252
2010/08/26 21:21:29 :: ifconfig eth1 192.168.1.252 netmask 255.255.255.0
2010/08/26 21:21:29 :: Setting default gateway : 192.168.1.1
2010/08/26 21:21:29 :: route add default gw 192.168.1.1 dev eth1
2010/08/26 21:21:29 :: Setting DNS : 205.171.3.65
2010/08/26 21:21:29 :: Setting DNS : 205.171.2.65
2010/08/26 21:21:29 :: Verifying AP association...
2010/08/26 21:21:29 :: Attempt 1 of 10...
2010/08/26 21:21:29 :: ping -q -w 3 -c 1 192.168.1.1
2010/08/26 21:21:29 :: Successfully associated.
2010/08/26 21:21:29 :: Connecting thread exiting.

[chconnor (t-launchpad-caseyconnor-org)]

Been spending some time with this one... My (uneducated) suspicion is that it has to do with an interrelation between wpa_supplicant and wicd. Ignore what i said in my previous comments about "Forced disconnect", etc.

On wicd's failed attempts, wpa_supplicant is failing to scan or authenticate, but is returning an "associated"/"completed" status and wicd thus believes that the AP is connected, but since the auth isn't actually complete the pinging fails.

I don't know why it eventually works. I'm guessing this is a bug in wpa_supplicant.

I'm running 10.04, wicd 1.70 and wpa_supplicant 0.6.9, and using WEP authentication (acknowledged: worthless).

@zsd, if you're still following this: what auth type and wpa_supplicant versions are/were you using? After failures in wicd's gui, can you ever get it to connect through repeated clicks on "connect" in the gui? How many times have you tried? For me, it connects after 3 or 4 attempts.

10.10 comes with wpa_supplicant 0.6.10-2... i am dist-upgrading soon and will test and report back. If it doesn't work, i'll look around some more for a workaround. There must be something that can be done with wpa_cli or wpa_supplicant to force it into some state that will work...

[zsd (zlists)]

I was using WEP at home (where the log above is from) and WPA/TKIP/PEAP at work. I upgraded to Slackware 13.1 about 6 months ago and I no longer remember for certain whether I had the same problem at work. (I normally connect using a wired connection at work, but not always.)

I was using wpa_supplicant 0.6.9 on Slack 13.0.

I don't recall ever getting it to work by repeatedly clicking the connect button in the gui. But at this point I don't recall how persistent I was. Certainly I would have tried 3 or 4 times, though.

Having said that, on Slack 13.1 (wpa supplicant 0.6.10) things are much more reliable, to the point where I will risk jinxing things by saying I have no problems whatsoever.

[chconnor (t-launchpad-caseyconnor-org)]

Ok, got it working (without upgrading wicd/ubuntu) by switching wpa_supplicant with a script that passes the call through and then immediately does a wpa_cli "reassociate", which apparently kicks wpa_supplicant back into a functional state for my situation.

Create the file /sbin/wpa_supplicant_fake with the following contents:

#!/bin/sh
/sbin/wpa_supplicant_real "$@"
/sbin/wpa_cli -i eth1 reassociate

Then mv the real one and add a symlink:
$ sudo mv /sbin/wpa_supplicant /sbin/wpa_supplicant_real
$ sudo ln -s /sbin/wpa_supplicant_fake /sbin/wpa_supplicant

...and confirm all appropriate permissions, etc.

This seems to do the trick for me (so far, anyway). Wicd has options (configurable per network profile) to use scripts pre- and post- connect and disconnect, but those are called before wpa_supplicant is called and after verification (the ping'ing) occurs, so i don't think they'd help. Not sure what the ramifications of my method would be when upgrading/updating, but it can easily be backed out before doing so.

I used an alternate version of the script for debugging:

#!/bin/sh
/sbin/wpa_supplicant_real -d -f/var/log/wpa_supplicant.log "$@"
/sbin/wpa_cli -i eth1 reassociate 2>&1 >> /var/log/wpa_cli.log

[chconnor (t-launchpad-caseyconnor-org)]

zsd - just saw your comment. Good to hear that maybe the update will fix it for real.

[chconnor (t-launchpad-caseyconnor-org)]

Updated to Kubuntu 10.10 (wpa_supplicant 0.6.10). Didn't fix it, so i'm using my hack, which still works. Now i'm glad i spent the time. :-)

wpa_supplicant seems to be called on startup by other processes (i see this via bootchart), so i don't know what affect my hack will have on that, but it's working for me so far, and i don't anticipate a problem from the startup calls.