Hey there airheads... Have some interesting questions to find out what the heck is going on.
I have a factory reset AP225 that I have configured on the aruba activate site. It's all setup to push the AP over to my airwave server (which is up and runnig with other APs attached).
For the life of me, and after packet tracing the AP, I am at a point where I dont understand why the AP is waiting nearly 30 minutes to query device.arubanetworks.com. During the boot, it tries to query aruba-master (which I know is somewhat normal) but it's trying that first, then seems to stick and hang and maybe I know why.
When the AP is booting the DHCP scope assigns the IP, no issues. Part of the scope is for the AP to use 4.2.2.2 as the DNS server. As soon as the AP gets the IP, it's off and queries instantly aruba-master (short name and no FQDN). However, what happens next is somewhat fascinating.
Since 4.2.2.2 is a Level3 is DNS anycast IP, it's returning two IPs to the AP: 198.105.244.11 and 104.239.213.7. If you watch the CLI on the AP when it's booting, all of this happens just as soon as it runs ADP. I can see all of this on my packet trace. Then you see it say elected master is: 198.105.244.11 (which is completely bogus).
From there the AP sits for nearly 30 minutes... then out of the blue, it send a DNS query for device.arubanetworks.com, which returns the IP of the activate site. When this occurs, the activate site sends the DNS name of my airwave server, the AP gets it, and then it starts to communicate with my airwave server, it shows up as a new device, and the rest is easy... no issues with that, it's just the delay.
So, a couple of things: does everyone know that without a FQDN, the AP is actually getting a response to "aruba-master" from a public DNS server? I know if I had a controller I would do this myself, but I dont need it and becsue I am setting up APs all over the place for different clients, I am going to have who knows what in the way of DNS resolvers.
Secondly, why is it waiting for 30 minutes to try to hit device.arubanetworks.com? Since this is an instant, why isnt it trying that site first, then trying aruba-master if it cannot find anything?
The AP is running the 6.5.x code. Below is a snip of the boot of this AP, so you can see what I am talking about. This is on a hard-reset while powering the AP up. I have bolded the aruba-master response.
BTW look up that IP, it's some search site from L3 and such...
APBoot 1.4.0.6 (build 38177)
Built: 2013-04-25 at 22:52:20
Model: AP-22x
CPU0: P1020E, Version: 1.1, (0x80ec0011)
Core: E500, Version: 5.1, (0x80212051)
Clock:
CPU0: 800 MHz
CPU1: 800 MHz
CCB: 400 MHz
DDR: 333.333 MHz (666.667 MT/s data rate) (Asynchronous)
LBC: 25 MHz
L1: D-cache 32KB enabled
I-cache 32KB enabled
I2C: ready
DRAM: Configuring DDR for 666.667 MT/s data rate
DDR: 512 MB (DDR3, 32-bit, CL=5, ECC off)
POST1: memory passed
Flash: 32 MB
L2: 256 KB enabled
Power: 802.3at POE
PCIe1: RC, link up, x1
dev fn venID devID class rev MBAR0 MBAR1 MBAR2 MBAR3
00 00 14e4 43a2 00002 03 80000004 00000000 80200004 00000000
PCIe2: RC, link up, x1
dev fn venID devID class rev MBAR0 MBAR1 MBAR2 MBAR3
00 00 14e4 43a1 00002 03 a0000004 00000000 a0200004 00000000
Net: eth0, eth1
Radio: bcm43460#0, bcm43460#1
**** Configuration Reset Requested by User ****
Clearing state... Checking OS image and flags
Image is signed; verifying checksum... passed
Preserving image partition 0
Erasing flash sector @ 0xefe80000.... done
Erased 1 sectors
Erasing flash sector @ 0xefea0000.... done
Erased 1 sectors
Erasing flash sector @ 0xefee0000.... done
Erased 1 sectors
Erasing flash sector @ 0xeff00000.... done
Erased 1 sectors
Erasing flash sector @ 0xeff20000.... done
Erased 1 sectors
done
Purging environment... preserving os_partition (1)
Un-Protected 1 sectors
. done
Erased 1 sectors
Writing 9....8....7....6....5....4....3....2....1....
Un-Protected 1 sectors
. done
Erased 1 sectors
Writing 9....8....7....6....5....4....3....2....1....
done
Hit <Enter> to stop autoboot: 0
Booting OS partition 1
Checking image @ 0xeee00000
Copying image from 0xeee00000
Image is signed; verifying checksum... passed
Signer Cert OK
Policy Cert OK
RSA signature verified.
[ 0.000000] Flash variant: default
[ 0.000000]
[ 0.000000] Aruba Networks
[ 0.000000] ArubaOS Version 6.5.3.0-6.5.3.0 (build 59775 / label #59775)
[ 0.000000] Built by p4build@pr-hpn-build01 on 2017-05-24 at 22:08:47 AST (gcc version 4.5.1)
[ 0.000000]
[ 0.000000] Memory: 504092k/524288k available (14508k kernel code, 20196k reserved, 612k data, 376k bss, 10972k init)
[ 0.003035] Processor 1 found.
[ 0.112672] Brought up 2 CPUs
[ 0.189898] PCI: Probing PCI hardware
[ 0.232687] PCI: Resetting PCI bus
[ 0.433649] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[ 0.496033] pci 0001:02:00.0: PCI bridge to [bus 03-ff]
[ 0.558275] pci 0000:01:00.0: BAR 2: assigned [mem 0x80000000-0x801fffff 64bit]
[ 0.645151] pci 0000:01:00.0: BAR 2: set to [mem 0x80000000-0x801fffff 64bit] (PCI address [0x80000000-0x801fffff]
[ 0.769065] pci 0000:01:00.0: BAR 0: assigned [mem 0x80200000-0x80207fff 64bit]
[ 0.856561] pci 0000:01:00.0: BAR 0: set to [mem 0x80200000-0x80207fff 64bit] (PCI address [0x80200000-0x80207fff]
[ 0.980514] pci 0000:00:00.0: enabling device (0106 -> 0107)
[ 1.048216] pci 0001:03:00.0: BAR 2: assigned [mem 0xa0000000-0xa01fffff 64bit]
[ 1.135711] pci 0001:03:00.0: BAR 2: set to [mem 0xa0000000-0xa01fffff 64bit] (PCI address [0xa0000000-0xa01fffff]
[ 1.259656] pci 0001:03:00.0: BAR 0: assigned [mem 0xa0200000-0xa0207fff 64bit]
[ 1.347155] pci 0001:03:00.0: BAR 0: set to [mem 0xa0200000-0xa0207fff 64bit] (PCI address [0xa0200000-0xa0207fff]
[ 1.471106] pci 0001:02:00.0: enabling device (0106 -> 0107)
[ 9.249943] ee000000.nor: Found 1 x16 devices at 0x0 in 16-bit bank
[ 9.324987] Amd/Fujitsu Extended Query Table at 0x0040
[ 9.386506] number of CFI chips: 1
[ 9.431764] fsl-gianfar ethernet.2: enabled errata workarounds, flags: 0x4
[ 9.514595] /proc/gfar_eth0_stats created
[ 9.564849] fsl-gianfar ethernet.3: enabled errata workarounds, flags: 0x4
[ 9.647651] /proc/gfar_eth1_stats created
[ 9.712702] Enabling watchdog on CPU 1
[ 9.712710] Enabling watchdog on CPU 0
[ 9.802566] Masking ICV Error interrupt
[ 10.104338]
[ 10.104342] Starting Kernel SHA1 KAT ...Starting Kernel HMAC SHA1 FIPS KAT ...Completed Kernel HMAC SHA1 FIPS KAT
[ 10.114412] Starting Kernel HMAC SHA256 FIPS KAT ...Completed Kernel HMAC SHA256 FIPS KAT
[ 10.115167] Starting Kernel HMAC SHA384 FIPS KAT ...Completed Kernel HMAC SHA384 FIPS KAT
[ 10.115702] Starting Kernel HMAC SHA512 FIPS KAT ...Completed Kernel HMAC SHA512 FIPS KAT
[ 10.116275] Starting Kernel AES-CBC FIPS KAT ...Completed Kernel AES-CBC FIPS KAT
[ 10.121519] Starting Kernel AES-CCM FIPS KAT ...Completed Kernel AES-CCM FIPS KAT
[ 10.122030] Starting Kernel 3DES-CBC FIPS KAT ...Completed Kernel 3DES-CBC FIPS KAT
[ 10.816934] Completed Kernel SHA1 KAT
[ 10.861748] Starting Kernel HMAC-SHA1 KAT ...Completed Kernel HMAC-SHA1 KAT
[ 10.950166] Starting Kernel DES KAT ...Completed Kernel DES KAT
[ 11.022120] Starting Kernel AES KAT ...Completed Kernel AES KAT
[ 11.065918]
Thu Jan 1 00:00:00 PST 1970
Domain Name: SetMeUp.arubanetworks.com
Current OEM Name : Aruba Networks
Disabling ipv6 for devices by default
AP-type has_ble_support: USB.
IPv6 capability is supported for devices
No panic info available
ardmore: Start hotplug
Enabling ble_daemon and ble_relay via nanny
apfcutil: sector CACHE: Cache uninitialized
apfcutil: sector RAP: Cache uninitialized
apfcutil: sector FAT: Cache uninitialized
apfcutil: sector SCRATCH: Cache uninitialized
Backup ENV.
apfcutil: sector MESH Prov: Cache uninitialized
[ 21.087105] p1020_soc: P1020 Misc Utils Driver version 1
Enter non-FIPS mode
Cfg len is 0
Configuration file is empty, turning on default services...
extended ssid activate due to no AP config ...
Ethernet port 1 mode: active-standby
[ 24.983324] init_phy: PHY interface is SGMII
[ 25.036869] ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 25.102686] ADDRCONF(NETDEV_UP): bond0: link is not ready
[ 25.186954] init_phy: PHY interface is SGMII
[ 25.239518] bonding: bond0: enslaving eth0 as a backup interface with a down link.
Info: use bondin[ 25.349089] init_phy: PHY interface is SGMII
g and enslave et[ 25.413696] ADDRCONF(NETDEV_UP): eth1: link is not ready
h1
[ 25.516874] init_phy: PHY interface is SGMII
[ 25.569439] bonding: bond0: enslaving eth1 as a backup interface with a down link.
Starting watchdog process...
touching file /tmp/ip_mode_1
Enabling DHCPv6 ... IP mode is v4-prefer ...
init usb modem ...
ardmore: Copying BT modules to /tmp
[ 25.963903] PPP generic driver version 2.4.2
[ 26.216689] usbcore: registered new interface driver usbfs
[ 26.293950] usbcore: registered new interface driver hub
[ 26.367202] usbcore: registered new device driver usb
[ 26.498115] usbcore: registered new interface driver usbserial
[ 26.578167] USB Serial support registered for generic
[ 26.642507] usbcore: registered new interface driver usbserial_generic
[ 26.720718] usbserial: USB Serial Driver core
[ 26.896339] SCSI subsystem initialized
[ 27.180908] Initializing USB Mass Storage driver...
[ 27.251550] usbcore: registered new interface driver usb-storage
[ 27.323489] USB Mass Storage support registered.
[ 27.427615] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 27.505861] fsl-ehci fsl-ehci.0: Freescale On-Chip EHCI Host Controller
[ 27.585118] fsl-ehci fsl-ehci.0: new USB bus registered, assigned bus number 1
[ 27.694144] fsl-ehci fsl-ehci.0: irq 28, io base 0xffe22000
[ 27.768087] fsl-ehci fsl-ehci.0: USB 2.0 started, EHCI 1.00
[ 27.834829] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 27.916104] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 28.002582] usb usb1: Product: Freescale On-Chip EHCI Host Controller
[ 28.079690] usb usb1: Manufacturer: Linux 2.6.35 ehci_hcd
[ 28.144293] usb usb1: SerialNumber: fsl-ehci.0
[ 28.200813] hub 1-0:1.0: USB hub found
[ 28.245675] hub 1-0:1.0: 1 port detected
insmod: cannot i[ 28.398652] PHY: eth0 (mdio@ffe24000:00) - Link is Upnsert `/lib/ehci - 1000/Full-hcd.ko': File e
xists (-1): File exists
[ 28.583604] bonding: bond0: link status definitely up for interface eth0.
[ 28.664891] bonding: bond0: making interface eth0 the new active one.
[ 28.742048] bonding: bond0: first active interface up!
[ 28.803704] ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready
No USB Plugged i[ 48.653623] usbcore: deregistering interface driver usb-storage
n
[ 48.777214] Uniform CD-ROM driver unloaded
[ 48.885206] usbcore: deregistering interface driver usbserial_generic
[ 48.976228] USB Serial deregistering driver generic
[ 49.034916] usbcore: deregistering interface driver usbserial
Checking country code.
Ethernet uplink active. Becoming Mesh Portal
Mesh is DISABLED on this device.
extended ssid is activated on the platform ...
copying bootuplog ...
[ 53.628727] AP xml model 66, num_radios 2 (jiffies 26177)
[ 53.693367] apType 66 hw_opmode 0
[ 53.732979] radio 0: band 1 ant 0 max_ssid 16
[ 53.785086] radio 1: band 0 ant 0 max_ssid 16
[ 53.851080] init_asap_mod: installation:0
[ 53.899086] election init: rand=17 HZ=500
[ 53.947034] IAP client match init
[ 53.987248] ethernet_device_event: dev eth0 is up
[ 54.043541] ethernet_device_event: dev eth1 is up
allow PAPI
set device anul0 mtu to 2000
notify asap_mod 3g no present...
Enabling ipv6 on br0
Enabling ipv6 on loopback
apdot1x authentication is not enabled
Starting[ 54.456244] bonding: bond0: eth0 is already the current active slave.
DHCP
Getting an IP address...
Jan 1 00:00:43 udhcpc[3124]: udhcpc (v0.9.9-pre) started
Jan 1 00:00:43 udhcpc[3124]: send_discover: pkt num 0, secs 0
Jan 1 00:00:43 udhcpc[3124]: Sending discover...
Jan 1 00:00:43 udhcpc[3124]: send_selecting: pkt num 0, secs 0
Jan 1 00:00:43 udhcpc[3124]: Sending select for 172.30.11.253...
Jan 1 00:00:43 udhcpc[3124]: Lease of 172.30.11.253 obtained, lease time 43200
[ 58.954102] ip_time_handler: Got ip and packets on bond0 Started master election 13-0, rand 27
172.30.11.253 255.255.255.0 172.30.11.1
Running ADP...
Done. Master is 198.105.244.11
Compressing all files in the /etc/httpd directory...
Done.
Starting Webserver
bind: Transport endpoint is not connected
bind: Transport endpoint is not connected
bind: Transport endpoint is not connected
bind: Transport endpoint is not connected