Alot of Failed connection attempts.

Hi,

 

In my setup i run a Sophos UTM v9.413-3 and i have two AP's connected to it, one AP55C and one AP30. This was working just fine for a long time, but recently i noticed my wifi connection in was getting worse, so i looked at the logging and i noticed that since december 2016 i started to get alot of failed connection attempts.

this is how it daily looks now.

This is the yearly one, where you can see it started out of the blue in december.

I do see these log messages, but im not sure if they have anything to do with it.

2017:05:09-20:23:15 ding awed[4969]: [MASTER] start processing configuration change
2017:05:09-20:23:16 ding awed[4969]: [MASTER] end processing configuration change
2017:05:09-20:27:54 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f WPA: group key handshake completed (RSN)
2017:05:09-20:28:02 A4002FE206C4AE1 hostapd: wlan9: STA f4:5c:89:87:36:e1 WPA: group key handshake completed (RSN)
2017:05:09-20:28:05 A4002FE206C4AE1 awelogger[14396]: id="4105" severity="info" sys="System" sub="WiFi" name="STA WPA failure" ssid="BreakingBad" ssid_id="WLAN1.1" bssid="00:1a:8c:8d:37:54" sta="10:41:7f:56:4b:0a" reason_code="2"
2017:05:09-20:28:05 A4002FE206C4AE1 awelogger[14396]: id="4102" severity="info" sys="System" sub="WiFi" name="STA disconnected" ssid="BreakingBad" ssid_id="WLAN1.1" bssid="00:1a:8c:8d:37:54" sta="10:41:7f:56:4b:0a"
2017:05:09-20:28:10 A4002FE206C4AE1 hostapd: wlan9: STA 10:41:7f:56:4b:0a IEEE 802.11: deauthenticated due to local deauth request
2017:05:09-20:28:32 A4002FE206C4AE1 hostapd: wlan9: STA 10:41:7f:56:4b:0a IEEE 802.11: authenticated
2017:05:09-20:28:32 A4002FE206C4AE1 hostapd: wlan9: STA 10:41:7f:56:4b:0a IEEE 802.11: associated (aid 1)
2017:05:09-20:28:32 A4002FE206C4AE1 hostapd: wlan9: STA 10:41:7f:56:4b:0a WPA: pairwise key handshake completed (RSN)
2017:05:09-20:28:32 A4002FE206C4AE1 awelogger[14396]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="BreakingBad" ssid_id="WLAN1.1" bssid="00:1a:8c:8d:37:54" sta="10:41:7f:56:4b:0a" status_code="0"
2017:05:09-20:28:32 A4002FE206C4AE1 awelogger[14396]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="BreakingBad" ssid_id="WLAN1.1" bssid="00:1a:8c:8d:37:54" sta="10:41:7f:56:4b:0a" status_code="0"
2017:05:09-20:28:32 A4002FE206C4AE1 awelogger[14396]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="BreakingBad" ssid_id="WLAN1.1" bssid="00:1a:8c:8d:37:54" sta="10:41:7f:56:4b:0a"
 
Anyone able to help me out troubleshoot this?
 
Thanks.
  • Are all of the failures with the same SSID or AP?

    Cheers - Bob

  • In reply to BAlfson:

    This is happening on all SSID's and on both AP's.

    Ill put in some config screenshots, i did play with them a bit to see if it would help.

     

    Also seen this in the logs:

    2017:05:12-13:02:02 A4002FE206C4AE1 awelogger[2084]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="Breaking-Gast" ssid_id="WLAN0.0" bssid="00:1a:8c:8d:37:5b" sta="00:40:9d:8e:df:1f" status_code="0"
    2017:05:12-13:02:02 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f IEEE 802.11: authenticated
    2017:05:12-13:02:02 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f IEEE 802.11: associated (aid 1)
    2017:05:12-13:02:02 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f WPA: pairwise key handshake completed (RSN)
    2017:05:12-13:02:02 A4002FE206C4AE1 awelogger[2084]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="Breaking-Gast" ssid_id="WLAN0.0" bssid="00:1a:8c:8d:37:5b" sta="00:40:9d:8e:df:1f" status_code="0"
    2017:05:12-13:02:19 A4002FE206C4AE1 hostapd: wlan9: STA f4:5c:89:87:36:e1 IEEE 802.11: disassociated due to inactivity
    2017:05:12-13:02:20 A4002FE206C4AE1 hostapd: wlan9: STA f4:5c:89:87:36:e1 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.200000] ------------[ cut here ]------------
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.200000] WARNING: CPU: 0 PID: 0 at /mnt/bamboo-ebs/bamboo/bamboo-agent-home/xml-data/build-dir/WIFI-BAFU-AP55C/firmware-wifi/build_dir/target-mips_34kc_uClibc-0.9.33.2/linux-ar71xx_generic/compat-wireless-2015-06-03/net/mac80211/tx.c:3212 ieee80211_csa_update_counter+0x8c/0xbe4 [mac80211]()
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.230000] Modules linked in: ath9k ath9k_common ath9k_hw ath10k_pci ath10k_core ath iptable_nat nf_nat_ipv4 nf_conntrack_ipv4 iptable_mangle iptable_filter ipt_REJECT ipt_MASQUERADE ip_tables xt_time xt_tcpudp xt_nat xt_multiport xt_mark xt_mac xt_limit xt_id xt_comment xt_TCPMSS xt_REDIRECT xt_LOG x_tables nf_reject_ipv4 nf_nat_masquerade_ipv4 nf_nat nf_log_ipv4 nf_log_common nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack mac80211 cfg80211 compat arc4 cryp
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] CPU: 0 PID: 0 Comm: swapper Tainted: P 3.18.11 #3
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] Stack : 00000000 00000000 00000000 00000000 808d4172 0000003f 00000000 85e224e8
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] 00000001 8073e440 802df088 8032b223 00000000 808d33b4 8032b558 8073e440
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] 00000000 85969830 8073c038 800a3114 00000003 80080cd0 00000c8c 8073e440
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] 802e2e30 80323bec 00000000 00000000 00000000 00000000 00000000 00000000
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.280000] ...
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.320000] Call Trace:
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.320000] [<80070bfc>] show_stack+0x48/0x70
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.330000] [<80080e4c>] warn_slowpath_common+0x84/0xb4
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.330000] [<80080f04>] warn_slowpath_null+0x18/0x24
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.340000] [<85e224e8>] ieee80211_csa_update_counter+0x8c/0xbe4 [mac80211]
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.340000] [<85e25ac0>] ieee80211_csa_is_complete+0x384/0x780 [mac80211]
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.350000]
    2017:05:12-13:06:20 A4002FE206C4AE1 kernel: [13025.350000] ---[ end trace 8defd7f5b7a5a5b4 ]---
    2017:05:12-13:06:21 A4002FE206C4AE1 hostapd: wlan2: IEEE 802.11 driver had channel switch: freq=2472, ht=1, offset=0, width=1 (20 MHz), cf1=2472, cf2=0
    2017:05:12-13:06:21 A4002FE206C4AE1 hostapd: wlan1: IEEE 802.11 driver had channel switch: freq=2472, ht=1, offset=0, width=1 (20 MHz), cf1=2472, cf2=0
    2017:05:12-13:06:21 A4002FE206C4AE1 hostapd: wlan0: IEEE 802.11 driver had channel switch: freq=2472, ht=1, offset=0, width=1 (20 MHz), cf1=2472, cf2=0
    2017:05:12-13:06:24 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f IEEE 802.11: authenticated
    2017:05:12-13:06:24 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f IEEE 802.11: associated (aid 1)
    2017:05:12-13:06:24 A4002FE206C4AE1 hostapd: wlan0: STA 00:40:9d:8e:df:1f WPA: pairwise key handshake completed (RSN)
    2017:05:12-13:06:24 A4002FE206C4AE1 awelogger[2084]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="Breaking-Gast" ssid_id="WLAN0.0" bssid="00:1a:8c:8d:37:5b" sta="00:40:9d:8e:df:1f" status_code="0"
    2017:05:12-13:06:24 A4002FE206C4AE1 awelogger[2084]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="Breaking-Gast" ssid_id="WLAN0.0" bssid="00:1a:8c:8d:37:5b" sta="00:40:9d:8e:df:1f" status_code="0"
    2017:05:12-13:06:37 ding awed[5265]: [MASTER] updating confd object for AP A4002FE206C4AE1 with new channels (6,36 -> 13,36)
    2017:05:12-13:06:37 ding awed[5265]: [MASTER] start processing configuration change
    2017:05:12-13:06:38 ding awed[5265]: [MASTER] end processing configuration change

  • In reply to rizzah:

    What happens if you change the Wireless Network definitions from 'AES' to 'TKIP&AES'?  Definitely time for Sophos Support to take a look at this - it feels like a bug to me.

    Cheers - Bob

  • In reply to BAlfson:

    I changed that setting now, lets see how today goes.

    Thanks for your help.

  • In reply to rizzah:

    the setting change did not help.

  • In reply to rizzah:

    I have similar problems.

    A customer having trouble with a Sophos SG 125 (UTM 9.413-44) and a AP15.
    We have the same device configuration 2 times at the same customer, once in his business place and one at his private place.
    He have multiple devices from different vendors - iPhone, Andoird and Windows Tablet/Notebooks.

    He got trouble having a steady wireless connection and the connection just breaks down sometime multiple times a day.
    The log says:


    2017:05:16-13:32:51 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 WPA: pairwise key handshake completed (RSN)
    2017:05:16-13:32:52 A400391A137218E awelogger[2224]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="c8:1e:e7:f3:f8:d3"
    2017:05:16-13:34:25 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 IEEE 802.11: disassociated
    2017:05:16-13:34:25 A400391A137218E awelogger[2224]: id="4102" severity="info" sys="System" sub="WiFi" name="STA disconnected" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="c8:1e:e7:f3:f8:d3"
    2017:05:16-13:34:26 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
    2017:05:16-13:35:32 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 IEEE 802.11: authenticated
    2017:05:16-13:35:32 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 IEEE 802.11: associated (aid 2)
    2017:05:16-13:35:32 A400391A137218E awelogger[2224]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="c8:1e:e7:f3:f8:d3" status_code="0"
    2017:05:16-13:35:32 A400391A137218E awelogger[2224]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="c8:1e:e7:f3:f8:d3" status_code="0"
    2017:05:16-13:35:32 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 WPA: pairwise key handshake completed (RSN)
    2017:05:16-13:35:32 A400391A137218E awelogger[2224]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="c8:1e:e7:f3:f8:d3"
    2017:05:16-13:37:09 A400391A137218E hostapd: wlan1: STA ec:1f:72:99:3e:e2 IEEE 802.11: authenticated
    2017:05:16-13:37:09 A400391A137218E hostapd: wlan1: STA ec:1f:72:99:3e:e2 IEEE 802.11: associated (aid 3)
    2017:05:16-13:37:09 A400391A137218E awelogger[2224]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="ec:1f:72:99:3e:e2" status_code="0"
    2017:05:16-13:37:09 A400391A137218E awelogger[2224]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="ec:1f:72:99:3e:e2" status_code="0"
    2017:05:16-13:37:09 A400391A137218E hostapd: wlan1: STA ec:1f:72:99:3e:e2 WPA: pairwise key handshake completed (RSN)
    2017:05:16-13:37:09 A400391A137218E awelogger[2224]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="WLAN-HOME" ssid_id="WLAN1.0" bssid="00:1a:8c:99:bc:37" sta="ec:1f:72:99:3e:e2"
    2017:05:16-13:42:12 A400391A137218E hostapd: wlan1: STA 80:ea:96:db:52:14 WPA: group key handshake completed (RSN)
    2017:05:16-13:42:13 A400391A137218E hostapd: wlan1: STA ec:1f:72:99:3e:e2 WPA: group key handshake completed (RSN)
    2017:05:16-13:42:14 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 WPA: group key handshake completed (RSN)
    2017:05:16-13:52:12 A400391A137218E hostapd: wlan1: STA ec:1f:72:99:3e:e2 WPA: group key handshake completed (RSN)
    2017:05:16-13:52:12 A400391A137218E hostapd: wlan1: STA 80:ea:96:db:52:14 WPA: group key handshake completed (RSN)
    2017:05:16-13:52:13 A400391A137218E hostapd: wlan1: STA c8:1e:e7:f3:f8:d3 WPA: group key handshake completed (RSN)
    2017:05:16-13:58:43 A400391A137218E hostapd: wlan1: STA f4:09:d8:32:cc:b8 IEEE 802.11: authenticated
    2017:05:16-13:58:43 A400391A137218E hostapd: wlan1: STA f4:09:d8:32:cc:b8 IEEE 802.11: associated (aid 4)
    2017:05:16-13:58:43 A400391A137218E hostapd: wlan1: STA f4:09:d8:32:cc:b8 WPA: pairwise key handshake completed (RSN)

  • In reply to rizzah:

    I tried reinstalling the VM with a fresh version of UTm v9.5 and restored the config file. This did not help either.

  • In reply to rizzah:

    I did a factory reset and installed a fresh image with bootable CD on the device.

    Then i did a full reconfigure of the device  - without recover the old config.

    Problem still persists.

  • In reply to Michael Schneider:

     

    I read on some posts that changing the encryption mode and/or the algorithm used would at least make things a bit more stable. 

    I have noticed myself that the errors (the disconnecting) of clients are not solved, i still see disconnects during the day, but it does seem the timeouts are less big now. Of course lowering the security methods is not to be advised, but could help meanwhile this problem persists.

    I have tested with a friend using AirPcap hardware to see if we could find anything in the wireless network which could result in the problem of disconnected clients, we have found nothing of this sort. So my personal conclusion is that there is a bug in the software of the UTM.

    I have not tested this with XG, have you?

     

    Regards,

  • In reply to rizzah:

    No, i have not tested it with XG. 

    But the problem still is there.

  • In reply to Michael Schneider:

    I pulled the power cable from my AP30 (this device i had added later on). Until now, i have not seen any failed connection attempts. -crossing fingers-

    My guess now would be that the AP30 has more limitations compared to the AP55C. For example the handling of WPA2 or the encryption algorithm used which would conflict between the two access points. 

    When i have seen no more failed attempts for 24 hours, i will try to turn on the AP30 again and limit its transmit power to 10% for example, but otherwise ill see if i can get another AP55C.

    Hope this info helps you somewhat, would be nice if  could confirm or deny the above.

  • In reply to rizzah:

    I connected both AP's to Sphos XG firewall. Seems its running way better now. 

    Guess something happend around december which caused problems with UTM...

  • In reply to rizzah:

    This is not an official channel to interact with Sophos Support.

    Cheers - Bob

  • In reply to BAlfson:

    BAlfson

    This is not an official channel to interact with Sophos Support.

    Cheers - Bob

     

    Yeah, i think we know its not an official channel.
    But for now the support could not help me with this sporadically error, and perhaps the community can.
     
    @rizzah - I can't switch to XG for now because there are features missing, which i need.
  • Hi everybody,

    we're experiencing the same issue at a customers site with UTM 9.413 and AP55c.

    Some advice?

     

    regards

    Tobi