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

ASG120 Rev4 dropping AP 10 connections

Hi All

Since I got the ASG 120 , my AP10 is keep disconnecting (twice per day). I have firmware 8.202 and the relevant log is:

2011:10:02-22:52:31 ap-10 hostapd: wlan0: STA 00:1d:e0:72:09:a9 WPA: received EAPOL-Key frame (2/2 Group)

2011:10:02-22:52:31 ap-10 hostapd: wlan0: STA 00:1d:e0:72:09:a9 WPA: group key handshake completed (RSN)
2011:10:02-22:52:31 ap-10 hostapd: wlan0: STA 00:1f:c6:e2:c5:1d WPA: received EAPOL-Key frame (2/2 Group)
2011:10:02-22:52:31 ap-10 hostapd: wlan0: STA 00:1f:c6:e2:c5:1d WPA: group key handshake completed (RSN)
2011:10:02-22:52:32 stuffman awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
2011:10:02-22:52:48 stuffman awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
2011:10:02-22:53:03 stuffman awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
2011:10:02-22:53:18 stuffman awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48
2011:10:02-22:53:48 ap-10 sysinit: alrm_handler(): timeout
2011:10:02-22:53:48 ap-10 init: starting pid 10805, tty '': '/etc/init.d/rcS K shutdown'
2011:10:02-22:53:48 ap-10 sysinit: interface not found.
2011:10:02-22:54:00 ****  awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
2011:10:02-22:54:12 ****  awed[6092]: ll_read: short read or connection error: Connection reset by peer
2011:10:02-22:54:12 ****  awed[6092]: error handling client 192.168.2.1, cutting connection.

2011:10:02-22:54:12 ****  awed[6092]: >=========================================================================
2011:10:02-22:54:12 ****  awed[6092]: low-level recv error: sysread failed
2011:10:02-22:54:12 ****  awed[6092]: 
2011:10:02-22:54:12 ****  awed[6092]:  1. Internal::AP:[:P]rocess_request:745() awed.pl
2011:10:02-22:54:12 ****  awed[6092]:  2. main::top-level:215() awed.pl
2011:10:02-22:54:12 ****  awed[6092]:  rt2x00mac_conf_tx: Info - Configured TX queue 1 - CWmin: 4, CWmax: 5, Aifs: 2, TXop: 188.
2011:10:01-19:00:20 ap-10 kernel: [   17.890000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 2 - CWmin: 5, CWmax: 10, Aifs: 3, TXop: 0.
2011:10:01-19:00:20 ap-10 kernel: [   17.890000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 3 - CWmin: 5, CWmax: 10, Aifs: 7, TXop: 0.
2011:10:01-19:00:21 ap-10 sysinit: Channel 1 busy time 46/234ms, 19%
2011:10:01-19:00:21 ap-10 sysinit: Channel 2 busy time 11/217ms, 5%
2011:10:01-19:00:21 ap-10 sysinit: Channel 3 busy time 0/217ms, 0%
2011:10:01-19:00:22 ap-10 sysinit: Channel 4 busy time 1/217ms, 0%
2011:10:01-19:00:22 ap-10 sysinit: Channel 5 busy time 16/217ms, 7%
2011:10:01-19:00:22 ap-10 sysinit: Channel 6 busy time 42/217ms, 19%
2011:10:01-19:00:23 ap-10 sysinit: Channel 7 busy time 22/217ms, 10%
2011:10:01-19:00:23 ap-10 sysinit: Channel 8 busy time 3/217ms, 1%
2011:10:01-19:00:23 ap-10 sysinit: Channel 9 busy time 18/217ms, 8%
2011:10:01-19:00:24 ap-10 sysinit: Channel 10 busy time 85/217ms, 39%
2011:10:01-19:00:24 ap-10 sysinit: Channel 11 busy time 79/217ms, 36%
2011:10:01-19:00:25 ap-10 sysinit: Select channel 1
2011:10:01-19:00:25 ap-10 sysinit: 192.168.2.100 = 192.168.2.100 
2011:10:01-19:00:25 ap-10 kernel: [   22.710000] RED: tunnel id 800, use_crypto was set to 0
2011:10:01-19:00:26 ap-10 sysinit: Interface type  not supported.
2011:10:01-19:00:26 ap-10 kernel: [   23.820000] device eth0.20 entered promiscuous mode
2011:10:01-19:00:26 ap-10 kernel: [   23.820000] br-lan20: port 1(eth0.20) entering forwarding state
2011:10:01-19:00:26 ap-10 kernel: [   23.820000] br-lan20: port 1(eth0.20) entering forwarding state
2011:10:01-19:00:27 ap-10 sysinit: Usage: iw [options] phy  set antenna  | all |  
2011:10:01-19:00:27 ap-10 sysinit: Set a bitmap of allowed antennas to use for TX and RX.
2011:10:01-19:00:27 ap-10 sysinit: The driver may reject antenna configurations it cannot support.
2011:10:01-19:00:27 ap-10 sysinit: Options:
2011:10:01-19:00:27 ap-10 sysinit:  --debug enable netlink debugging
2011:10:01-19:00:27 ap-10 kernel: [   24.670000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 0 - CWmin: 3, CWmax: 4, Aifs: 2, TXop: 102.
2011:10:01-19:00:27 ap-10 kernel: [   24.670000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 1 - CWmin: 4, CWmax: 5, Aifs: 2, TXop: 188.
2011:10:01-19:00:27 ap-10 kernel: [   24.670000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 2 - CWmin: 5, CWmax: 10, Aifs: 3, TXop: 0.
2011:10:01-19:00:27 ap-10 kernel: [   24.670000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 3 - CWmin: 5, CWmax: 10, Aifs: 7, TXop: 0.
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 0 - CWmin: 3, CWmax: 4, Aifs: 2, TXop: 102.
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 1 - CWmin: 4, CWmax: 5, Aifs: 2, TXop: 188.
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 2 - CWmin: 5, CWmax: 10, Aifs: 3, TXop: 0.
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 3 - CWmin: 5, CWmax: 10, Aifs: 7, TXop: 0.
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] device wlan0 entered promiscuous mode
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] br-lan10: port 2(wlan0) entering forwarding state
2011:10:01-19:00:27 ap-10 kernel: [   24.760000] br-lan10: port 2(wlan0) entering forwarding state
2011:10:01-19:00:28 ap-10 kernel: [   25.700000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 0 - CWmin: 2, CWmax: 3, Aifs: 1, TXop: 47.
2011:10:01-19:00:28 ap-10 kernel: [   25.700000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 1 - CWmin: 3, CWmax: 4, Aifs: 1, TXop: 94.
2011:10:01-19:00:28 ap-10 kernel: [   25.700000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 2 - CWmin: 4, CWmax: 6, Aifs: 3, TXop: 0.
2011:10:01-19:00:28 ap-10 kernel: [   25.700000] phy0 -> rt2x00mac_conf_tx: Info - Configured TX queue 3 - CWmin: 4, CWmax: 10, Aifs: 7, TXop: 0.
2011:10:01-19:00:30 ap-10 kernel: [   27.900000] device wlan0 left promiscuous mode
2011:10:01-19:00:30 ap-10 kernel: [   27.900000] br-lan10: port 2(wlan0) entering forwarding state
2011:10:01-19:00:31 ap-10 kernel: [   28.100000] device wlan0 entered promiscuous mode
2011:10:01-19:00:31 ap-10 kernel: [   28.100000] br-lan10: port 2(wlan0) entering forwarding state
2011:10:01-19:00:31 ap-10 kernel: [   28.100000] br-lan10: port 2(wlan0) entering forwarding state
2011:10:01-19:00:31 ap-10 kernel: [   28.390000] device wlan1 entered promiscuous mode
2011:10:01-19:00:31 ap-10 kernel: [   28.390000] br-lan20: port 2(wlan1) entering forwarding state
2011:10:01-19:00:31 ap-10 kernel: [   28.390000] br-lan20: port 2(wlan1) entering forwarding state
2011:10:02-22:54:32 ****  awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
2011:10:02-22:54:32 ap-10 hostapd: wlan0: WPA rekeying GTK


Thanks


This thread was automatically locked due to age.
Parents
  • I have attached two files. One of them is when filtering by IP address and one of them using the port 9980 (Wireless Security Magic IP) filter

    I was able to force the AP to reboot by enabling/Disabling Snort [:)]

    same error message 

    2011:10:05-19:04:07 ****  awed[6092]: ll_read: short read or connection error: Connection reset by peer
    2011:10:05-19:04:07 ****  awed[6092]: error handling client 192.168.2.1, cutting connection.
    2011:10:05-19:04:07 ****  awed[6092]: >=========================================================================
    2011:10:05-19:04:07 ****  awed[6092]: low-level recv error: sysread failed
    2011:10:05-19:04:07 ****  awed[6092]: 
    2011:10:05-19:04:07 ****  awed[6092]:  1. Internal::AP:[:P]rocess_request:745() awed.pl
    2011:10:05-19:04:07 ****  awed[6092]:  2. main::top-level:215() awed.pl
    2011:10:05-19:04:07 ****  awed[6092]: 


    Thanks
    Desktop.zip
  • Ok, the disconnect_AP-IP.pcap shows us the following (the AP is 192.168.2.1):
    Every 15 seconds the AP sends a status update to the ASG and expects a reply.

    A successful exchange can be seen for example in frame 9-12 or 13-16.

    Frame 17+18 show the next status update from the AP being accepted by the ASGs network stack. But there is no reply happening. Instead 15 seconds later we can see the AP performing a reboot due to the internal timeout. The ASG sends its reply in frame 24 which is 26 seconds later and of course the AP is already gone at that time.

    So, I don't know what is eating all your ASGs CPU or IO but it seems it is simply overloaded and cannot serve the AP in time.

    Let me think about this a bit more. Increasing the timeout is not necessarily a good idea since it means that the AP will need longer to realize if the connection really dropped ...

    So as a "workaround" you could try to disable some IO and CPU intensive features.

    Helmut
Reply
  • Ok, the disconnect_AP-IP.pcap shows us the following (the AP is 192.168.2.1):
    Every 15 seconds the AP sends a status update to the ASG and expects a reply.

    A successful exchange can be seen for example in frame 9-12 or 13-16.

    Frame 17+18 show the next status update from the AP being accepted by the ASGs network stack. But there is no reply happening. Instead 15 seconds later we can see the AP performing a reboot due to the internal timeout. The ASG sends its reply in frame 24 which is 26 seconds later and of course the AP is already gone at that time.

    So, I don't know what is eating all your ASGs CPU or IO but it seems it is simply overloaded and cannot serve the AP in time.

    Let me think about this a bit more. Increasing the timeout is not necessarily a good idea since it means that the AP will need longer to realize if the connection really dropped ...

    So as a "workaround" you could try to disable some IO and CPU intensive features.

    Helmut
Children
No Data