Cisco doesn't respect RFC 2131 : New info about C2611 as a DHCP client

I post a few weeks ago about pb with a cisco 2611 can't renewing it's ISP renewal adress... The ISP made an upgrade of the firmware of his ADSL modem but now , it take a while (9 minutes) to the connection to be establish after the router take a new ip...

The isp told me that the Cisco don't respect the RFC 2131 because the DHCP NAK field must not contain the field "Requested IP address". And then , the ISP thinks that the Cisco drop the packet and wait until the lease end, then it does a new init of the interface and then can take the new dynamic ip

Here is the log... Take a look of the DHCP NAK lines : DHCP: Nak.. not our requested addr. punt

What do you think of it ?

Thanks of your help Hardware : Cisco 2611 (not the XM one) , IOS 12.3 (6c)

2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488586: 1w1d: DHCP: QScan: Bound..T1 fired..Renewing 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488587: 1w1d: DHCP: SRequest attempt # 1 for entry: 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488588: 1w1d: Temp IP addr: 82.252.128.220 for peer on Interface: Ethernet0/1 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488589: 1w1d: Temp sub net mask: 255.255.255.0 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488590: 1w1d: DHCP Lease server: 82.252.128.254, state: 5 Renewing 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488591: 1w1d: DHCP transaction id: 5A02 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488592: 1w1d: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488593: 1w1d: Temp default-gateway addr: 82.252.128.254 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488594: 1w1d: Next timer fires after: 00:01:59 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488595: 1w1d: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488596: 1w1d: Hostname: toto.free.fr 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488597: 1w1d: DHCP: SRequest - ciaddr: 82.252.128.220 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488598: 1w1d: DHCP: SRequest placed lease len option: 600 2005-05-18 20:16:39 Local7.Debug 192.168.0.244 488599: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488600: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488601: 1w1d: DHCP: Received a BOOTREP pkt 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488602: 1w1d: DHCP: Scan: Message type: DHCP Nak 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488603: 1w1d: DHCP: Scan: Server ID Option: 82.252.128.254 = 52FC80FE 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488604: 1w1d: DHCP: rcvd pkt source: 82.252.128.254, destination: 82.252.128.220 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488605: 1w1d: UDP sport: 43, dport: 44, length: 556 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488606: 1w1d: DHCP op: 2, htype: 1, hlen: 6, hops: 0 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488607: 1w1d: DHCP server identifier: 82.252.128.254 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488608: 1w1d: xid: 5A02, secs: 0, flags: 0 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488609: 1w1d: client: 0.0.0.0, your: 0.0.0.0 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488610: 1w1d: srvr: 0.0.0.0, gw: 0.0.0.0 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488611: 1w1d: options block length: 308 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488612: 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488613: 1w1d: DHCP Nak Message 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488614: 1w1d: DHCP: Server ID Option: 82.252.128.254 2005-05-18 20:16:40 Local7.Debug 192.168.0.244 488615: 1w1d: DHCP: Nak.. not our requested addr. punt 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488616: 1w1d: DHCP: QScan: Renewal..T2 fired..Rebinding 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488617: 1w1d: DHCP: SRequest attempt # 1 for entry: 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488618: 1w1d: Temp IP addr: 82.252.128.220 for peer on Interface: Ethernet0/1 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488619: 1w1d: Temp sub net mask: 255.255.255.0 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488620: 1w1d: DHCP Lease server: 82.252.128.254, state: 4 Rebinding 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488621: 1w1d: DHCP transaction id: 5A02 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488622: 1w1d: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488623: 1w1d: Temp default-gateway addr: 82.252.128.254 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488624: 1w1d: Next timer fires after: 00:06:59 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488625: 1w1d: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488626: 1w1d: Hostname: toto.free.fr 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488627: 1w1d: DHCP: SRequest - ciaddr: 82.252.128.220 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488628: 1w1d: DHCP: SRequest placed lease len option: 600 2005-05-18 20:18:39 Local7.Debug 192.168.0.244 488629: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488630: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488631: 1w1d: DHCP: Received a BOOTREP pkt 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488632: 1w1d: DHCP: Scan: Message type: DHCP Nak 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488633: 1w1d: DHCP: Scan: Server ID Option: 82.252.128.254 = 52FC80FE 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488634: 1w1d: DHCP: rcvd pkt source: 82.252.128.254, destination: 82.252.128.220 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488635: 1w1d: UDP sport: 43, dport: 44, length: 556 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488636: 1w1d: DHCP op: 2, htype: 1, hlen: 6, hops: 0 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488637: 1w1d: DHCP server identifier: 82.252.128.254 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488638: 1w1d: xid: 5A02, secs: 0, flags: 0 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488639: 1w1d: client: 0.0.0.0, your: 0.0.0.0 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488640: 1w1d: srvr: 0.0.0.0, gw: 0.0.0.0 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488641: 1w1d: options block length: 308 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488642: 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488643: 1w1d: DHCP Nak Message 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488644: 1w1d: DHCP: Server ID Option: 82.252.128.254 2005-05-18 20:18:40 Local7.Debug 192.168.0.244 488645: 1w1d: DHCP: Nak.. not our requested addr. punt 2005-05-18 20:25:40 Local7.Debug 192.168.0.244 488646: 1w1d: DHCP: QScan: Rebind..LT fired..Halting 2005-05-18 20:25:40 Local7.Debug 192.168.0.244 488647: 1w1d: DHCP: Address lease expired. Attempting Shutdown 2005-05-18 20:25:40 Local7.Debug 192.168.0.244 488648: 1w1d: RAC: DHCP stopped on interface Ethernet0/1 2005-05-18 20:25:42 Local7.Notice 192.168.0.244 488649: 1w1d: %LINK-5-CHANGED: Interface Ethernet0/1, changed state to administratively down 2005-05-18 20:25:42 Local7.Notice 192.168.0.244 488650: 1w1d: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0/1, changed state to down 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488651: 1w1d: DHCP: DHCP client process started: 10 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488652: 1w1d: RAC: Starting DHCP discover on Ethernet0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488653: 1w1d: DHCP: Try 1 to acquire address for Ethernet0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488654: 1w1d: DHCP: allocate request 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488655: 1w1d: DHCP: zapping entry in DHC_PURGING state for Et0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488656: 1w1d: DHCP: new entry. add to queue 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488657: 1w1d: DHCP: SDiscover attempt # 1 for entry: 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488658: 1w1d: Temp IP addr: 0.0.0.0 for peer on Interface: Ethernet0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488659: 1w1d: Temp sub net mask: 0.0.0.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488660: 1w1d: DHCP Lease server: 0.0.0.0, state: 1 Selecting 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488661: 1w1d: DHCP transaction id: 29AD518C 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488662: 1w1d: Lease: 0 secs, Renewal: 0 secs, Rebind: 0 secs 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488663: 1w1d: Next timer fires after: 00:00:02 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488664: 1w1d: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488665: 1w1d: Hostname: toto.free.fr 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488666: 1w1d: DHCP: SDiscover: sending 304 byte length DHCP packet 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488667: 1w1d: DHCP: SDiscover 304 bytes 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488668: 1w1d: B'cast on Ethernet0/1 interface from 0.0.0.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488669: 1w1d: DHCP: Received a BOOTREP pkt 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488670: 1w1d: DHCP: Scan: Message type: DHCP Offer 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488671: 1w1d: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488672: 1w1d: DHCP: Scan: Renewal time: 60 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488673: 1w1d: DHCP: Scan: Rebind time: 180 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488674: 1w1d: DHCP: Scan: Lease Time: 600 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488675: 1w1d: DHCP: Scan: Subnet Address Option: 255.255.255.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488676: 1w1d: DHCP: Scan: Router Option: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488677: 1w1d: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488678: 1w1d: DHCP: rcvd pkt source: 82.252.148.254, destination: 255.255.255.255 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488679: 1w1d: UDP sport: 43, dport: 44, length: 556 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488680: 1w1d: DHCP op: 2, htype: 1, hlen: 6, hops: 0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488681: 1w1d: DHCP server identifier: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488682: 1w1d: xid: 29AD518C, secs: 0, flags: 0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488683: 1w1d: client: 0.0.0.0, your: 82.252.148.168 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488684: 1w1d: srvr: 82.252.148.254, gw: 0.0.0.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488685: 1w1d: options block length: 308 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488686: 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488687: 1w1d: DHCP Offer Message Offered Address: 82.252.148.168 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488688: 1w1d: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488689: 1w1d: DHCP: Server ID Option: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488690: 1w1d: DHCP: offer received from 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488691: 1w1d: DHCP: SRequest attempt # 1 for entry: 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488692: 1w1d: Temp IP addr: 82.252.148.168 for peer on Interface: Ethernet0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488693: 1w1d: Temp sub net mask: 255.255.255.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488694: 1w1d: DHCP Lease server: 82.252.148.254, state: 2 Requesting 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488695: 1w1d: DHCP transaction id: 29AD518C 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488696: 1w1d: Lease: 600 secs, Renewal: 0 secs, Rebind: 0 secs 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488697: 1w1d: Next timer fires after: 00:00:01 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488698: 1w1d: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488699: 1w1d: Hostname: toto.free.fr 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488700: 1w1d: DHCP: SRequest- Server ID option: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488701: 1w1d: DHCP: SRequest- Requested IP addr option: 82.252.148.168 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488702: 1w1d: DHCP: SRequest placed lease len option: 600 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488703: 1w1d: DHCP: SRequest: 322 bytes 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488704: 1w1d: DHCP: SRequest: 322 bytes 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488705: 1w1d: B'cast on Ethernet0/1 interface from 0.0.0.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488706: 1w1d: DHCP: Received a BOOTREP pkt 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488707: 1w1d: DHCP: Scan: Message type: DHCP Ack 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488708: 1w1d: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488709: 1w1d: DHCP: Scan: Renewal time: 60 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488710: 1w1d: DHCP: Scan: Rebind time: 180 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488711: 1w1d: DHCP: Scan: Lease Time: 600 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488712: 1w1d: DHCP: Scan: Subnet Address Option: 255.255.255.0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488713: 1w1d: DHCP: Scan: Router Option: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488714: 1w1d: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488715: 1w1d: DHCP: rcvd pkt source: 82.252.148.254, destination: 255.255.255.255 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488716: 1w1d: UDP sport: 43, dport: 44, length: 556 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488717: 1w1d: DHCP op: 2, htype: 1, hlen: 6, hops: 0 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488718: 1w1d: DHCP server identifier: 82.252.148.254 2005-05-18 20:25:43 Local7.Debug 192.168.0.244 488719: 1w1d: xid: 29AD518C, secs: 0, flags: 0 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488720: 1w1d: client: 0.0.0.0, your: 82.252.148.168 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488721: 1w1d: srvr: 82.252.148.254, gw: 0.0.0.0 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488722: 1w1d: options block length: 308 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488723: 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488724: 1w1d: DHCP Ack Message 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488725: 1w1d: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 2005-05-18 20:25:44 Local7.Debug 192.168.0.244 488726: 1w1d: DHCP: Server ID Option: 82.252.148.254 2005-05-18 20:25:46 Local7.Error 192.168.0.244 488727: 1w1d: %LINK-3-UPDOWN: Interface Ethernet0/1, changed state to up 2005-05-18 20:25:46 Local7.Notice 192.168.0.244 488728: 1w1d: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0/1, changed state to up 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488729: 1w1d: DHCP: Applying DHCP options: 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488730: 1w1d: DHCP: Releasing ipl options: 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488731: 1w1d: Setting default_gateway to 82.252.148.254 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488732: 1w1d: Adding default route 82.252.148.254 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488733: 1w1d: Adding DNS server address 213.228.0.212 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488734: 1w1d: Adding DNS server address 212.27.32.177 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488735: 1w1d: DHCP Client Pooling: ***Allocated IP address: 82.252.148.168 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488736: 1w1d: Allocated IP address = 82.252.148.168 255.255.255.0 2005-05-18 20:25:46 Local7.Debug 192.168.0.244 488737: 2005-05-18 20:25:47 Local7.Info 192.168.0.244 488738: 1w1d: %DHCP-6-ADDRESS_ASSIGN: Interface Ethernet0/1 assigned DHCP address 82.252.148.168, mask 255.255.255.0, hostname toto.free.fr 2005-05-18 20:25:47 Local7.Info 192.168.0.244 488739: 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488740: 1w1d: DHCP: QScan: Purging entry 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488741: 1w1d: DHCP: deleting entry 8171A69C 0.0.0.0 from list 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488742: 1w1d: Temp IP addr: 0.0.0.0 for peer on Interface: unknown 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488743: 1w1d: Temp sub net mask: 255.255.255.0 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488744: 1w1d: DHCP Lease server: 82.252.128.254, state: 8 Purging 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488745: 1w1d: DHCP transaction id: 5A02 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488746: 1w1d: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488747: 1w1d: No timer running 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488748: 1w1d: Retry count: 0 Client-ID: 2005-05-18 20:26:10 Local7.Debug 192.168.0.244 488749: 1w1d: Hostname: toto.free.fr 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488750: 1w1d: DHCP: QScan: Bound..T1 fired..Renewing 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488751: 1w1d: DHCP: SRequest attempt # 1 for entry: 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488752: 1w1d: Temp IP addr: 82.252.148.168 for peer on Interface: Ethernet0/1 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488753: 1w1d: Temp sub net mask: 255.255.255.0 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488754: 1w1d: DHCP Lease server: 82.252.148.254, state: 5 Renewing 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488755: 1w1d: DHCP transaction id: 29AD518C 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488756: 1w1d: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488757: 1w1d: Temp default-gateway addr: 82.252.148.254 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488758: 1w1d: Next timer fires after: 00:01:59 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488759: 1w1d: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488760: 1w1d: Hostname: toto.free.fr 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488761: 1w1d: DHCP: SRequest - ciaddr: 82.252.148.168 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488762: 1w1d: DHCP: SRequest placed lease len option: 600 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488763: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488764: 1w1d: DHCP: SRequest: 310 bytes 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488765: 1w1d: DHCP: Received a BOOTREP pkt 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488766: 1w1d: DHCP: Scan: Message type: DHCP Ack 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488767: 1w1d: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488768: 1w1d: DHCP: Scan: Renewal time: 60 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488769: 1w1d: DHCP: Scan: Rebind time: 180 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488770: 1w1d: DHCP: Scan: Lease Time: 600 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488771: 1w1d: DHCP: Scan: Subnet Address Option: 255.255.255.0 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488772: 1w1d: DHCP: Scan: Router Option: 82.252.148.254 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488773: 1w1d: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488774: 1w1d: DHCP: rcvd pkt source: 82.252.148.254, destination: 82.252.148.168 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488775: 1w1d: UDP sport: 43, dport: 44, length: 556 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488776: 1w1d: DHCP op: 2, htype: 1, hlen: 6, hops: 0 2005-05-18 20:26:46 Local7.Debug 192.168.0.244 488777: 1w1d: DHCP server identifier: 82.252.148.254 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488778: 1w1d: xid: 29AD518C, secs: 0, flags: 0 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488779: 1w1d: client: 0.0.0.0, your: 82.252.148.168 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488780: 1w1d: srvr: 82.252.148.254, gw: 0.0.0.0 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488781: 1w1d: options block length: 308 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488782: 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488783: 1w1d: DHCP Ack Message 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488784: 1w1d: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488785: 1w1d: DHCP: Server ID Option: 82.252.148.254 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488786: 1w1d: DHCP: Applying DHCP options: 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488787: 1w1d: DHCP: Releasing ipl options: 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488788: 1w1d: Setting default_gateway to 82.252.148.254 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488789: 1w1d: Adding DNS server address 213.228.0.212 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488790: 1w1d: Adding DNS server address 212.27.32.177 2005-05-18 20:26:47 Local7.Debug 192.168.0.244 488791: 1w1d: DHCP Client Pooling: ***Allocated IP address: 82.252.148.168
Reply to
sam
Loading thread data ...

Well!

I am not an expert on DHCP however I have had a look.

Sending this log file without significant explanation to a newsgroup is a big shot in the dark. If you have worked out anything about the data please let us know. It would also have been an idea to have re-formatted the log so that it is possible to read it.

The cisco router is I understand DHCP Client.

According to RFC2131 DHCPNAK is only sent by a DHCP server. Your ISP then seems to be confused.

ISP says: "DHCP NAK field must not contain the field "Requested IP address"."

I say that if this is a problem (well I haven't worked out that level of detail) then the source is most likely at the ISP since the ISP's DHCP Server is sending the faulty packet.

One example of a NAK given in the RFC is that a client attempts to renew it's address from a different server than the one which issued the address. Does the ISP have more than one DHCP server?

I would get a packet sniffer on this network to see exactly what was being sent. The Cisco debug messages make little sense to me. I am now a convert to Ethereal.

Cleaned up log follows. Nothing deleted, just made easier (well possible for me) to read.

20:16:39 586: DHCP: QScan: Bound..T1 fired..Renewing 20:16:39 587: DHCP: SRequest attempt # 1 for entry: 20:16:39 588: Temp IP addr: 82.252.128.220 for peer on Interface: Ethernet0/1 20:16:39 589: Temp sub net mask: 255.255.255.0 20:16:39 590: DHCP Lease server: 82.252.128.254, state: 5 Renewing 20:16:39 591: DHCP transaction id: 5A02 20:16:39 592: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 20:16:39 593: Temp default-gateway addr: 82.252.128.254 20:16:39 594: Next timer fires after: 00:01:59 20:16:39 595: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 20:16:39 596: Hostname: toto.free.fr 20:16:39 597: DHCP: SRequest - ciaddr: 82.252.128.220 20:16:39 598: DHCP: SRequest placed lease len option: 600 20:16:39 599: DHCP: SRequest: 310 bytes 20:16:40 600: DHCP: SRequest: 310 bytes 20:16:40 601: DHCP: Received a BOOTREP pkt 20:16:40 602: DHCP: Scan: Message type: DHCP Nak 20:16:40 603: DHCP: Scan: Server ID Option: 82.252.128.254 = 52FC80FE 20:16:40 604: DHCP: rcvd pkt source: 82.252.128.254, destination: 82.252.128.220 20:16:40 605: UDP sport: 43, dport: 44, length: 556 20:16:40 606: DHCP op: 2, htype: 1, hlen: 6, hops: 0 20:16:40 607: DHCP server identifier: 82.252.128.254 20:16:40 608: xid: 5A02, secs: 0, flags: 0 20:16:40 609: client: 0.0.0.0, your: 0.0.0.0 20:16:40 610: srvr: 0.0.0.0, gw: 0.0.0.0 20:16:40 611: options block length: 308 20:16:40 612: 20:16:40 613: DHCP Nak Message 20:16:40 614: DHCP: Server ID Option: 82.252.128.254 20:16:40 615: DHCP: Nak.. not our requested addr. punt ======== 2m delay =========== 20:18:39 616: DHCP: QScan: Renewal..T2 fired..Rebinding 20:18:39 617: DHCP: SRequest attempt # 1 for entry: 20:18:39 618: Temp IP addr: 82.252.128.220 for peer on Interface: Ethernet0/1 20:18:39 619: Temp sub net mask: 255.255.255.0 20:18:39 620: DHCP Lease server: 82.252.128.254, state: 4 Rebinding 20:18:39 621: DHCP transaction id: 5A02 20:18:39 622: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 20:18:39 623: Temp default-gateway addr: 82.252.128.254 20:18:39 624: Next timer fires after: 00:06:59 20:18:39 625: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 20:18:39 626: Hostname: toto.free.fr 20:18:39 627: DHCP: SRequest - ciaddr: 82.252.128.220 20:18:39 628: DHCP: SRequest placed lease len option: 600 20:18:39 629: DHCP: SRequest: 310 bytes 20:18:40 630: DHCP: SRequest: 310 bytes 20:18:40 631: DHCP: Received a BOOTREP pkt 20:18:40 632: DHCP: Scan: Message type: DHCP Nak 20:18:40 633: DHCP: Scan: Server ID Option: 82.252.128.254 = 52FC80FE 20:18:40 634: DHCP: rcvd pkt source: 82.252.128.254, destination: 82.252.128.220 20:18:40 635: UDP sport: 43, dport: 44, length: 556 20:18:40 636: DHCP op: 2, htype: 1, hlen: 6, hops: 0 20:18:40 637: DHCP server identifier: 82.252.128.254 20:18:40 638: xid: 5A02, secs: 0, flags: 0 20:18:40 639: client: 0.0.0.0, your: 0.0.0.0 20:18:40 640: srvr: 0.0.0.0, gw: 0.0.0.0 20:18:40 641: options block length: 308 20:18:40 642: 20:18:40 643: DHCP Nak Message 20:18:40 644: DHCP: Server ID Option: 82.252.128.254 20:18:40 645: DHCP: Nak.. not our requested addr. punt =================== 20:25:40 646: DHCP: QScan: Rebind..LT fired..Halting 20:25:40 647: DHCP: Address lease expired. Attempting Shutdown 20:25:40 648: RAC: DHCP stopped on interface Ethernet0/1 20:25:42 Local7.Notice 192.168.0.244 488649: %LINK-5-CHANGED: Interface Ethernet0/1, changed state to administratively down 20:25:42 Local7.Notice 192.168.0.244 488650: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0/1, changed state to down 20:25:43 651: DHCP: DHCP client process started: 10 20:25:43 652: RAC: Starting DHCP discover on Ethernet0/1 20:25:43 653: DHCP: Try 1 to acquire address for Ethernet0/1 20:25:43 654: DHCP: allocate request 20:25:43 655: DHCP: zapping entry in DHC_PURGING state for Et0/1 20:25:43 656: DHCP: new entry. add to queue 20:25:43 657: DHCP: SDiscover attempt # 1 for entry: 20:25:43 658: Temp IP addr: 0.0.0.0 for peer on Interface: Ethernet0/1

20:25:43 659: Temp sub net mask: 0.0.0.0

20:25:43 660: DHCP Lease server: 0.0.0.0, state: 1 Selecting 20:25:43 661: DHCP transaction id: 29AD518C 20:25:43 662: Lease: 0 secs, Renewal: 0 secs, Rebind: 0 secs 20:25:43 663: Next timer fires after: 00:00:02 20:25:43 664: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 20:25:43 665: Hostname: toto.free.fr 20:25:43 666: DHCP: SDiscover: sending 304 byte length DHCP packet 20:25:43 667: DHCP: SDiscover 304 bytes 20:25:43 668: B'cast on Ethernet0/1 interface from 0.0.0.0 20:25:43 669: DHCP: Received a BOOTREP pkt 20:25:43 670: DHCP: Scan: Message type: DHCP Offer 20:25:43 671: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 20:25:43 672: DHCP: Scan: Renewal time: 60 20:25:43 673: DHCP: Scan: Rebind time: 180 20:25:43 674: DHCP: Scan: Lease Time: 600 20:25:43 675: DHCP: Scan: Subnet Address Option: 255.255.255.0 20:25:43 676: DHCP: Scan: Router Option: 82.252.148.254 20:25:43 677: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 20:25:43 678: DHCP: rcvd pkt source: 82.252.148.254, destination: 255.255.255.255 20:25:43 679: UDP sport: 43, dport: 44, length: 556 20:25:43 680: DHCP op: 2, htype: 1, hlen: 6, hops: 0 20:25:43 681: DHCP server identifier: 82.252.148.254 20:25:43 682: xid: 29AD518C, secs: 0, flags: 0 20:25:43 683: client: 0.0.0.0, your: 82.252.148.168 20:25:43 684: srvr: 82.252.148.254, gw: 0.0.0.0 20:25:43 685: options block length: 308 20:25:43 686: 20:25:43 687: DHCP Offer Message Offered Address: 82.252.148.168 20:25:43 688: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 20:25:43 689: DHCP: Server ID Option: 82.252.148.254 20:25:43 690: DHCP: offer received from 82.252.148.254 20:25:43 691: DHCP: SRequest attempt # 1 for entry: 20:25:43 692: Temp IP addr: 82.252.148.168 for peer on Interface: Ethernet0/1 20:25:43 693: Temp sub net mask: 255.255.255.0 20:25:43 694: DHCP Lease server: 82.252.148.254, state: 2 Requesting 20:25:43 695: DHCP transaction id: 29AD518C 20:25:43 696: Lease: 600 secs, Renewal: 0 secs, Rebind: 0 secs 20:25:43 697: Next timer fires after: 00:00:01 20:25:43 698: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 20:25:43 699: Hostname: toto.free.fr 20:25:43 700: DHCP: SRequest- Server ID option: 82.252.148.254 20:25:43 701: DHCP: SRequest- Requested IP addr option: 82.252.148.168 20:25:43 702: DHCP: SRequest placed lease len option: 600 20:25:43 703: DHCP: SRequest: 322 bytes 20:25:43 704: DHCP: SRequest: 322 bytes 20:25:43 705: B'cast on Ethernet0/1 interface from 0.0.0.0 20:25:43 706: DHCP: Received a BOOTREP pkt 20:25:43 707: DHCP: Scan: Message type: DHCP Ack 20:25:43 708: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 20:25:43 709: DHCP: Scan: Renewal time: 60 20:25:43 710: DHCP: Scan: Rebind time: 180 20:25:43 711: DHCP: Scan: Lease Time: 600 20:25:43 712: DHCP: Scan: Subnet Address Option: 255.255.255.0 20:25:43 713: DHCP: Scan: Router Option: 82.252.148.254 20:25:43 714: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 20:25:43 715: DHCP: rcvd pkt source: 82.252.148.254, destination: 255.255.255.255 20:25:43 716: UDP sport: 43, dport: 44, length: 556 20:25:43 717: DHCP op: 2, htype: 1, hlen: 6, hops: 0 20:25:43 718: DHCP server identifier: 82.252.148.254 20:25:43 719: xid: 29AD518C, secs: 0, flags: 0 20:25:44 720: client: 0.0.0.0, your: 82.252.148.168 20:25:44 721: srvr: 82.252.148.254, gw: 0.0.0.0 20:25:44 722: options block length: 308 20:25:44 723: 20:25:44 724: DHCP Ack Message 20:25:44 725: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 20:25:44 726: DHCP: Server ID Option: 82.252.148.254 20:25:46 Local7.Error 192.168.0.244 488727: %LINK-3-UPDOWN: Interface Ethernet0/1, changed state to up 20:25:46 Local7.Notice 192.168.0.244 488728: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0/1, changed state to up 20:25:46 729: DHCP: Applying DHCP options: 20:25:46 730: DHCP: Releasing ipl options: 20:25:46 731: Setting default_gateway to 82.252.148.254 20:25:46 732: Adding default route 82.252.148.254 20:25:46 733: Adding DNS server address 213.228.0.212 20:25:46 734: Adding DNS server address 212.27.32.177 20:25:46 735: DHCP Client Pooling: ***Allocated IP address: 82.252.148.168 20:25:46 736: Allocated IP address = 82.252.148.168 255.255.255.0 20:25:46 737: 20:25:47 Local7.Info 192.168.0.244 488738: %DHCP-6-ADDRESS_ASSIGN: Interface Ethernet0/1 assigned DHCP address 82.252.148.168, mask 255.255.255.0, hostname toto.free.fr 20:25:47 Local7.Info 192.168.0.244 488739: =================== 20:26:10 740: DHCP: QScan: Purging entry 20:26:10 741: DHCP: deleting entry 8171A69C 0.0.0.0 from list 20:26:10 742: Temp IP addr: 0.0.0.0 for peer on Interface: unknown 20:26:10 743: Temp sub net mask: 255.255.255.0 20:26:10 744: DHCP Lease server: 82.252.128.254, state: 8 Purging 20:26:10 745: DHCP transaction id: 5A02 20:26:10 746: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 20:26:10 747: No timer running 20:26:10 748: Retry count: 0 Client-ID: 20:26:10 749: Hostname: toto.free.fr =================== 20:26:46 750: DHCP: QScan: Bound..T1 fired..Renewing 20:26:46 751: DHCP: SRequest attempt # 1 for entry: 20:26:46 752: Temp IP addr: 82.252.148.168 for peer on Interface: Ethernet0/1 20:26:46 753: Temp sub net mask: 255.255.255.0 20:26:46 754: DHCP Lease server: 82.252.148.254, state: 5 Renewing 20:26:46 755: DHCP transaction id: 29AD518C 20:26:46 756: Lease: 600 secs, Renewal: 60 secs, Rebind: 180 secs 20:26:46 757: Temp default-gateway addr: 82.252.148.254 20:26:46 758: Next timer fires after: 00:01:59 20:26:46 759: Retry count: 1 Client-ID: cisco-0008.21ea.aa81-Et0/1 20:26:46 760: Hostname: toto.free.fr 20:26:46 761: DHCP: SRequest - ciaddr: 82.252.148.168 20:26:46 762: DHCP: SRequest placed lease len option: 600 20:26:46 763: DHCP: SRequest: 310 bytes 20:26:46 764: DHCP: SRequest: 310 bytes 20:26:46 765: DHCP: Received a BOOTREP pkt 20:26:46 766: DHCP: Scan: Message type: DHCP Ack 20:26:46 767: DHCP: Scan: Server ID Option: 82.252.148.254 = 52FC94FE 20:26:46 768: DHCP: Scan: Renewal time: 60 20:26:46 769: DHCP: Scan: Rebind time: 180 20:26:46 770: DHCP: Scan: Lease Time: 600 20:26:46 771: DHCP: Scan: Subnet Address Option: 255.255.255.0 20:26:46 772: DHCP: Scan: Router Option: 82.252.148.254 20:26:46 773: DHCP: Scan: DNS Name Server Option: 213.228.0.212, 212.27.32.177 20:26:46 774: DHCP: rcvd pkt source: 82.252.148.254, destination: 82.252.148.168 20:26:46 775: UDP sport: 43, dport: 44, length: 556 20:26:46 776: DHCP op: 2, htype: 1, hlen: 6, hops: 0 20:26:46 777: DHCP server identifier: 82.252.148.254 20:26:47 778: xid: 29AD518C, secs: 0, flags: 0 20:26:47 779: client: 0.0.0.0, your: 82.252.148.168 20:26:47 780: srvr: 82.252.148.254, gw: 0.0.0.0 20:26:47 781: options block length: 308 20:26:47 782: 20:26:47 783: DHCP Ack Message 20:26:47 784: DHCP: Lease Seconds: 600 Renewal secs: 60 Rebind secs: 180 20:26:47 785: DHCP: Server ID Option: 82.252.148.254 20:26:47 786: DHCP: Applying DHCP options: 20:26:47 787: DHCP: Releasing ipl options: 20:26:47 788: Setting default_gateway to 82.252.148.254 20:26:47 789: Adding DNS server address 213.228.0.212 20:26:47 790: Adding DNS server address 212.27.32.177 20:26:47 791: DHCP Client Pooling: ***Allocated IP address: 82.252.148.168
Reply to
anybody43

and you had already help me on this pb : Cisco 2611 and Cisco 1721 : Why , why , why ?????

Yes ! The ISP use address like 82.252.128.Y with a gateway&dhcp server 82.252.128.254, and for a IP like 82.252.148.Y , it use

82.252.148.254, and for ip like 62.147.213.Y use 62.147.213.254 for dhcp and ...... The Ip change from 2days to 1week ... Every 24 hour a micro stop/restart of the DSL connection : sometimes the ip change, sometines not !

What tool doing this ? Thanks

So can i tell something more to the ISP or is Cisco "fault" ? Thanks for your help !

Reply to
sam

For information, a Netgear RP614 , level1 VPN FBR1404TX , and a VPN Bewan LB2204 renew their lease never more than 30seconds and take the newer ip of the newer DHCP server.... Why the Cisco need 9 min ???? Thanks

Reply to
sam

Cabling-Design.com Forums website is not affiliated with any of the manufacturers or service providers discussed here. All logos and trade names are the property of their respective owners.