Wireless Access

Hi,

I am currently testing the setup of a cluster of IAPs.  I currently have a 105 and a 205 in the same cluster working perfectly with IPs 172.20.166.100 (master) and 172.20.166.101 slave.

I have tried to connect another 205 (same firmware) and I am getting strange error messages after booting, see below copied from console on boot:

Getting an IP address...
Jan 1 00:00:13 udhcpc[1589]: udhcpc (v0.9.9-pre) started
Jan 1 00:00:13 udhcpc[1589]: send_discover: pkt num 0, secs 0
Jan 1 00:00:13 udhcpc[1589]: Sending discover...
Jan 1 00:00:15 udhcpc[1589]: send_discover: pkt num 1, secs 512
Jan 1 00:00:15 udhcpc[1589]: Sending discover...
Jan 1 00:00:17 udhcpc[1589]: send_discover: pkt num 2, secs 1024
Jan 1 00:00:17 udhcpc[1589]: Sending discover...
Jan 1 00:00:19 udhcpc[1589]: No lease, forking to background.
Jan 1 00:00:39 udhcpc[1701]: send_discover: pkt num 0, secs 6656
Jan 1 00:00:39 udhcpc[1701]: Sending discover...
Jan 1 00:00:41 udhcpc[1701]: send_discover: pkt num 1, secs 7168
Jan 1 00:00:41 udhcpc[1701]: Sending discover...
Jan 1 00:00:43 udhcpc[1701]: send_discover: pkt num 2, secs 7680
Jan 1 00:00:43 udhcpc[1701]: Sending discover...
Jan 1 00:01:05 udhcpc[1701]: send_discover: pkt num 0, secs 13312
Jan 1 00:01:05 udhcpc[1701]: Sending discover...
Jan 1 00:01:07 udhcpc[1701]: send_discover: pkt num 1, secs 13824
Jan 1 00:01:07 udhcpc[1701]: Sending discover...
Jan 1 00:01:09 udhcpc[1701]: send_discover: pkt num 2, secs 14336
Jan 1 00:01:09 udhcpc[1701]: Sending discover...
Jan 1 00:01:31 udhcpc[1701]: send_discover: pkt num 0, secs 19968
Jan 1 00:01:31 udhcpc[1701]: Sending discover...
Jan 1 00:01:33 udhcpc[1701]: send_discover: pkt num 1, secs 20480
Jan 1 00:01:33 udhcpc[1701]: Sending discover...
Jan 1 00:01:35 udhcpc[1701]: send_discover: pkt num 2, secs 20992
Jan 1 00:01:35 udhcpc[1701]: Sending discover...
[ 110.018000] Picked up default IP a9fed91c, rand d91c
[ 115.028000] Default IP is ready
Jan 1 00:01:57 udhcpc[1701]: send_discover: pkt num 0, secs 26624
Jan 1 00:01:57 udhcpc[1701]: Sending discover...
Jan 1 00:01:59 udhcpc[1701]: send_discover: pkt num 1, secs 27136
Jan 1 00:01:59 udhcpc[1701]: Sending discover...
Jan 1 00:02:01 udhcpc[1701]: send_discover: pkt num 2, secs 27648
Jan 1 00:02:01 udhcpc[1701]: Sending discover...
DHCP timed out.
Installing default ip.
Default IP comes up.
[ 148.094000] ip_time_handler: Got ip and packets on bond0 Started master election 3579-0, rand 18
[ 148.354000] (08:02:21) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 148.354000]
DHCP timed out.
DHCP got ip address.
169.254.217.28 255.255.0.0
Compressing all files in the /etc/httpd directory...
[ 149.142000] notify cli0 to reboot system
[ 149.170000] (08:02:22) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 149.170000]
Jan 1 00:02:23 udhcpc[1701]: send_discover: pkt num 0, secs 33280
Jan 1 00:02:23 udhcpc[1701]: Sending discover...
[ 150.030000] (08:02:23) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 150.030000]
[ 150.890000] (08:02:24) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 150.890000]
Jan 1 00:02:25 udhcpc[1701]: send_discover: pkt num 1, secs 33792
Jan 1 00:02:25 udhcpc[1701]: Sending discover...
[ 151.750000] (08:02:25) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 151.750000]
[ 152.610000] (08:02:26) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 152.610000]
Jan 1 00:02:27 udhcpc[1701]: send_discover: pkt num 2, secs 34304
Jan 1 00:02:27 udhcpc[1701]: Sending discover...
[ 153.470000] (08:02:27) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 153.470000]
Done.
Starting Webserver
[ 154.330000] (08:02:28) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 154.330000]
bind: Transport endpoint is not connected
bind: Transport endpoint is not connected
bind: Transport endpoint is not connected
Launching NTP Client on pool.ntp.org
[ 155.276000] (08:02:30) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 155.276000]
[ 155.278000] (08:02:30) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 155.278000]
[ 155.292000] wifi0: AP type AP-205, radio 0, max_bssids 16
[ 155.368000] wifi1: AP type AP-205, radio 1, max_bssids 16
[ 155.432000] busybox used greatest stack depth: 5336 bytes left
[ 155.718000] (08:02:30) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 155.718000]
Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
shutting down watchdog process (nanny will restart it)...
[ 156.578000] (08:02:31) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 156.578000]

<<<<< W[ 157.438000] (08:02:32) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 157.438000]
elcome to the Access Point >>>>>

Completed SW FIPS KAT test
User: [ 158.296000] (08:02:33) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 158.296000]
[ 159.156000] (08:02:34) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 159.156000]
[ 159.288000] notify cli0 to reboot system
[ 159.972000] (08:02:35) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 159.972000]
[ 160.832000] (08:02:36) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 160.832000]
[ 161.692000] (08:02:37) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 161.692000]
[ 163.482000] (08:02:39) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 163.482000]
[ 163.486000] (08:02:40) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 163.486000]
[ 164.272000] (08:02:40) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 164.272000]
[ 165.526000] (08:02:42) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 165.526000]
[ 165.992000] (08:02:42) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 165.992000]
[ 166.852000] (08:02:43) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 166.852000]

[ 173.548000]
[ 174.146000] i am master now
[ 174.148000] (08:02:52) !!! Init ---> Master
[ 174.150000] asap_send_elected_master: sent successfully
[ 174.268000] (08:02:52) OOPS. someone else thinks he is the master too, beacon version 4 from 40:e3:d6:ce:f5:48 172.20.166.100 bond0
[ 174.270000] (08:02:53) I am MASTER. recv-ed a master normal-beacon.
[ 174.272000] (08:02:53) master provision, 0 vs. 0
[ 174.274000] (08:02:53) !!! Election result, -5
[ 174.950000] (08:02:53) OOPS. someone else thinks he is the master too, beacon version 4 from 40:e3:d6:ce:f5:48 172.20.166.100 bond0
[ 174.952000] (08:02:54) I am MASTER. recv-ed a master normal-beacon.
[ 174.954000] (08:02:54) master provision, 0 vs. 0
The sys[ 178.684000] asap_mob_pkt_rcv: 13 callbacks suppressed
[ 178.686000] (08:02:57) OOPS. someone else thinks he is the master too, beacon version 4 from 40:e3:d6:ce:f5:48 172.20.166.100 bond0
[ 178.688000] (08:02:58) I am MASTER. recv-ed a master normal-beacon.
[ 178.690000] (08:02:58) master provision, 0 vs. 0
[ 178.694000] (08:02:58) !!! Election result, -5
Sending SIGKILL to all processes.
[ 179.310000] (08:02:58) OOPS. someone else thinks he is the master too, beacon version 4 from 40:e3:d6:ce:f5:48 172.20.166.100 bond0
[ 179.312000] (08:02:59) I am MASTER. recv-ed a master normal-beacon.
[ 179.314000] (08:02:59) master provision, 0 vs. 0
[ 179.316000] (08:02:59) !!! Election result, -5
[ 179.582000] Timed out trying to marshall reboot through user process, rebooting system directly
[ 180.096000] Restarting system.

Anyone any ideas why it is doing this?

Thanks

Hi,

It looks like the AP is not getting an IP address through DHCP (We can see some DHCP issues in the logs)

HTH

Any ideas why it wouldn't be whenever the other APs are getting an IP?

I can hard set this IP (172.20.166.102) via console but it always resets on reboot

I would check the port configuration on the switch and compare to the port config where the other APs are connected to (it should be the same)

HTH

Kevin

As kevin_pm mentioned, the IAP is not able to obtain an IP address as a result a self assigned IP is being used.

[ 148.354000] (08:02:21) Rebooting AP due to default-ip is denied in this network (40:e3:d6:ce:f5:48 172.20.166.100)
[ 148.354000]
DHCP timed out.
DHCP got ip address.
169.254.217.28 255.255.0.0

Can you confirm the switch port is correct and all the IAP's are in the same broadcast domain? Can you confirm the VC is also configured to allow auto-join from other IAP's?

How do I confirm that it is set to Auto-Join?

Although on saying that I have connected another AP which did join with 172.20.166.101

I would check the DHCP server, check logs, to tcpdump/wireshark if the DHCP packet is coming in.

Could maybe the DHCP pool be empty (all possible IP addresses given)?

On ArubaOS switches, might you have enabled dhcp-snooping or any other technology that may prevent the dhcp response to be dropped?

Are you using a tagged management VLAN in your cluster or in the AP that you are trying to connect? If so, try to get rid of that and make management on the native VLAN. It looks good, given that you see rejects from 172.20.166.100, which suggests you are in the right VLAN.

As last resort, mirror the traffic on the AP port and see if DHCP is working properly.

For the AP to get an IP i had statically assigned these however even on reset this IP doesnt come up with "instant" so i cannot connect and then assign an IP to it.  This is the part which is confusing me

Here's how you configure auto-join

http://www.arubanetworks.com/techdocs/Instant_41_Mobile/Advanced/Content/UG_files/GeneralConfTasks/Adv_conf_tasks/ConfigureAutoJoinMode.htm

Can you confirm there is no DHCP issues with this particular client, if you can set up the port mirror I expect you might see a DHCPNack

Ok so I have now managed to statically assign this IAP an AP and it comes up (sort of) on 172.20.166.102 however it is showing:

[ 87.090000] (08:01:24) !!! Init ---> Slave
[ 87.926000] turn off mobility
[ 88.012000] (08:01:25) !!! Init ---> Slave
[ 88.952000] turn off mobility
[ 88.956000] (08:01:26) !!! Init ---> Slave
[ 89.948000] turn off mobility
[ 90.856000] (08:01:28) !!! Init ---> Slave
[ 90.962000] turn off mobility
[ 91.778000] (08:01:29) !!! Init ---> Slave
[ 91.988000] turn off mobility
[ 92.700000] (08:01:30) !!! Init ---> Slave
[ 93.016000] turn off mobility

When I browse to the 172.20.166.102 address it redirects me to 172.20.166.100 the master IP but it only shows the other 2 APs in the cluster, this one is not showing?

Never mind looks like this part number is not an instant ap - but thanks everyone for the replies as I did manage (finally) to get the AP an IP which made it come up.  If it was an IAP it would be working now.  Looks like one problem is solved :)