Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 18 replies
  • Subscribers 1 subscriber
  • Views 11339 views
  • Users 0 members are here
Options
Suggested
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

wingman
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
  • 0
    Hi Helmut

    This issue continues on 9.004 but the error messages are different

    012:11:14-15:06:47 ap-10 hostapd: wlan0: STA 00:1c:b3:52:b7:58 RADIUS: starting accounting session 50941695-00000D64
    2012:11:14-15:07:20 ap-10 hostapd: wlan0: STA 00:1c:b3:52:b7:58 IEEE 802.11: deauthenticated
    2012:11:14-15:07:30 ap-10 kernel: [1023266.280000] phy0 -> rt2800pci_txdone: Warning - No matching frame found for TX status on queue 2, dropping
    2012:11:14-15:07:30 ap-10 kernel: [1023266.290000] phy0 -> rt2800pci_txdone: Warning - No matching frame found for TX status on queue 2, dropping
    2012:11:14-15:07:30 ap-10 kernel: [1023266.290000] phy0 -> rt2800pci_txdone: Warning - No matching frame found for TX status on queue 2, dropping
    2012:11:14-15:07:47 ap-10 aweclient: qid	flags		count	limit	length	index	dma done	done
    2012:11:14-15:07:47 ap-10 aweclient: 14	0x00000001	66060453	128	0	37	37		37
    2012:11:14-15:07:47 ap-10 aweclient: 0	0x00000001	502293	16	0	5	0		5
    2012:11:14-15:07:47 ap-10 aweclient: 1	0x00000001	171	16	0	11	0		11
    2012:11:14-15:07:47 ap-10 aweclient: 2	0x00000003	11911468	16	15	11	0		12
    2012:11:14-15:07:47 ap-10 aweclient: 3	0x00000001	12669	16	0	13	0		13
    2012:11:14-15:07:47 ap-10 aweclient: 16	0x00000001	0	8	0	0	0		0
    2012:11:14-15:07:47 ap-10 aweclient: Queue 2 is stuck, forcing reboot!
    2012:11:14-15:07:47 ap-10 init: starting pid 12830, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:14-15:07:47 ap-10 sysinit: interface not found.
    2012:11:14-15:08:15 ******  awed[4139]: [MASTER] new connection from 192.168.2.1:57382
    2012:11:14-15:08:16 ******  awed[20474]: [AP10 A40000D709AC807] (Re-)loaded identity and/or configuration
    2012:11:14-15:08:17 ap-10 sysinit: Channel 2 busy time 28/241ms, 11%
    2012:11:14-15:08:17 ap-10 sysinit: Channel 3 busy time 3/230ms, 1%
    2012:11:14-15:08:18 ap-10 sysinit: Channel 4 busy time 7/230ms, 3%
    2012:11:14-15:08:18 ap-10 sysinit: Channel 5 busy time 31/230ms, 13%
    2012:11:14-15:08:18 ******  awed[5983]: [AP10 A40000D709AC807] disconnected. Close socket and kill process.
    2012:11:14-15:08:18 ap-10 sysinit: Channel 6 busy time 64/230ms, 27%
    2012:11:14-15:08:19 ap-10 sysinit: Channel 7 busy time 23/230ms, 10%


    Thanks
  • 0 in reply to wingman
    Hallo,

    I think we have a similar issue.
    After an update to 9.0004 all AccessPoints are inactive (AP10 and AP30).

    Deleting, Factory Reset and firmware flashing of the AccessPoints does not fix the problem.

    After a retsart of the firewall all AccessPoints are getting up again - but only for about 15 minutes.

    In the Log we see the following:
    2012:11:22-02:13:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-02:23:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-02:33:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-02:43:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-02:53:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-03:03:00 10.10.20.102 hostapd: wlan0: WPA rekeying GTK
    2012:11:22-03:11:09 10.10.20.102 sysinit: alrm_handler(): timeout, reason 1
    2012:11:22-03:11:09 10.10.20.102 init: starting pid 2396, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:22-03:11:09 10.10.20.102 sysinit: interface not found.
    2012:11:22-03:11:24 ghp-gw-01 awed[18184]: [AP30 A4000BF1C3CAD27] disconnected. Close socket and kill process.


    Therefore we restored our Firewall (VM) to the Firmware 9.0003.
    But now there is the same issue. AccessPOints are online after a restart for just a short time. The Log is the same as above.

    Have you any solution for us?

    best regards Marco
  • 0 in reply to marco116
    Hallo,

    I think we have a similar issue.
    After an update to 9.0004 all AccessPoints are inactive (AP10 and AP30).

    Deleting, Factory Reset and firmware flashing of the AccessPoints does not fix the problem.

    After a retsart of the firewall all AccessPoints are getting up again - but only for about 15 minutes.

    In the Log we see the following:


    Therefore we restored our Firewall (VM) to the Firmware 9.0003.
    But now there is the same issue. AccessPOints are online after a restart for just a short time. The Log is the same as above.

    Have you any solution for us?

    best regards Marco


    Could you start the awed in debug mode and attach the logfile again? Maybe we will get more information and the developers might be able to resolve our issue if it is bug related

    /var/mdw/scripts/awed stop 
    awed_ng.plx --debug --nodaemon 
  • 0 in reply to wingman
    Hallo,

    Thank you for your advise. 
    We activated the debug Mode.

    Then all AccessPoints went up again.
    They are still up after a few hours.

    Therfore i tried to quit the debug mode and restarted the awed service.
    AccessPoints went down again.

    2012:11:23-09:31:40 ghp-gw-01 awed[19263]: [MASTER] awed_ng starting
    2012:11:23-09:31:40 ghp-gw-01 awed[19263]: [MASTER] access point firmware available: AP10:3024 AP50:3024 AP5:1 AP30:3024
    2012:11:23-09:31:47 10.10.20.116 sysinit: alrm_handler(): timeout, reason 1
    2012:11:23-09:31:47 10.10.20.116 init: starting pid 5937, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:23-09:31:47 10.10.20.116 sysinit: interface not found.
    2012:11:23-09:31:52 10.20.0.114 sysinit: alrm_handler(): timeout, reason 1
    2012:11:23-09:31:52 10.20.0.114 init: starting pid 5607, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:23-09:31:53 10.10.20.102 sysinit: alrm_handler(): timeout, reason 1
    2012:11:23-09:31:53 10.10.20.102 init: starting pid 5347, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:23-09:31:52 10.20.0.114 sysinit: interface not found.
    2012:11:23-09:31:53 10.10.20.102 sysinit: interface not found.
    2012:11:23-09:31:53 10.10.20.105 sysinit: alrm_handler(): timeout, reason 1
    2012:11:23-09:31:53 10.10.20.105 init: starting pid 5459, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:23-09:31:53 10.10.20.105 sysinit: interface not found.
    2012:11:23-09:31:56 10.10.20.110 sysinit: alrm_handler(): timeout, reason 1
    2012:11:23-09:31:56 10.10.20.110 init: starting pid 5730, tty '': '/etc/init.d/rcS K shutdown'
    2012:11:23-09:31:56 10.10.20.110 sysinit: interface not found.
    2012:11:23-09:32:16 ghp-gw-01 awed[19263]: [MASTER] new connection from 10.10.20.105:55286
    2012:11:23-09:32:16 ghp-gw-01 awed[19425]: [AP10 A400091DF0BC054] (Re-)loaded identity and/or configuration
    2012:01:01-00:00:18 10.10.20.105 kernel: [ 18.290000] RED: red4_encap_rcv: tunnel 802 not found
    2012:11:23-09:32:17 10.10.20.105 kernel: [ 19.280000] RED: red4_encap_rcv: tunnel 804 not found
    2012:11:23-09:32:17 10.10.20.105 kernel: [ 19.290000] RED: red4_encap_rcv: tunnel 802 not found
    2012:11:23-09:32:17 10.10.20.105 sysinit: Channel 2 busy time 0/239ms, 0%
    2012:11:23-09:32:17 10.10.20.105 sysinit: Channel 3 busy time 0/239ms, 0%
    2012:11:23-09:32:18 10.10.20.105 sysinit: Channel 4 busy time 0/239ms, 0%
    2012:11:23-09:32:18 10.10.20.105 kernel: [ 20.280000] RED: red4_encap_rcv: tunnel 804 not found
    2012:11:23-09:32:18 10.10.20.105 kernel: [ 20.290000] RED: red4_encap_rcv: tunnel 802 not found 


    Now we activated the debug mode again and the AccessPoints went up.

    Do you have any other ideas?
    Could we let the service in debug mode in the meantime?

    Attached you can find the Wireless Protection Log of a few hours.
    (includes normal mode and debug mode)

    best regards
    Marco
    WirelessProtection.zip
  • 0 in reply to marco116
    Hi Marco

    I wouldn't recommend leaving the debug on as it will result live log filling up quickly

    Can you provide more info regarding our topology? Is the AP connected directly to the UTM ?



    Therfore i tried to quit the debug mode and restarted the awed service.


    Basically there are 2 possibilities to start and end awed.
    first one is with the "/var/mdw/scripts/awed start/stop" command and second one is with "awed --debug" and "killall awed". 

    Debugging mode will only produce more logs AFAIK but it will not affect the configuration. If you are still running in debug mode you should stop the service by "killall awed".  

    After that , start the process by "/var/mdw/scripts/awed start" and post only the relevant section

    Thanks
Reply
  • 0 in reply to marco116
    Hi Marco

    I wouldn't recommend leaving the debug on as it will result live log filling up quickly

    Can you provide more info regarding our topology? Is the AP connected directly to the UTM ?



    Therfore i tried to quit the debug mode and restarted the awed service.


    Basically there are 2 possibilities to start and end awed.
    first one is with the "/var/mdw/scripts/awed start/stop" command and second one is with "awed --debug" and "killall awed". 

    Debugging mode will only produce more logs AFAIK but it will not affect the configuration. If you are still running in debug mode you should stop the service by "killall awed".  

    After that , start the process by "/var/mdw/scripts/awed start" and post only the relevant section

    Thanks
Children
No Data
Unfiltered HTML