Re: Phones Unable to Obtain IP via DHCP

Joel Jackson · ‎06-01-2018

We have 7841s at branch locations that obtain addresses and TFTP info via DHCP on our branch routers. They are 4321s running: Cisco IOS Software [Everest], ISR Software (X86_64_LINUX_IOSD-UNIVERSALK9-M), Version 16.6.3, RELEASE SOFTWARE (fc8)

Sometimes the facility loses power to the whole building or their MPLS ckt goes down and when things come back up, the phones are unable to obtain IPs via DHCP. The only way to get them back online is to pull power to power cycle them.

The DHCP config is as follows:

ip dhcp excluded-address start end

ip dhcp pool Voice
 network ip mask
 default-router defaultgw
 domain-name domain.name
 dns-server dns1 dns2 dns2
 option 150 ip tftp1 tftp2

debug ip dhcp server events shows the following errors:


DHCP server event debugging is on.
Jun  1 2018 15:49:49.648 EDT: DHCPD: Reload workspace interface GigabitEthernet0/0/0.2 tableid 0.
Jun  1 2018 15:49:49.648 EDT: DHCPD: FSM state change INVALID
Jun  1 2018 15:49:49.648 EDT: DHCPD: Workspace state changed from INIT to INVALID
Jun  1 2018 15:49:49.648 EDT: DHCPD: Client either rebooted or rebinding we are seeing the client for first time
Jun  1 2018 15:49:49.648 EDT: DHCPD : Locating relay for Subnet 10.227.1.129
Jun  1 2018 15:49:49.648 EDT: DHCPD: Sending notification of ASSIGNMENT FAILURE:
Jun  1 2018 15:49:49.648 EDT:   DHCPD: htype 1 chaddr 00cc.fca6.6828
Jun  1 2018 15:49:49.648 EDT:   DHCPD: remote id 020a00000ae3018100000002
Jun  1 2018 15:49:49.648 EDT:   DHCPD: interface = GigabitEthernet0/0/0.2
Jun  1 2018 15:49:49.648 EDT:   DHCPD: class id 436973636f2053797374656d732c20496e632e2049502050686f6e652043502d3738343100
Jun  1 2018 15:49:49.648 EDT: DHCPD: Sending notification of ASSIGNMENT_FAILURE:
Jun  1 2018 15:49:49.648 EDT:  DHCPD: due to: CANT FORWARD
Jun  1 2018 15:49:49.648 EDT:   DHCPD: htype 1 chaddr 00cc.fca6.6828
Jun  1 2018 15:49:49.648 EDT:   DHCPD: remote id 020a00000ae3018100000002
Jun  1 2018 15:49:49.649 EDT:   DHCPD: interface = GigabitEthernet0/0/0.2
Jun  1 2018 15:49:49.649 EDT:   DHCPD: class id 436973636f2053797374656d732c20496e632e2049502050686f6e652043502d3738343100
Jun  1 2018 15:50:10.607 EDT: DHCPD: checking for expired leases.
Jun  1 2018 15:50:21.674 EDT: DHCPD: Reload workspace interface GigabitEthernet0/0/0.2 tableid 0.
Jun  1 2018 15:50:21.674 EDT: DHCPD: FSM state change INVALID
Jun  1 2018 15:50:21.674 EDT: DHCPD: Workspace state changed from INIT to INVALID
Jun  1 2018 15:50:21.674 EDT: DHCPD: Client either rebooted or rebinding we are seeing the client for first time
Jun  1 2018 15:50:21.674 EDT: DHCPD : Locating relay for Subnet 10.227.1.129
Jun  1 2018 15:50:21.674 EDT: DHCPD: Sending notification of ASSIGNMENT FAILURE:
Jun  1 2018 15:50:21.675 EDT:   DHCPD: htype 1 chaddr 00cc.fca6.6828
Jun  1 2018 15:50:21.675 EDT:   DHCPD: remote id 020a00000ae3018100000002
Jun  1 2018 15:50:21.675 EDT:   DHCPD: interface = GigabitEthernet0/0/0.2
Jun  1 2018 15:50:21.675 EDT:   DHCPD: class id 436973636f2053797374656d732c20496e632e2049502050686f6e652043502d3738343100
Jun  1 2018 15:50:21.675 EDT: DHCPD: Sending notification of ASSIGNMENT_FAILURE:
Jun  1 2018 15:50:21.675 EDT:  DHCPD: due to: CANT FORWARD
Jun  1 2018 15:50:21.675 EDT:   DHCPD: htype 1 chaddr 00cc.fca6.6828
Jun  1 2018 15:50:21.675 EDT:   DHCPD: remote id 020a00000ae3018100000002
Jun  1 2018 15:50:21.675 EDT:   DHCPD: interface = GigabitEthernet0/0/0.2
Jun  1 2018 15:50:21.675 EDT:   DHCPD: class id 436973636f2053797374656d732c20496e632e2049502050686f6e652043502d3738343100

I know the config is correct so I'm at a loss. Any advice would be greatly appreciated.

Georg Pauwen · ‎06-01-2018

Hello,

try and configure 'update arp' in the pool:

ip dhcp pool Voice
network ip mask
default-router defaultgw
domain-name domain.name
dns-server dns1 dns2 dns2
option 150 ip tftp1 tftp2

update arp

Joel Jackson · ‎06-01-2018

Thank you for your reply. I tried that but it did not work.

Georg Pauwen · ‎06-01-2018

Can you post the config of one of the switchports ?

Joel Jackson · ‎06-01-2018

interface GigabitEthernet1/0/12
 description Phone & PC's
 switchport mode access
 switchport voice vlan 2
 srr-queue bandwidth share 1 30 35 5
 priority-queue out
 snmp trap mac-notification change added
 snmp trap mac-notification change removed
 mls qos trust device cisco-phone
 mls qos trust cos
 auto qos voip cisco-phone
 spanning-tree portfast
 service-policy input AUTOQOS-SRND4-CISCOPHONE-POLICY

Georg Pauwen · ‎06-01-2018

Hello,

I might be overlooking something, but I do not see ' switchport access vlan x' on the port ?

Which switches are you using ?

Joel Jackson · ‎06-01-2018

We're using 2960X switches. The only thing connected to this port is the phone which would use voice vlan 2. And since the "switchport access vlan x" command is not present, access vlan 1 is implied. I feel like this is an ios bug. I'm pretty confident the config is correct. I'm still open to further troubleshooting though.

Georg Pauwen · ‎06-01-2018

Hello,

an you debug dhcp (debug dhcp detail) to see if there is any client activity reaching the switch at all ?

I'll check for bugs...which IOS version are you running on the switches ?

Joel Jackson · ‎06-04-2018

They are 4321s running: Cisco IOS Software [Everest], ISR Software (X86_64_LINUX_IOSD-UNIVERSALK9-M), Version 16.6.3, RELEASE SOFTWARE (fc8)

I see the MAC of the phone in the DHCP debugs on the router.

Edit: Misread your post. The IOS on the switches is 15.2(2)E6.

Joel Jackson · ‎06-05-2018

I reloaded the router afterhours and the issue seems to have gone away. Since that is the case it seems like this is an IOS bug. If it happens again I will contact Cisco via TAC. Strange that it would happen only at this one site. We have 40 other sites with the same IOS and hardware and never had this issue. Another troubleshooting step I did was setup the scope on our Windows DHCP server (+ a helper address) and the phones pulled IPs from that just fine so it seems like a router issue.