This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

AP 10 disconnecting

Hi All

I am getting quite few disconnects over the past month and this is relevant log

2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 1/2 msg of Group Key Handshake
2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 70:56:81:c2:3a:19 WPA: sending 1/2 msg of Group Key Handshake
2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 70:56:81:c2:3a:19 WPA: received EAPOL-Key frame (2/2 Group)
2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 70:56:81:c2:3a:19 WPA: group key handshake completed (RSN)
2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: received EAPOL-Key frame (2/2 Group)
2012:09:03-18:47:52 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: group key handshake completed (RSN)
2012:09:03-18:49:35 ap-10 sysinit: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1alrm_handler(): timeout, reason 1
2012:09:03-18:49:35 ap-10 init: starting pid 20657, tty '': '/etc/init.d/rcS K shutdown'
2012:09:03-18:49:35 ap-10 sysinit: interface not found.
2012:09:03-18:50:02 * awed[6916]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.
2012:09:03-18:50:04 * awed[4157]: [MASTER] new connection from 192.168.2.1:45989
2012:09:03-18:50:06 * awed[6568]: [AP10 A40000D709AC807] (Re-)loaded identity and/or configuration
2012:09:03-18:50:08 ap-10 sysinit: Channel 2 busy time 17/230ms, 7%


and 

2012:08:29-06:32:42 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 IEEE 802.1X: authenticated - EAP type: 21 ((null))
2012:08:29-06:32:42 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: Added PMKSA cache entry (IEEE 802.1X)
2012:08:29-06:41:32 ap-10 hostapd: wlan1: WPA rekeying GTK
2012:08:29-06:41:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 1/2 msg of Group Key Handshake
2012:08:29-06:41:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: received EAPOL-Key frame (2/2 Group)
2012:08:29-06:41:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: group key handshake completed (RSN)
2012:08:29-06:47:38 ap-10 sysinit: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1alrm_handler(): timeout, reason 1
2012:08:29-06:47:38 ap-10 sysinit: interface not found.
2012:08:29-06:48:06 * awed[15443]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.
2012:08:29-06:48:09 * awed[4146]: [MASTER] new connection from 192.168.2.1:45989
2012:08:29-06:48:10 * awed[26308]: [AP10 A40000D709AC807] (Re-)loaded identity and/or configuration
2012:08:29-06:48:11 ap-10 sysinit: Channel 2 busy time 33/242ms, 13%



MAC 68:a8:6d:cd:2e:07 is : iphone 4S IOS 5.1.1

Same issue as here: https://community.sophos.com/products/unified-threat-management/astaroorg/f/76/t/64639 Is there a solution on this one?

Thanks


This thread was automatically locked due to age.
Parents
  • Helumt did you receive the wireshark log? Do you need more captures from me?
  • Yep, got it. Thanks. I did only a quick analysis but this is what I've found out:

    Frame no 115964 + 115965 + 115978 + 115979 is the last successful handshake with the AP before a disconnect.

    15 seconds later (frame 116041 + 116042) the AP again sends a status update to the ASG. However, the ASG doesn't answer immediately but with a delay of nearly 40 seconds (frame 116110 and later). In the meantime the AP already timed out (frame 116090) because it assumes the ASG is gone.

    Hence, my assumption is that your ASG is under quite heavy load and thus awed (the wireless control daemon) doesn't receive enough CPU time to finish its work in a timely manner [:(]

    Could you please check the CPU usage graph in the reporting section to see whether your ASG is under high load from time to time? Of course you can also just run a script that writes the current CPU (and maybe IO) load to a file such that we can identify if CPU or IO spikes are the culprit for the AP disconnects.

    Thanks,
    Helmut
Reply
  • Yep, got it. Thanks. I did only a quick analysis but this is what I've found out:

    Frame no 115964 + 115965 + 115978 + 115979 is the last successful handshake with the AP before a disconnect.

    15 seconds later (frame 116041 + 116042) the AP again sends a status update to the ASG. However, the ASG doesn't answer immediately but with a delay of nearly 40 seconds (frame 116110 and later). In the meantime the AP already timed out (frame 116090) because it assumes the ASG is gone.

    Hence, my assumption is that your ASG is under quite heavy load and thus awed (the wireless control daemon) doesn't receive enough CPU time to finish its work in a timely manner [:(]

    Could you please check the CPU usage graph in the reporting section to see whether your ASG is under high load from time to time? Of course you can also just run a script that writes the current CPU (and maybe IO) load to a file such that we can identify if CPU or IO spikes are the culprit for the AP disconnects.

    Thanks,
    Helmut
Children
No Data