Problem with ReachRS and WiFi authentication

My ReachRS rover is configured to output position data over a TCP connection.

If my router is turned on before ReachRS boots all goes well. Here is an example of a successful connection (taken from syslog log on router).

Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.11: associated
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: event 1 notification
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: start authentication
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.1X: unauthorizing port
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: sending 1/4 msg of 4-Way Handshake
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: received EAPOL-Key frame (2/4 Pairwise)
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: sending 3/4 msg of 4-Way Handshake
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: received EAPOL-Key frame (4/4 Pairwise)
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.1X: authorizing port
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 RADIUS: starting accounting session 59F2AC1D-00000004
Oct 27 14:57:32 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: pairwise key handshake completed (RSN)
Oct 27 14:57:32 aaa dnsmasq-dhcp[563]: DHCPDISCOVER(wlan0) 11:22:33:44:55:66
Oct 27 14:57:32 aaa dnsmasq-dhcp[563]: DHCPOFFER(wlan0) 192.168.40.65 11:22:33:44:55:66
Oct 27 14:57:33 aaa dnsmasq-dhcp[563]: DHCPREQUEST(wlan0) 192.168.40.65 11:22:33:44:55:66
Oct 27 14:57:33 aaa dnsmasq-dhcp[563]: DHCPACK(wlan0) 192.168.40.65 11:22:33:44:55:66<

However, if ReachRS is powered on before the router then ReachRS fails to authenticate when the router is powered on. Here is an example of a failed connection.

Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.11: associated
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: event 1 notification
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: start authentication
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.1X: unauthorizing port
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: sending 1/4 msg of 4-Way Handshake
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: event 3 notification
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.1X: unauthorizing port
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.11: disassociated
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 WPA: event 2 notification
Oct 27 14:59:02 aaa hostapd: wlan0: STA 11:22:33:44:55:66 IEEE 802.1X: unauthorizing port<

The only way I have found to get around this problem is to use an open network.

I do not have this problem with other devices connecting to the same router, which makes me think the problem lies with ReachRS. However, I did not have this problem when I tried ReachRS on another router, so there may be something unique this specific combination.

Any help troubleshooting this problem would be very much appreciated.

Edit

To reproduce this behaviour:

  1. Boot ReachRS and allow it to connect to a known router hotspot.
  2. Cycle power to the router.
  3. When the router reboots ReachRS fails to connect.

Note, the router I am using is a Raspberry Pi running hostapd and dnsmasq.

Well, I don’t see a problem here. Seems like the RPi is not fully initialized by the time Reach tries to connect.

Does this happen if you, say, power the RPi later?

@egor.fedorov,

I don’t think this is a problem with initialization because other devices connect fine to the RPi after it is rebooted. Or at least if this is the problem ReachRS should attempt, more than once, to reconnect.

Once the authentication fails ReachRS never tries to connect again. The fast flashing blue light on ReachRS indicates it is in scanning mode but ReachRS never attempts another connection. It seems the only way to recover comms is to shut down both devices then reboot the RPi and (after a short delay) reboot ReachRS. This is not ideal.

I’m not sure what you mean by:

If you mean rebooting the RPi multiple times, this does not help. ReachRS fails to connect every time.

What I mean is, if you start the RPi first, then wait for it to boot, then start Reach it works OK?

Yes, that’s correct. It works that way around.

Well, I think the answer lies within Reach’s wpa_supplicant log (journalctl -u wpa_supplicant --no-pager).

Overall, my guess is that for some reason the hostapd starts advertising the SSID and all, but rejects Reach’s incoming connection and wpa_supplicant does not attempt another one. I might be wrong, though.

If I am right, the best thing to do is to optimise hostapd startup time.

@egor.fedorov,

I have captured both a successful connection and a failed connection. Here are the steps I took.

  1. Booted the RPi router and waited for it to be ready.
  2. Booted ReachRS and waited for it to connect to the RPi hotspot.
  3. Rebooted the RPi router. When the router came back up ReachRS connected successfully (not typical).
  4. Rebooted the RPi router a second time. Again, when the router came back up ReachRS connected successfully (not typical).
  5. Rebooted the RPi router a third time. This time ReachRS failed to connect (typical).

On the third (failed) attempt the blue LED on ReachRS went from fast flashing to off (for about 10 sec) back to fast flashing. I’m pretty sure the off state does not occur when everything goes well.

From this point on ReachRS will not connect to any known networks and will not create a hotspot. The only way out it to reboot ReachRS.

From what I can tell from the log files it looks like WPA_supplicant crashes and doesn’t recover.

Timing

To make it easier to follow the log files I have listed the time of key events below:

04:26:21 - Boot Reach RS
04:26:59 - Reboot RPi x1 (success)
04:43:11 - Reboot RPi x2 (success)
04:45:27 - Reboot RPi x3 (fail)
04:48:20 - Shutdown ReachRS

The full logs can be downloaded from here.

I’ve listed the main parts below:

root@reach-rover[/]# journalctl -u wpa_supplicant_p2p_event.service --no-pager

– Logs begin at Tue 2017-10-31 04:26:11 UTC, end at Tue 2017-10-31 04:55:11 UTC. –
Oct 31 04:26:21 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:21 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:26:22 reach-rover wpa_cli[328]: Failed to connect to non-global ctrl_ifname: p2p-dev-wlan0 error: No such file or directory
Oct 31 04:26:22 reach-rover systemd[1]: wpa_supplicant_p2p_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:26:22 reach-rover systemd[1]: Unit wpa_supplicant_p2p_event.service entered failed state.
Oct 31 04:26:23 reach-rover systemd[1]: wpa_supplicant_p2p_event.service holdoff time over, scheduling restart.
Oct 31 04:26:23 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:26:23 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:23 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:26:23 reach-rover systemd[1]: wpa_supplicant_p2p_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:26:23 reach-rover systemd[1]: Unit wpa_supplicant_p2p_event.service entered failed state.
Oct 31 04:26:23 reach-rover wpa_cli[332]: Failed to connect to non-global ctrl_ifname: p2p-dev-wlan0 error: No such file or directory
Oct 31 04:26:24 reach-rover systemd[1]: wpa_supplicant_p2p_event.service holdoff time over, scheduling restart.
Oct 31 04:26:24 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:26:24 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:24 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:47:46 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:47:48 reach-rover wpa_cli[357]: wpa_supplicant is terminating - stop monitoring
Oct 31 04:47:48 reach-rover wpa_cli[357]: eloop: could not process SIGINT or SIGTERM in two seconds. Looks like there
Oct 31 04:47:48 reach-rover wpa_cli[357]: is a bug that ends up in a busy loop that prevents clean shutdown.
Oct 31 04:47:48 reach-rover wpa_cli[357]: Killing program forcefully.
Oct 31 04:47:48 reach-rover systemd[1]: wpa_supplicant_p2p_event.service: main process exited, code=exited, status=1/FAILURE
Oct 31 04:47:48 reach-rover systemd[1]: Stopped Daemon to receive the wpa_supplicant event.
Oct 31 04:47:48 reach-rover systemd[1]: Unit wpa_supplicant_p2p_event.service entered failed state.
Oct 31 04:47:48 reach-rover systemd[1]: Stopped Daemon to receive the wpa_supplicant event.
– Reboot –
Oct 31 04:48:14 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:14 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:48:14 reach-rover wpa_cli[328]: Failed to connect to non-global ctrl_ifname: p2p-dev-wlan0 error: No such file or directory
Oct 31 04:48:14 reach-rover systemd[1]: wpa_supplicant_p2p_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:48:14 reach-rover systemd[1]: Unit wpa_supplicant_p2p_event.service entered failed state.
Oct 31 04:48:15 reach-rover systemd[1]: wpa_supplicant_p2p_event.service holdoff time over, scheduling restart.
Oct 31 04:48:15 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:48:15 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:15 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:48:15 reach-rover wpa_cli[334]: Failed to connect to non-global ctrl_ifname: p2p-dev-wlan0 error: No such file or directory
Oct 31 04:48:15 reach-rover systemd[1]: wpa_supplicant_p2p_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:48:15 reach-rover systemd[1]: Unit wpa_supplicant_p2p_event.service entered failed state.
Oct 31 04:48:16 reach-rover systemd[1]: wpa_supplicant_p2p_event.service holdoff time over, scheduling restart.
Oct 31 04:48:16 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:48:16 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:16 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.

root@reach-rover[/]# journalctl -u wpa_supplicant_wlan0_event.service --no-pager

– Logs begin at Tue 2017-10-31 04:26:11 UTC, end at Tue 2017-10-31 04:57:41 UTC. –
Oct 31 04:26:21 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:21 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:26:21 reach-rover wpa_cli[324]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Oct 31 04:26:21 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:26:21 reach-rover systemd[1]: Unit wpa_supplicant_wlan0_event.service entered failed state.
Oct 31 04:26:23 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service holdoff time over, scheduling restart.
Oct 31 04:26:23 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:26:23 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:23 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:26:23 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:26:23 reach-rover systemd[1]: Unit wpa_supplicant_wlan0_event.service entered failed state.
Oct 31 04:26:23 reach-rover wpa_cli[334]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Oct 31 04:26:24 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service holdoff time over, scheduling restart.
Oct 31 04:26:24 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:26:24 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:26:24 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:26:28 reach-rover wpa_cli[356]: event CONNECTED received from wpa_supplicant
Oct 31 04:26:28 reach-rover udhcpc[378]: udhcpc (v1.22.1) started
Oct 31 04:26:28 reach-rover wpa_cli[356]: udhcpc (v1.22.1) started
Oct 31 04:26:28 reach-rover udhcpc[378]: Sending discover…
Oct 31 04:26:28 reach-rover wpa_cli[356]: Sending discover…
Oct 31 04:26:28 reach-rover udhcpc[378]: Sending select for 192.168.50.2…
Oct 31 04:26:28 reach-rover wpa_cli[356]: Sending select for 192.168.50.2…
Oct 31 04:26:28 reach-rover udhcpc[378]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:26:28 reach-rover wpa_cli[356]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:26:28 reach-rover wpa_cli[356]: /etc/udhcpc.d/50default: Adding DNS 192.168.50.1
Oct 31 04:26:59 reach-rover wpa_cli[356]: event DISCONNECTED received from wpa_supplicant
Oct 31 04:26:59 reach-rover wpa_cli[356]: 399 root 2652 S udhcpc -i wlan0 -p /var/run/udhcpc-wlan0.pid -S
Oct 31 04:26:59 reach-rover wpa_cli[356]: rm: cannot remove ‘/var/run/udhcpc-wlan0.pid’: No such file or directory
Oct 31 04:28:05 reach-rover wpa_cli[356]: event CONNECTED received from wpa_supplicant
Oct 31 04:28:05 reach-rover udhcpc[510]: udhcpc (v1.22.1) started
Oct 31 04:28:05 reach-rover wpa_cli[356]: udhcpc (v1.22.1) started
Oct 31 04:28:05 reach-rover udhcpc[510]: Sending discover…
Oct 31 04:28:05 reach-rover wpa_cli[356]: Sending discover…
Oct 31 04:28:05 reach-rover udhcpc[510]: Sending select for 192.168.50.2…
Oct 31 04:28:05 reach-rover wpa_cli[356]: Sending select for 192.168.50.2…
Oct 31 04:28:05 reach-rover udhcpc[510]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:28:05 reach-rover wpa_cli[356]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:28:05 reach-rover wpa_cli[356]: /etc/udhcpc.d/50default: Adding DNS 192.168.50.1
Oct 31 04:43:11 reach-rover wpa_cli[356]: event DISCONNECTED received from wpa_supplicant
Oct 31 04:43:11 reach-rover wpa_cli[356]: 525 root 2652 S udhcpc -i wlan0 -p /var/run/udhcpc-wlan0.pid -S
Oct 31 04:44:12 reach-rover wpa_cli[356]: event CONNECTED received from wpa_supplicant
Oct 31 04:44:12 reach-rover udhcpc[699]: udhcpc (v1.22.1) started
Oct 31 04:44:12 reach-rover wpa_cli[356]: udhcpc (v1.22.1) started
Oct 31 04:44:12 reach-rover udhcpc[699]: Sending discover…
Oct 31 04:44:12 reach-rover wpa_cli[356]: Sending discover…
Oct 31 04:44:12 reach-rover udhcpc[699]: Sending select for 192.168.50.2…
Oct 31 04:44:12 reach-rover wpa_cli[356]: Sending select for 192.168.50.2…
Oct 31 04:44:12 reach-rover udhcpc[699]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:44:12 reach-rover wpa_cli[356]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:44:12 reach-rover wpa_cli[356]: /etc/udhcpc.d/50default: Adding DNS 192.168.50.1
Oct 31 04:45:27 reach-rover wpa_cli[356]: event DISCONNECTED received from wpa_supplicant
Oct 31 04:45:27 reach-rover wpa_cli[356]: 714 root 2652 S udhcpc -i wlan0 -p /var/run/udhcpc-wlan0.pid -S
Oct 31 04:45:27 reach-rover wpa_cli[356]: rm: cannot remove ‘/var/run/udhcpc-wlan0.pid’: No such file or directory
Oct 31 04:47:46 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:47:48 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service: main process exited, code=exited, status=1/FAILURE
Oct 31 04:47:48 reach-rover systemd[1]: Stopped Daemon to receive the wpa_supplicant event.
Oct 31 04:47:48 reach-rover systemd[1]: Unit wpa_supplicant_wlan0_event.service entered failed state.
Oct 31 04:47:48 reach-rover wpa_cli[356]: wpa_supplicant is terminating - stop monitoring
Oct 31 04:47:48 reach-rover wpa_cli[356]: eloop: could not process SIGINT or SIGTERM in two seconds. Looks like there
Oct 31 04:47:48 reach-rover wpa_cli[356]: is a bug that ends up in a busy loop that prevents clean shutdown.
Oct 31 04:47:48 reach-rover wpa_cli[356]: Killing program forcefully.
– Reboot –
Oct 31 04:48:13 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:13 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:48:13 reach-rover wpa_cli[324]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Oct 31 04:48:13 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:48:13 reach-rover systemd[1]: Unit wpa_supplicant_wlan0_event.service entered failed state.
Oct 31 04:48:15 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service holdoff time over, scheduling restart.
Oct 31 04:48:15 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:48:15 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:15 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:48:15 reach-rover wpa_cli[332]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Oct 31 04:48:15 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service: main process exited, code=exited, status=255/n/a
Oct 31 04:48:15 reach-rover systemd[1]: Unit wpa_supplicant_wlan0_event.service entered failed state.
Oct 31 04:48:16 reach-rover systemd[1]: wpa_supplicant_wlan0_event.service holdoff time over, scheduling restart.
Oct 31 04:48:16 reach-rover systemd[1]: Stopping Daemon to receive the wpa_supplicant event…
Oct 31 04:48:16 reach-rover systemd[1]: Starting Daemon to receive the wpa_supplicant event…
Oct 31 04:48:16 reach-rover systemd[1]: Started Daemon to receive the wpa_supplicant event.
Oct 31 04:48:20 reach-rover wpa_cli[358]: event CONNECTED received from wpa_supplicant
Oct 31 04:48:20 reach-rover udhcpc[380]: udhcpc (v1.22.1) started
Oct 31 04:48:20 reach-rover wpa_cli[358]: udhcpc (v1.22.1) started
Oct 31 04:48:20 reach-rover udhcpc[380]: Sending discover…
Oct 31 04:48:20 reach-rover wpa_cli[358]: Sending discover…
Oct 31 04:48:20 reach-rover udhcpc[380]: Sending select for 192.168.50.2…
Oct 31 04:48:20 reach-rover wpa_cli[358]: Sending select for 192.168.50.2…
Oct 31 04:48:20 reach-rover udhcpc[380]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:48:20 reach-rover wpa_cli[358]: Lease of 192.168.50.2 obtained, lease time 43200
Oct 31 04:48:20 reach-rover wpa_cli[358]: /etc/udhcpc.d/50default: Adding DNS 192.168.50.1

root@reach-rover[/]# journalctl -u wpa_supplicant.service --no-pager

– Logs begin at Tue 2017-10-31 04:26:11 UTC, end at Tue 2017-10-31 04:59:12 UTC. –
Oct 31 04:26:21 reach-rover systemd[1]: Starting WPA supplicant service…
Oct 31 04:26:22 reach-rover systemd[1]: Started WPA supplicant service.
Oct 31 04:47:46 reach-rover systemd[1]: Stopping WPA supplicant service…
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: Successfully initialized wpa_supplicant
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: Key negotiation completed with 11:22:33:44:55:66 [PTK=CCMP GTK=CCMP]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-CONNECTED - Connection to 11:22:33:44:55:66 completed (auth) [id=3 id_str=]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=3 ssid=“MySSID” auth_failures=1 duration=10
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-REENABLED id=3 ssid="MySSID"
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: Key negotiation completed with 11:22:33:44:55:66 [PTK=CCMP GTK=CCMP]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-CONNECTED - Connection to 11:22:33:44:55:66 completed (auth) [id=3 id_str=]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: Group rekeying completed with 11:22:33:44:55:66 [GTK=CCMP]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=3 ssid=“MySSID” auth_failures=1 duration=10
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-REENABLED id=3 ssid="MySSID"
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: Key negotiation completed with 11:22:33:44:55:66 [PTK=CCMP GTK=CCMP]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-CONNECTED - Connection to 11:22:33:44:55:66 completed (auth) [id=3 id_str=]
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=11:22:33:44:55:66 status_code=1
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: Retrying assoc: 1
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=3 locally_generated=1
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=11:22:33:44:55:66 status_code=1
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: Retrying assoc: 2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=3 locally_generated=1
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=3 ssid=“MySSID” auth_failures=1 duration=10
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-REENABLED id=3 ssid="MySSID"
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Trying to associate with 11:22:33:44:55:66 (SSID=‘MySSID’ freq=2437 MHz)
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: Associated with 11:22:33:44:55:66
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-DISCONNECTED bssid=11:22:33:44:55:66 reason=2
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=3 ssid=“MySSID” auth_failures=2 duration=20
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING
Oct 31 04:47:46 reach-rover wpa_supplicant[322]: wlan0: CTRL-EVENT-TERMINATING
Oct 31 04:47:48 reach-rover systemd[1]: Stopped WPA supplicant service.
– Reboot –
Oct 31 04:48:13 reach-rover systemd[1]: Starting WPA supplicant service…
Oct 31 04:48:14 reach-rover systemd[1]: Started WPA supplicant service.

Thanks for the thorough reports, will take a look. Reconnecting automatically is problematic because of a fault in a low-level linux driver. That’s practically impossible to fix, but we might still have a different solution cooking.

@egor.fedorov,

ReachRS is running wpa_supplicant version 2.1-devel (2014-02-04). The latest version is 2.6 (2016-10-02). Is there any way to upgrade to see if this solves the problem?

The problem is lower than the wpa_supplicant, in the kernel module bcm-43xxx. It’s a one-commit Intel’s repo with tons of code.

You can try to compile wpa_supplicant from sources on Reach directly, but I haven’t tried this.

This topic was automatically closed after 100 days. New replies are no longer allowed.