wireless dhcp issue after upgrading WLC to 7.6.100

Josu Bagazgoitia · ‎05-16-2014

Hi All,

We have upgraded our controllers to version 7.6.100. After upgrading, the access points also upgraded their version to 15.2(4)JB3. But, the problem is that after this process the APs do not get IP. It stays on this state:

*Sep 26 03:55:36.334: %CAPWAP-3-DHCP_RENEW: Could not discover WLC using DHCP IP. Renewing DHCP IP.

Not in Bound state.

The DCHP configuration is OK, since it is working in other two controllers we have and that we are not upgrading untill this issue is solved.

If we connect the APs via console and configure a static IP and controller's IP, the AP registers and works fine. But, the access points are located in 20 remote sites, so we would like to avoid going site by site.

Has anyone suffered this issue and knows how to "recover" those access points?

Thank you very mucho for your help!

conraddaniel · ‎06-18-2014

I had the configured vlan numbers on the APs 'FlexConnect' tab disappear during a similar upgrade, could this be the case? If so your APs may be requesting a DHCP in the 'wrong' VLAN.

Josu Bagazgoitia · ‎06-18-2014

Hi,

Thank you for your answer conraddaniel.

But, our issue was an error on the DHCP. The DHCP server pool for the APs was configured with lease time infinite (on a Cisco 6500). After capturing the packets and debugging on the AP we realized that the AP were receiving wrong values:

DHCP: Scan: Renewal time: 2147483647
DHCP: Scan: Rebind time: 536870911

So, on the AP debugging we saw:

DHCP: Scan: Renewal time larger than Rebind time

On Cisco documentation:

T1 Timer(Renewal) After a certain portion of the lease time has expired, you attempt to contact the server that initially granted the lease in order to renew the lease so its IP address can still be used.

T2 Timer(Rebinding) If renewal with the original leasing server fails, because, for example, the server was taken offline, then you ideally try to rebind to any active DHCP server and try to extend its current lease with any server that allows it to do so.

These T1 and T2 timers can be any values, but must be less than the IP address lease duration. T1 Timer must be less than T2. Generally T1 is set to 50 percent of the lease duration and T2 is set to 87.5 percent of the lease duration. Use this rule to set T1 and T2 timers.

On the previous version of the WLC, the DHCP was configured in the same way and we confirmed that the APs received same times, but they ignored those wrong values.

The workaround was to modify the lease time of the DHCP pool (1 day). This way, both timers had valid values and the APs accepted the DHCP OFFER. We still do not know why with lease infinite these timers have wrong values (a bug?).

khernandezruiz · ‎07-23-2018

Checking this DHCP case issue, the reason is because the DHCP server is allocating those devices as Static and assign a large number in Renewal time and Rebind time.

My case (Autonomous AP 3502 IOS Version 15.2(4)JB6):

*Jul 8 08:05:16.088: DHCP: Try 23 to acquire address for BVI1
*Jul 8 08:05:16.088: DHCP: allocate request
*Jul 8 08:05:16.088: DHCP: new entry. add to queue, interface BVI1
*Jul 8 08:05:16.088: DHCP: Client socket is opened
*Jul 8 08:05:16.088: DHCP: SDiscover attempt # 1 for entry:
*Jul 8 08:05:16.088: Temp IP addr: 0.0.0.0 for peer on Interface: BVI1
*Jul 8 08:05:16.088: Temp sub net mask: 0.0.0.0
*Jul 8 08:05:16.088: DHCP Lease server: 0.0.0.0, state: 3 Selecting
*Jul 8 08:05:16.088: DHCP transaction id: 1D97
*Jul 8 08:05:16.088: Lease: 0 secs, Renewal: 0 secs, Rebind: 0 secs
*Jul 8 08:05:16.088: Next timer fires after: 00:00:04
*Jul 8 08:05:16.088: Retry count: 1 Client-ID: 0006.f6c8.e0d7
*Jul 8 08:05:16.088: Client-ID hex dump: 0006F6C8E0D7
*Jul 8 08:05:16.088: Hostname: ap
*Jul 8 08:05:16.088: DHCP: SDiscover placed class-id option: 436973636F204150206333353030
*Jul 8 08:05:16.088: DHCP: SDiscover: sending 287 byte length DHCP packet
*Jul 8 08:05:16.088: DHCP: SDiscover 287 bytes
*Jul 8 08:05:16.088: B'cast on BVI1 interface from 0.0.0.0
*Jul 8 08:05:16.516: DHCP: Received a BOOTREP pkt
*Jul 8 08:05:16.516: DHCP: Scan: Message type: DHCP Offer
*Jul 8 08:05:16.516: DHCP: Scan: Server ID Option: 192.168.10.10 = C0A80A0A
*Jul 8 08:05:16.516: DHCP: Scan: Lease Time: 4294967295
*Jul 8 08:05:16.516: DHCP: Scan: Renewal time: 429496729
*Jul 8 08:05:16.516: DHCP: Scan: Rebind time: 4294966
*Jul 8 08:05:16.516: DHCP: Scan: Subnet Address Option: 255.255.255.0
*Jul 8 08:05:16.516: DHCP: Scan: Renewal time larger than Rebind time
*Jul 8 08:05:16.516: DHCP: Error in pkt. punting

Eliminating the static DHCP to this Autonomus AP, received its IP Address.

*Jul 8 08:24:59.876: DHCP: SDiscover attempt # 1 for entry:
*Jul 8 08:24:59.876: Temp IP addr: 0.0.0.0 for peer on Interface: BVI1
*Jul 8 08:24:59.876: Temp sub net mask: 0.0.0.0
*Jul 8 08:24:59.876: DHCP Lease server: 0.0.0.0, state: 3 Selecting
*Jul 8 08:24:59.876: DHCP transaction id: 17B1
*Jul 8 08:24:59.876: Lease: 0 secs, Renewal: 0 secs, Rebind: 0 secs
*Jul 8 08:24:59.876: Next timer fires after: 00:00:04
*Jul 8 08:24:59.876: Retry count: 1 Client-ID: 0006.f6c8.e0d7
*Jul 8 08:24:59.876: Client-ID hex dump: 0006F6C8E0D7
*Jul 8 08:24:59.876: Hostname: ap
*Jul 8 08:24:59.876: DHCP: SDiscover placed class-id option: 436973636F204150206333353030
*Jul 8 08:24:59.876: DHCP: SDiscover: sending 287 byte length DHCP packet
*Jul 8 08:24:59.876: DHCP: SDiscover 287 bytes
*Jul 8 08:24:59.876: B'cast on BVI1 interface from 0.0.0.0
*Jul 8 08:24:59.885: DHCP: Received a BOOTREP pkt
*Jul 8 08:24:59.885: DHCP: Scan: Message type: DHCP Offer
*Jul 8 08:24:59.885: DHCP: Scan: Server ID Option: 192.168.10.10 = C0A80A0A
*Jul 8 08:24:59.885: DHCP: Scan: Lease Time: 86400
*Jul 8 08:24:59.885: DHCP: Scan: Renewal time: 43200
*Jul 8 08:24:59.885: DHCP: Scan: Rebind time: 75600
*Jul 8 08:24:59.885: DHCP: Scan: Subnet Address Option: 255.255.255.0
*Jul 8 08:24:59.885: DHCP: Scan: Router Option: 192.168.10.1
*Jul 8 08:24:59.885: DHCP: Scan: DNS Name Server Option: 192.168.10.1
*Jul 8 08:24:59.885: DHCP: Scan: Vendor specific option 43: C0A80AC9
*Jul 8 08:24:59.885: DHCP: rcvd pkt source: 192.168.10.10, destination: 255.255.255.255
*Jul 8 08:24:59.885: UDP sport: 43, dport: 44, length: 300
*Jul 8 08:24:59.885: DHCP op: 2, htype: 1, hlen: 6, hops: 0
*Jul 8 08:24:59.885: DHCP server identifier: 192.168.10.10
*Jul 8 08:24:59.885: xid: 17B1, secs: 0, flags: 8000
*Jul 8 08:24:59.885: client: 0.0.0.0, your: 192.168.10.105
*Jul 8 08:24:59.885: srvr: 0.0.0.0, gw: 0.0.0.0
*Jul 8 08:24:59.885: options block length: 52

*Jul 8 08:24:59.885: DHCP Offer Message Offered Address: 192.168.10.105
*Jul 8 08:24:59.885: DHCP: Lease Seconds: 86400 Renewal secs: 43200 Rebind secs: 75600
*Jul 8 08:24:59.885: DHCP: Server ID Option: 192.168.10.10
*Jul 8 08:24:59.885: DHCP: offer received from 192.168.10.10
*Jul 8 08:24:59.885: DHCP: SRequest attempt # 1 for entry:
*Jul 8 08:24:59.885: Temp IP addr: 192.168.10.105 for peer on Interface: BVI1
*Jul 8 08:24:59.885: Temp sub net mask: 255.255.255.0
*Jul 8 08:24:59.885: DHCP Lease server: 192.168.10.10, state: 4 Requesting
*Jul 8 08:24:59.885: DHCP transaction id: 17B1
*Jul 8 08:24:59.885: Lease: 86400 secs, Renewal: 0 secs, Rebind: 0 secs
*Jul 8 08:24:59.885: Next timer fires after: 00:00:03
*Jul 8 08:24:59.885: Retry count: 1 Client-ID: 0006.f6c8.e0d7
*Jul 8 08:24:59.885: Client-ID hex dump: 0006F6C8E0D7
*Jul 8 08:24:59.888: Hostname: ap
*Jul 8 08:24:59.888: DHCP: SRequest- Server ID option: 192.168.10.10
*Jul 8 08:24:59.888: DHCP: SRequest- Requested IP addr option: 192.168.10.105
*Jul 8 08:24:59.888: DHCP: SRequest placed class-id option: 436973636F204150206333353030
*Jul 8 08:24:59.888: DHCP: SRequest: 299 bytes
*Jul 8 08:24:59.888: DHCP: SRequest: 299 bytes
*Jul 8 08:24:59.888: B'cast on BVI1 interface from 0.0.0.0
*Jul 8 08:24:59.891: DHCP: Received a BOOTREP pkt
*Jul 8 08:24:59.891: DHCP: Scan: Message type: DHCP Ack
*Jul 8 08:24:59.891: DHCP: Scan: Server ID Option: 192.168.10.10 = C0A80A0A
*Jul 8 08:24:59.891: DHCP: Scan: Lease Time: 86400
*Jul 8 08:24:59.891: DHCP: Scan: Renewal time: 43200
*Jul 8 08:24:59.891: DHCP: Scan: Rebind time: 75600
*Jul 8 08:24:59.891: DHCP: Scan: Subnet Address Option: 255.255.255.0
*Jul 8 08:24:59.891: DHCP: Scan: Router Option: 192.168.10.1
*Jul 8 08:24:59.891: DHCP: Scan: DNS Name Server Option: 192.168.10.1
*Jul 8 08:24:59.891: DHCP: Scan: Vendor specific option 43: C0A80AC9
*Jul 8 08:24:59.891: DHCP: rcvd pkt source: 192.168.10.10, destination: 255.255.255.255
*Jul 8 08:24:59.891: UDP sport: 43, dport: 44, length: 300
*Jul 8 08:24:59.891: DHCP op: 2, htype: 1, hlen: 6, hops: 0
*Jul 8 08:24:59.891: DHCP server identifier: 192.168.10.10
*Jul 8 08:24:59.891: xid: 17B1, secs: 0, flags: 8000
*Jul 8 08:24:59.891: client: 0.0.0.0, your: 192.168.10.105
*Jul 8 08:24:59.891: srvr: 0.0.0.0, gw: 0.0.0.0
*Jul 8 08:24:59.891: options block length: 52

*Jul 8 08:24:59.891: DHCP Ack Message
*Jul 8 08:24:59.891: DHCP: Lease Seconds: 86400 Renewal secs: 43200 Rebind secs: 75600
*Jul 8 08:24:59.891: DHCP: Server ID Option: 192.168.10.10
*Jul 8 08:25:00.719: %SYS-5-CONFIG_I: Configured from console by console
*Jul 8 08:25:01.873: %LINK-6-UPDOWN: Interface BVI1, changed state to up
*Jul 8 08:25:02.873: %LINEPROTO-5-UPDOWN: Line protocol on Interface BVI1, changed state to up
*Jul 8 08:25:02.892: DHCP: Releasing ipl options:
*Jul 8 08:25:02.892: DHCP: Applying DHCP options:
*Jul 8 08:25:02.892: Setting default_gateway to 192.168.10.1
*Jul 8 08:25:02.892: Adding default route 192.168.10.1
*Jul 8 08:25:02.924: DHCPC: Notifying other components about option 43
*Jul 8 08:25:02.924: Allocated IP address = 192.168.10.105 255.255.255.0

*Jul 8 08:25:02.924: %DHCP-6-ADDRESS_ASSIGN: Interface BVI1 assigned DHCP address 192.168.10.105, mask 255.255.255.0, hostname ap