Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 16 replies
  • Subscribers 1 subscriber
  • Views 8148 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

ASG120 Rev4 dropping AP 10 connections

wingman
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.
  • 0
    Hmm, looks like the control connection to the ASG is getting dropped. Not sure why though [:(]

    Did you have a different ASG before?

    Thanks,
    Helmut
  • 0
    Possibly an issue from the phys. network from AP to ASG (speed/duplex mismatch, switch config, routing...something like that?)
  • 0 in reply to Hallowach2
    Oh and you could of course run a tcpdump on the iface the AP is connected to. Maybe we can see something in there ...
  • 0 in reply to hschaa
    Hmm, looks like the control connection to the ASG is getting dropped. Not sure why though [:(]

    Did you have a different ASG before?

    Thanks,
    Helmut


    I am now using a ASG 120 Appliance (got it from the beta testing) . 

    -My old box had 4 Gig Ram -ASG 120 has 1G (planning to upgrade to 2G soon)-Running pretty hard with 1G as it's constantly on 75-80%
    -Settings are the same since I am using a backup from my old box

    2011:10:04-08:58:55 ap-10 awelogger[1588]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="****** Network" ssid_id="WLAN1" bssid="00:1a:8c:06:13:51" sta="00:1c:b3:52:b7:58"
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-ASSOC 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-CONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-ASSOC 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-CONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 hostapd: wlan1: STA 00:1c:b3:52:b7:58 IEEE 802.1X: authorizing port
    2011:10:04-08:58:55 ap-10 hostapd: wlan1: STA 00:1c:b3:52:b7:58 RADIUS: starting accounting session 4E87634C-00000037
    2011:10:04-08:58:55 ap-10 hostapd: wlan1: STA 00:1c:b3:52:b7:58 WPA: pairwise key handshake completed (RSN)
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-ASSOC 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-CONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-ASSOC 00:1c:b3:52:b7:580
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-CONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-DISCONNECTED 00:1c:b3:52:b7:58
    2011:10:04-08:58:55 ap-10 sysinit: AP-STA-AUTH 00:1c:b3:52:b7:580

    2011:10:04-10:53:54 ap-10 sysinit: alrm_handler(): timeout
    2011:10:04-10:53:54 ap-10 init: starting pid 6326, tty '': '/etc/init.d/rcS K shutdown'
    2011:10:04-10:53:55 ****  awed[6092]: send msg: ip:'192.168.2.1', id:'A40000D709AC807', type:'3', length:'48'
    2011:10:04-10:53:54 ap-10 sysinit: interface not found.
    2011:10:04-10:54:20 ****  awed[6092]: ll_read: short read or connection error: Connection reset by peer
    2011:10:04-10:54:20 ****  awed[6092]: error handling client 192.168.2.1, cutting connection.
    2011:10:04-10:54:20 ****  awed[6092]: >=========================================================================
    2011:10:04-10:54:20 ****  awed[6092]: low-level recv error: sysread failed
    2011:10:04-10:54:20 ****  awed[6092]: 
    2011:10:04-10:54:20 ****  awed[6092]:  1. Internal::AP:[:P]rocess_request:745() awed.pl
    2011:10:04-10:54:20 ****  awed[6092]:  2. main::top-level:215() awed.pl
    2011:10:04-10:54:20 ****  awed[6092]: 


    I will try and get the log messages from the event viewer of the affected box

    Thanks
  • 0 in reply to wingman
    I am now using a ASG 120 Appliance (got it from the beta testing) . 

    -My old box had 4 Gig Ram -ASG 120 has 1G (planning to upgrade to 2G soon)-Running pretty hard with 1G as it's constantly on 75-80%
    -Settings are the same since I am using a backup from my old box


    Ok, this might explain the spurious disconnects. The AP itself applies a 15 second timeout to the control connection. So, if the ASG isn't fast enough to reply to the AP's status request the AP will time out and reboot as it assumes the ASG is gone.

    If you could get me the tcpdump of the control connection I might be able to see more [:)]

    Thanks,
    Helmut
  • 0
    Thanks Helmut

    I will try and get the tcpdump today. In the meantime I have attached the event viewer log from the affected device. Also are there any plans to reduce the "15 second timeout" for the AP?
  • 0 in reply to wingman
    Also are there any plans to reduce the "15 second timeout" for the AP?


    Reducing it even more would increase the chance of a timeout. So, I still think 15 is a reasonable default ...

    Or did you mean to increase it?
  • 0
    yes sorry for that, I meant increase it. 

    However (I guess it's RAM related) most ASG/workstation come with at least 2Gig nowadays so let me upgrade my ASG 120 to 2G and see how it goes.

    (I will send over the tcpdump ASAP)
  • 0
    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
  • 0 in reply to wingman
    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
Unfiltered HTML