Wireless Access

Ap setup is RAP,  multiple other APs work fine.  That is not bootstrap but reboot

show ap debug counters | include AP-6-chicken
AP-6-chicken                    GDgroup  169.253.1.90   7             6              0              0               2          (455  )  225      N      2/1/2/1/0/0/0            455/454/455/454/0/0/0   0/-/-/-

May  8 14:45:54 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=xxxxxxxx idle-tmo:0 ]
May  8 14:47:16 stm[2754]: <501093> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg remove_stale_sta 3100: client a8:5c:2c:45:85:a2 not in stale hash table]
May  8 14:47:16 stm[2754]: <501095> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:47:16.033820] [mac a8:5c:2c:45:85:a2] [sn 2613] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:5787: mcast_encr(0x00000020), ucast_encr(0x00000020)]
May  8 14:47:16 stm[2754]: <501218> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg stm_sta_assign_vlan 18428: VLAN: sta a8:5c:2c:45:85:a2, STM assigns MAC based vlan_id 14]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req: STA:a8:5c:2c:45:85:a2 aid:0]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:6743 XXX mac=a8:5c:2c:45:85:a2 reassoc(0), dot11r(0), ftie_present(0), auth_alg(0) SNR(9) max_neg_rate(866)]


May  8 14:47:16 stm[2754]: <501100> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:47:16.037497] [mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=0.0.0.0 idle-tmo:0 ]
May  8 14:47:16 stm[2754]: <501093> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg remove_stale_sta 3100: client a8:5c:2c:45:85:a2 not in stale hash table]
May  8 14:47:16 stm[2754]: <501093> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg remove_stale_sta 3100: client a8:5c:2c:45:85:a2 not in stale hash table]
May  8 14:47:16 stm[2754]: <501095> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:47:16.124957] [mac a8:5c:2c:45:85:a2] [sn 2616] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:5787: mcast_encr(0x00000020), ucast_encr(0x00000020)]
May  8 14:47:16 stm[2754]: <501218> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg stm_sta_assign_vlan 18428: VLAN: sta a8:5c:2c:45:85:a2, STM assigns MAC based vlan_id 14]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req: STA:a8:5c:2c:45:85:a2 aid:0]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:6743 XXX mac=a8:5c:2c:45:85:a2 reassoc(0), dot11r(0), ftie_present(0), auth_alg(0) SNR(11) max_neg_rate(866)]
May  8 14:47:16 stm[2754]: <501100> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:47:16.128962] [mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: RRM Action - act(4) a1(18:64:72:df:c1:d1) a2(a8:5c:2c:45:85:a2) a3(18:64:72:df:c1:d1)]
May  8 14:47:16 stm[2754]: <524041> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[string wpa2_tx_eapolkey_mesg3] [len 22] [len1 46]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=0.0.0.0 idle-tmo:0 ]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: RRM Action - act(5) a1(a8:5c:2c:45:85:a2) a2(18:64:72:df:c1:d1) a3(18:64:72:df:c1:d1)]
May  8 14:47:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: neighbor report response for sta(a8:5c:2c:45:85:a2)]
May  8 14:48:16 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:49:17 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:50:18 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:51:05 sapd[2742]: <404069> <WARN> |AP AP-6-chicken@169.253.1.90 sapd|  ^[bssid 18:64:72:df:c1:c0] [min_amc_channel 1] [arm_nii_arm_nccii 146] [ap_amc_channel 11] [arm_nccii_arm_nii 193] [channel 1] [new_tx_power 1] [arm_tci 10] [dfch 38]
May  8 14:51:05 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=xxxxxxxxx idle-tmo:0 ]
May  8 14:51:05 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=xxxxxxxxxx idle-tmo:0 ]


May  8 14:51:19 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:51:37 stm[2754]: <501093> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg remove_stale_sta 3100: client a8:5c:2c:45:85:a2 not in stale hash table]
May  8 14:51:37 stm[2754]: <501095> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:51:37.754741] [mac a8:5c:2c:45:85:a2] [sn 3750] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:5787: mcast_encr(0x00000020), ucast_encr(0x00000020)]
May  8 14:51:37 stm[2754]: <501218> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg stm_sta_assign_vlan 18428: VLAN: sta a8:5c:2c:45:85:a2, STM assigns MAC based vlan_id 14]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req: STA:a8:5c:2c:45:85:a2 aid:0]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg handle_assoc_req:6743 XXX mac=a8:5c:2c:45:85:a2 reassoc(0), dot11r(0), ftie_present(0), auth_alg(0) SNR(14) max_neg_rate(866)]
May  8 14:51:37 stm[2754]: <501100> <NOTI> |AP AP-6-chicken@169.253.1.90 stm|  ^[tstr 14:51:37.756830] [mac a8:5c:2c:45:85:a2] [ip 169.253.1.90] [bssid 18:64:72:df:c1:d1] [name AP-6-chicken]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: RRM Action - act(4) a1(18:64:72:df:c1:d1) a2(a8:5c:2c:45:85:a2) a3(18:64:72:df:c1:d1)]
May  8 14:51:37 stm[2754]: <524041> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[string wpa2_tx_eapolkey_mesg3] [len 22] [len1 46]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: RRM Action - act(5) a1(a8:5c:2c:45:85:a2) a2(18:64:72:df:c1:d1) a3(18:64:72:df:c1:d1)]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_handle_action: neighbor report response for sta(a8:5c:2c:45:85:a2)]
May  8 14:51:37 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg update_ip_mac_role_acl_vlan: RAP user IP=0.0.0.0 idle-tmo:0 ]
May  8 14:52:38 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:53:39 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:54:40 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:55:41 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:56:42 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]
May  8 14:57:43 stm[2754]: <501065> <DBUG> |AP AP-6-chicken@169.253.1.90 stm|  ^[msg rrm_prepare_beacon_request_frame: bcn-req sent from ap-stm to sta:a8:5c:2c:45:85:a2 bss:18:64:72:df:c1:d1 bchan:36(sch:52) (5g:1)]

That may be more readable

That is typically because of poor network conditions between the RAP And the controller.

I have couple other APs there connecting to the same controller using same network setup and all work fine, so I would exclude routing.  The only thing that comes to my head would be bad cable or tips but looking at the swtich logs I see no errors so I would exclude that too. That would leave the cause to sth like bad AP. Do you think is that likely?

From swtich logs I can tell AP reboots like every 10 or 15 minutes

I 01/06/90 20:27:36 00076 ports: port 6 is now on-line
I 01/06/90 20:27:34 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:27:31 00077 ports: port 6 is now off-line
I 01/06/90 20:26:39 00076 ports: port 6 is now on-line
I 01/06/90 20:26:37 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:26:34 00077 ports: port 6 is now off-line
I 01/06/90 20:26:34 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:26:31 00077 ports: port 6 is now off-line
I 01/06/90 20:20:00 00076 ports: port 6 is now on-line
I 01/06/90 20:19:58 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:16:35 00077 ports: port 6 is now off-line
I 01/06/90 19:52:51 00076 ports: port 6 is now on-line
I 01/06/90 19:52:49 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:52:47 00077 ports: port 6 is now off-line
I 01/06/90 19:51:54 00076 ports: port 6 is now on-line
I 01/06/90 19:51:52 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:51:46 00077 ports: port 6 is now off-line
I 01/06/90 19:45:15 00076 ports: port 6 is now on-line
I 01/06/90 19:45:12 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:41:10 00077 ports: port 6 is now off-line
I 01/06/90 19:19:32 00076 ports: port 6 is now on-line
I 01/06/90 19:19:29 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:19:27 00077 ports: port 6 is now off-line
I 01/06/90 19:18:34 00076 ports: port 6 is now on-line
I 01/06/90 19:18:32 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:18:26 00077 ports: port 6 is now off-line
I 01/06/90 19:11:56 00076 ports: port 6 is now on-line
I 01/06/90 19:11:53 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:07:20 00077 ports: port 6 is now off-line
I 01/06/90 18:47:07 00076 ports: port 6 is now on-line
I 01/06/90 18:47:04 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:47:02 00077 ports: port 6 is now off-line
I 01/06/90 18:46:10 00076 ports: port 6 is now on-line
I 01/06/90 18:46:08 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:46:05 00077 ports: port 6 is now off-line
I 01/06/90 18:46:04 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:46:02 00077 ports: port 6 is now off-line

I have several other APs connected the same way to the same controller, so I dont think it is a routing and swtiching also since logs dont indicate any problem on that port. I can tell that it reboots every 10 or 15 min in average. So is this faulty AP?

I 01/06/90 20:27:36 00076 ports: port 6 is now on-line
I 01/06/90 20:27:34 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:27:31 00077 ports: port 6 is now off-line
I 01/06/90 20:26:39 00076 ports: port 6 is now on-line
I 01/06/90 20:26:37 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:26:34 00077 ports: port 6 is now off-line
I 01/06/90 20:26:34 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:26:31 00077 ports: port 6 is now off-line
I 01/06/90 20:20:00 00076 ports: port 6 is now on-line
I 01/06/90 20:19:58 00435 ports: port 6 is Blocked by STP
I 01/06/90 20:16:35 00077 ports: port 6 is now off-line
I 01/06/90 19:52:51 00076 ports: port 6 is now on-line
I 01/06/90 19:52:49 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:52:47 00077 ports: port 6 is now off-line
I 01/06/90 19:51:54 00076 ports: port 6 is now on-line
I 01/06/90 19:51:52 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:51:46 00077 ports: port 6 is now off-line
I 01/06/90 19:45:15 00076 ports: port 6 is now on-line
I 01/06/90 19:45:12 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:41:10 00077 ports: port 6 is now off-line
I 01/06/90 19:19:32 00076 ports: port 6 is now on-line
I 01/06/90 19:19:29 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:19:27 00077 ports: port 6 is now off-line
I 01/06/90 19:18:34 00076 ports: port 6 is now on-line
I 01/06/90 19:18:32 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:18:26 00077 ports: port 6 is now off-line
I 01/06/90 19:11:56 00076 ports: port 6 is now on-line
I 01/06/90 19:11:53 00435 ports: port 6 is Blocked by STP
I 01/06/90 19:07:20 00077 ports: port 6 is now off-line
I 01/06/90 18:47:07 00076 ports: port 6 is now on-line
I 01/06/90 18:47:04 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:47:02 00077 ports: port 6 is now off-line
I 01/06/90 18:46:10 00076 ports: port 6 is now on-line
I 01/06/90 18:46:08 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:46:05 00077 ports: port 6 is now off-line
I 01/06/90 18:46:04 00435 ports: port 6 is Blocked by STP
I 01/06/90 18:46:02 00077 ports: port 6 is now off-line

I dont think it is layer 3 because other RAPs with the same setup work fine and I dont think based on the logs from swtich it is layer 2 or 1 also.  RAP keeps rebooting in average every 10 min, wierd, faulty unit?

But that RAPs don't use the same circuit as the others.  It could be local to that RAP.  It could be simple as a duplex mismatch or a bad ISP.

---

@cjosephwrote:

But that RAPs don't use the same circuit as the others.  It could be local to that RAP.

---

How did you verify that it uses different circut?  

I see it uses exactly same vlan and settings as 5 other RAPs connected the same way and working fine.

I excluded duplex mismatch.

Where is the RAP physically and what kind of circuit is it connected to?

All 6 RAPs physically are connected in the same place using same wiring going to the same switch using same fiber 1Gbs circut on the same management vlan connecting to the same controller.

Very weird, it looks like RAP stopped rebooting today around 4pm but I have noticed it got differnet IP on controller side. Instead of 169.253.1.90 not it is 169.253.1.181

Status:

 169.253.1.181  Up 10h:8m:14s

I did:

show log all | include reboot

Could that be reason? What does it mean it can't get IP?

 Reboot Reason: AP rebooted Tue May 8 20:40:53 EST 2018; Unable to get IP address using DHCP after 10 tries, total DHCP retry:1

That means when the RAP reboots, nothing is supplying it with an ip address.  What dhcp server should be supplying the AP with an ip address?

Also, you have 6 RAPs at the same location?  Is there a firewall separating the RAPs and the controller?  Many firewall can only pass a limited number of ipsec connections. 

What dhcp server should be supplying the AP with an ip address? cisco 2900 series, I checked the pool it is way from full.

Also, you have 6 RAPs at the same location?  - yes

Is there a firewall separating the RAPs and the controller?  - no, I dont think there is ipsec limit factor here, recently I added another 6 RAPs served from the same router and they work fine

Are you calling it a remote AP because it is far from the controller, or do you have it configured as a remote AP (RAP Whitelist)?

It is a real RAP, RAP Whitelist and its like 15 miles away

If a RAP is rebooting, there is a problem with the quality of the connection between the RAP and the controller.  To make it worse, when it is rebooting, DHCP is not being supplied to it.  If you have a centralized DHCP server and you are serving this site using that DHCP server, the AP not getting an ip address is another symptom of a problem between that site and the controller.  You need to investigate that, because I don't know anything about your network.

AP is currently up 12 hours without reboot.

any possibility that something is statically configured (at the remote site) with the same IP address that was in use on this AP when it was unstable?

No, nothing statically. The only thing that comes to my mind is that IP on the controller side for RAP(ip pool) may have been used and conflicting but I can't verify this.

So far that RAP is up for 25 hours without reboot, without any changes on any side, strange.

The RAP pool should be private, non-routable addresses except for very limited circumstances.

The reason for that rebooting was most likely faulty firmware on POE+ SW that  messed up power managemnt