Question : Why does AP-275 comes up with an Inactive (I) flag where as other APs are up using the same AP configuration?
Environment Information : AP-275
Aruba OS 6.4+
Aruba Controller 7200, 6000 (M3), 3000 or 600 Series Controllers
Symptoms : AP 275 is coming up with I Flag where as other APs like AP-135/AP-125 using the same AP-Group are working fine
Cause : POE requirement for AP-275 is different from other APs
Resolution : AP-275 requires a minimum of 802.3at power (POE+) for it to function properly. With 802.3af power, the AP will come up with Inactive flag (I) and the radios and E1 port will still be disabled.
In one case, we have seen a Cisco 3850 POE switch (WS-C3850-48P) capable of POE+ was unable to power up the AP-275 fully. This was because the power module required for enabling POE+ per port was not in place.
Required:
In-Use:
Max Power supplied is 15.4W even though the POE switch is capable of upto 30W. We know that AP-275 requires a minimum of 802.3at (POE+) and upto a max power of 30W.
The resolution is to installed the required power supplies on the POE switch so that it can provide the POE+ power it is capable of.
Reference link for detailed specs for this POE switch:
http://www.cisco.com/c/en/us/products/collateral/switches/catalyst-3850-series-switches/data_sheet_c78-720918.html
Answer : If other APs are working fine using the same ap-group, then we must ensure the AP-275 is able to stably heartbeat (GRE) with the Controller and find out whether the AP is rebootstarpping or rebooting often. If GRE is blocked or GRE heartbeat packets droppedo n that path, the AP will continually bootstrap. It will appear to be active for the 8 seconds (by default) required for the AP to decide that the GRE tunnel is not there. The AP will appear as inactive ("I" flag) briefly between the times the AP reboots and the time the Controller configures the virtual APs. Commands used to verify GRE heartbeats and number of AP reboots/rebootstraps:
# show datapath session table <AP IP>
# show ap debug counters ap-name <AP>
In one instance, we have observed the AP-275 to be up continually with "I" flag and the AP is neither rebootstrapping or rebooting.
(Aruba) (config) #show ap database | include ap-group1
Aruba-Offices ap-group1 135 10.1.1.34 Up 10d:5h:21m:38s 2 10.1.1.242 0.0.0.
Aruba-Pillar ap-group1 135 10.1.1.35 Up 10d:4h:4m:25s 2 10.1.1.242 0.0.0.0
Aruba-AP275 ap-group1 275 10.1.1.39 Up 15m:30s 2I 10.1.1.242 0.0.0.0<<<<<<<<<<<<<<<<<<<
Aruba-Kitchen ap-group1 135 10.1.1.36 Up 10d:3h:59m:35s 2 10.1.1.242 0.0.0.0
(Aruba) (config) #show datapath session table 10.1.1.39
Datapath Session Table Entries
------------------------------
Flags: F - fast age, S - src NAT, N - dest NAT
D - deny, R - redirect, Y - no syn
H - high prio, P - set prio, T - set ToS
C - client, M - mirror, V - VOIP
Q - Real-Time Quality analysis
I - Deep inspect, U - Locally destined
E - Media Deep Inspect, G - media signal
A - Application Firewall Inspect
Source IP Destination IP Prot SPort DPort Cntr Prio ToS Age Destination TAge Packets Bytes Flags
--------------- --------------- ---- ----- ----- ----- ---- --- --- ----------- ---- --------- --------- ---------------
10.1.1.242 10.1.1.39 17 8222 8209 0/0 0 0 0 tunnel 868 e 0 0 FYI
10.1.1.242 10.1.1.39 17 8209 8209 0/0 0 0 1 tunnel 868 e 0 0 FYI
10.1.1.39 10.1.1.242 47 0 0 0/0 0 0 0 pc0 8b4 1086 108096 FC
10.1.1.39 10.1.1.242 17 65220 514 0/0 0 0 0 tunnel 868 34f 2787 511999 FC
10.1.1.242 10.1.1.39 47 0 0 0/0 0 0 0 pc0 8b4 1076 107216 F
10.1.1.39 10.1.1.242 17 8209 8209 0/0 0 0 0 tunnel 868 e 5 983 FCI
10.1.1.242 10.1.1.39 17 514 65220 0/0 0 0 52 tunnel 868 34f 0 0 FY
10.1.1.242 10.1.1.39 17 4500 4500 0/0 0 0 1 pc0 36b 2 58 F
10.1.1.39 10.1.1.242 17 4500 4500 0/0 0 0 0 pc0 36b 2841 750848 FC
10.1.1.242 10.1.1.39 17 8222 8211 0/0 0 0 0 local 3 3 312 FCI
10.1.1.39 10.1.1.242 17 8209 8222 0/0 0 0 0 tunnel 868 e 0 0 FYCI
10.1.1.39 10.1.1.242 17 8211 8222 0/0 0 0 0 local 3 0 0 FYI
As seen above, the PAPI and GRE tunnels seem to be active. The AP-Debug log and System log shows the AP is provisioned and configured fine and all profiles are applied correctly and we see no anomaly.
(Aruba) (config) #show log ap-debug 100
Apr 25 14:17:51 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Processing tagged ARP packet: Vlan=310 src=00:14:f2:3f:ff:32 Dst=00:00:00:00:00:00
Apr 25 14:17:51 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Parsed ARP Frame: src=00:14:f2:3f:ff:32 Dst=00:00:00:00:00:00
Apr 25 14:17:51 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: eif_add_mac: process_eif_packet MAC = 00:14:f2:3f:ff:32, IP = 10.1.1.202
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Tagged Frame Received 806 806 310
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Processing tagged ARP packet: Vlan=310 src=00:14:a8:51:77:32 Dst=00:00:00:00:00:00
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Parsed ARP Frame: src=00:14:a8:51:77:32 Dst=00:00:00:00:00:00
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: eif_add_mac: process_eif_packet MAC = 00:14:a8:51:77:32, IP = 10.1.1.196
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Tagged Frame Received 806 806 310
Apr 25 14:17:55 :326001: <DBUG> |AP Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Processing tagged ARP packet: Vlan=310 src=00:14:a8:51:77:32 Dst=00:00:00:00:00:00
(Aruba) (config) #show log system all | include Aruba-AP-275
Apr 25 14:21:56 :326148: <NOTI> |Aruba-AP275@10.1.1.39 sapd| AM: set_mode called for 6c:f3:7f:7c:7d:d0 type 1 active 0
Apr 25 14:21:56 :326009: <NOTI> |Aruba-AP275@10.1.1.39 sapd| AM: Wi-Fi Interface Reinit called for 6c:f3:7f:7c:7d:d0
Apr 25 14:21:56 :326148: <NOTI> |Aruba-AP275@10.1.1.39 sapd| AM: set_mode called for 6c:f3:7f:7c:7d:c0 type 1 active 0
Apr 25 14:21:56 :326009: <NOTI> |Aruba-AP275@10.1.1.39 sapd| AM: Wi-Fi Interface Reinit called for 6c:f3:7f:7c:7d:c0
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: am_update: set_mode processing complete
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_set_link_state: setting eth1 link state to 1
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_set_link_state: set eth1 link state to 1
Apr 25 14:21:56 :334101: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sap_msg_proc: received message from 10.1.1.242:8222: code 16100 type MONITORING_MSG_CONFIG id (10.1.1.242,535ab5c8,2) length 11
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_proc_sap_req: msg from 10.1.1.242:8222, type MONITORING_MSG_CONFIG id (10.1.1.242,535ab5c8,2) size 11,expecting id (10.1.1.242,535ab5c8,2)
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_proc_monitoring_msg_config_msg: msg from 10.1.1.242:8222 id (10.1.1.242,535ab5c8,2) size 11
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_proc_monitoring_msg_config_msg: LOCATION BITMASK (0) LOCATION FEED ENABLE (0)
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Tagged Frame Received 806 806 310
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Processing tagged ARP packet: Vlan=310 src=00:14:f2:4f:73:12 Dst=00:00:00:00:00:00
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Parsed ARP Frame: src=00:14:f2:4f:73:12 Dst=00:00:00:00:00:00
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: eif_add_mac: process_eif_packet MAC = 00:14:f2:4f:73:12, IP = 10.1.1.203
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Tagged Frame Received 806 806 310
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Processing tagged ARP packet: Vlan=310 src=00:14:f2:4f:73:12 Dst=00:00:00:00:00:00
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: process_eif_packet: Parsed ARP Frame: src=00:14:f2:4f:73:12 Dst=00:00:00:00:00:00
Apr 25 14:21:56 :326001: <DBUG> |Aruba-AP275@10.1.1.39 sapd| AM: eif_add_mac: process_eif_packet MAC = 00:14:f2:4f:73:12, IP = 10.1.1.203
Apr 25 14:21:56 :334101: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sap_msg_proc: received message from 10.1.1.242:8222: code 16100 type MONITORING_MSG_CONFIG id (10.1.1.242,535ab5c8,2) length 11
Apr 25 14:21:56 :311009: <DBUG> |Aruba-AP275@10.1.1.39 sapd| sapd_proc_sap_req: msg from 10.1.1.242:8222, type MONITORING_MSG_CONFIG id (10.1.1.242,535ab5c8,2) size 11,expecting id (10.1.1.242,535ab5c8,3)
The issue is related to the amount of power supplied to the AP and this is evident from the following output:
(Aruba) (config) #show ap debug system-status ap-name Aruba-AP275
********PARTIAL OUTPUT*******************
Power Status
------------
Operational State POE-AF: Ethernet port 1 disabled; All radios disabled;
----------------- ------------------------------------------------------
Current HW State POE-AF: Ethernet port 1 disabled; All radios disabled;