[8.980][OPEN] wireless client disconnected

Hi All

I am seeing clients being disconnected with the new firmware. Something important to not is that I am having 2G RAM instead of 4 on this version as my pm is suddenly not recognizing the 2 DIM (I am also using disk option for web database)

RAM/CPU stats and relevant wireless log send via email. The disconnect were: 2012:06:26-22:16:17
2012:06:21-20:36:23

Thanks

0 wingman over 12 years ago

ok I killed the process and set the debug. It seems to work now as I am getting messages like :

2012:06:28-10:55:11 **** awed[6031]: [AP10 A40000D709AC807] prepare_response ASG2DEV_STATUSACK, json: {"datetime":"2012-06-28 10:55:11"}

I will post once I have more info about a disconnect
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 xenon2008 over 12 years ago

I have the same issue in 8.305 - specifically when i connect with my iPhone

So i connected my AP30 to the UTM 9 (latest beta Version) and the AP30 get a new firmware (3024).

After the UTM was finished with the fw update i connected the AP 30 back to my ASG 8.305, but the error persists.
The whole thing is quite annoying...

sry my english isnt good [;)]

xenon
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 treskaan over 12 years ago

Hi,
please go more into detail regarding your setup. How many SSIDs do you stream? What kind of Client traffic did you setup. Which encryption? Are there other APs in use which work well? There must be a way for me to debug this here!!!
Thanks,
Andreas
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 xenon2008 over 12 years ago

Hi,

I have 2 SSIDs

1x Guest - Seperate Zone With WPA2 AES encryption
1x Wlan - Bridged in AP LAN also with WPA2 AES encryption

Acces Point is a AP 30 and there are no other APs in the LAN.
ASG Version 8.305
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 wingman over 12 years ago

Relevant log from another disconnect with debug on

2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 RADIUS: starting accounting session 4FEC004C-00000007
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 IEEE 802.1X: authenticated - EAP type: 25 ((null))
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: Added PMKSA cache entry (IEEE 802.1X)
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: sending 1/4 msg of 4-Way Handshake
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: received EAPOL-Key frame (2/4 Pairwise)
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: sending 3/4 msg of 4-Way Handshake
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: received EAPOL-Key frame (4/4 Pairwise)
2012:06:28-10:44:00 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: pairwise key handshake completed (RSN)
2012:06:28-10:47:18 ap-10 hostapd: wlan1: WPA rekeying GTK
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 1/2 msg of Group Key Handshake
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: sending 1/2 msg of Group Key Handshake
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: received EAPOL-Key frame (2/2 Group)
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 00:1d:e0:72:09:a9 WPA: group key handshake completed (RSN)
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: received EAPOL-Key frame (2/2 Group)
2012:06:28-10:47:18 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: group key handshake completed (RSN)
2012:06:28-10:53:21 ***** awed[4157]: [MASTER] SIGTERM received, sending SIGTERM to siblings, exiting
2012:06:28-10:53:21 ***** awed[20694]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.
2012:06:28-10:53:28 ***** awed[5923]: [MASTER] awed_ng starting
2012:06:28-10:53:28 ***** awed[5923]: [MASTER] access point firmware available: AP10:3024 AP50:3024 AP5:1 AP30:3024
2012:06:28-10:53:30 ***** awed[5923]: [MASTER] SSID: StoufoGuest is enabled and next time it is checked for being disabled is 1340924340.
2012:06:28-10:53:55 ap-10 sysinit: alrm_handler(): timeout, reason 1
2012:06:28-10:53:55 ap-10 init: starting pid 19028, tty '': '/etc/init.d/rcS K shutdown'
2012:06:28-10:53:55 ap-10 sysinit: interface not found.
2012:06:28-10:54:24 ***** awed[5923]: [MASTER] new connection from 192.168.2.1:50035
2012:06:28-10:54:24 ***** awed[6031]: [AP10 A40000D709AC807] (Re-)loaded identity and/or configuration
2012:06:28-10:54:24 ***** awed[6031]: [AP10 A40000D709AC807] DEV2ASG_REGISTEREDCONTACT
2012:06:28-10:54:24 ***** awed[6031]: [AP10 A40000D709AC807] decrypt_and_verify, json: { "id": "A40000D709AC807", "type": "AP10", "lan_mac": "00:1a:8c:06:13:58", "version": 3024, "allowed_channels": "1,2,3,4,5,6,7,8,9,10,11,", "max_ssids": "8", "tx_power_control": "1", "bridge_to_lan": "1", "bridge_to_vlan": "1", "separate_zone": "1" }      
2012:06:28-10:54:24 ***** awed[6031]: [AP10 A40000D709AC807] setting red peer host (tunnel_id: 800 peer: 192.168.2.1)
2012:06:28-10:54:24 ***** awed[6031]: [AP10 A40000D709AC807] prepare_response ASG2DEV_HERESYOURCONFIG, json: {"version":"3024","config":{"WLAN2.0":{"psk":"","disabled":"0","vlantag":"10","radio_id":"0","crypto_alg":"tkip+aes","ap_bridgemode":"vlan","network_mode":"mixed_bgn","radius_server":"192.168.2.100","wep128":"","wep_authentication":"open","hide_ssid":"1","radius_psk":"******","radius_service":"414","client_isolation":"0","encryption_mode":"wpa2_enterprise","ssid":"****"},"WLAN0.0":{"psk":"","disabled":"0","vlantag":20,"radio_id":"0","crypto_alg":"none","ap_bridgemode":"vlan","network_mode":"mixed_bgn","wep128":"","wep_authentication":"open","hide_ssid":0,"client_isolation":1,"encryption_mode":"none","ssid":"*****"},"GLOBAL":{"country_code":"gb","ap_vlantag":10,"tunnel_peer":"192.168.2.100","tunnel_id":"800","vlantagging":1,"ap_debuglevel":0},"RADIO0":{"freq_band":"g","channel":0,"txpower_pct":100,"radio_id":"0"}},"magic_ip":"1.2.3.4"}
2012:06:28-10:54:25 ***** awed[6031]: [AP10 A40000D709AC807] DEV2ASG_STATUSUPDATE
2012:06:28-10:54:25 ***** awed[6031]: [AP10 A40000D709AC807] decrypt_and_verify, json: { "associated_clients": [ ] }   
2012:06:28-10:54:25 ***** awed[6031]: [AP10 A40000D709AC807] prepare_response ASG2DEV_STATUSACK, json: {"datetime":"2012-06-28 10:54:25"}

Also this doesn't seem normal to me

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 RADIUS: starting accounting session 4FF387D3-0000003F
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 IEEE 802.1X: authenticated - EAP type: 21 ((null))
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: Added PMKSA cache entry (IEEE 802.1X)
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 1/4 msg of 4-Way Handshake
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: received EAPOL-Key frame (2/4 Pairwise)
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout
2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake
2012:07:06-02:01:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout
2012:07:06-02:01:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake
2012:07:06-02:01:33 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout
2012:07:06-02:01:33 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake
2012:07:06-02:01:34 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout
2012:07:06-02:01:34 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: PTKINITNEGOTIATING: Retry limit 4 reached
2012:07:06-02:01:34 ap-10 awelogger[808]: id="4105" severity="info" sys="System" sub="WiFi" name="STA WPA failure" ssid="Stoufospito" ssid_id="WLAN2.0" bssid="00:1a:8c:06:13:51" sta="68:a8:6d:cd:2e:07" reason_code="2"

I can send the complete log via email if needed

0 hschaa over 12 years ago in reply to xenon2008

I have the same issue in 8.305 - specifically when i connect with my iPhone

So i connected my AP30 to the UTM 9 (latest beta Version) and the AP30 get a new firmware (3024).

After the UTM was finished with the fw update i connected the AP 30 back to my ASG 8.305, but the error persists.
The whole thing is quite annoying...

Because the AP will be flashed back to the 8.305 firmware once you connect it to the 8.305 again.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 hschaa over 12 years ago in reply to wingman

Relevant log from another disconnect with debug on

Also this doesn't seem normal to me

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 RADIUS: starting accounting session 4FF387D3-0000003F

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 IEEE 802.1X: authenticated - EAP type: 21 ((null))

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: Added PMKSA cache entry (IEEE 802.1X)

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 1/4 msg of 4-Way Handshake

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: received EAPOL-Key frame (2/4 Pairwise)

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout

2012:07:06-02:01:31 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake

2012:07:06-02:01:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout

2012:07:06-02:01:32 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake

2012:07:06-02:01:33 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout

2012:07:06-02:01:33 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: sending 3/4 msg of 4-Way Handshake

2012:07:06-02:01:34 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: EAPOL-Key timeout

2012:07:06-02:01:34 ap-10 hostapd: wlan1: STA 68:a8:6d:cd:2e:07 WPA: PTKINITNEGOTIATING: Retry limit 4 reached

2012:07:06-02:01:34 ap-10 awelogger[808]: id="4105" severity="info" sys="System" sub="WiFi" name="STA WPA failure" ssid="Stoufospito" ssid_id="WLAN2.0" bssid="00:1a:8c:06:13:51" sta="68:a8:6d:cd:2e:07" reason_code="2"

I can send the complete log via email if needed

What kind of client is 68:a8:6d:cd:2e:07?
Thanks.

0 wingman over 12 years ago

It's my iphone 4S [:)] (running IOS 5.1.1)
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 etaube over 12 years ago
Hi wingman,

in your first log in this thread we noticed, that the AP disconnected:

2012:06:26-22:16:17 stuffman awed[5533]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.

did this happen this time too?
If so could you post the debug output related to that or even better the whole log file for the day?

regards,
Emanuel
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 wingman over 12 years ago
the only info on the log :

I am sure I didn't physically disconnect the AP. I've attached the whole log of the day

THis also happened on the 9th

/var/log/wireless/2012/07/wireless-2012-07-09.log.gz:2012:07:09-20:28:32 **** awed[6020]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.

I have attached the relevant log as well
wireless-2012-06-26.zip
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel