WAN DHCP does not renew



  • Hi all!

    I have a very strange issue I cannot semm to resolve…
    I have WAN via DHCP. My ISP configured me a static IP address but still via DHCP (MAC binds static IP to me).

    Now here is the problem:

    Feb 15 15:59:22 	dhclient[79541]: DHCPACK from 212.XXX.XXX.XXX
    Feb 15 15:59:22 	dhclient[79541]: accepting packet with data after udp payload.
    Feb 15 15:59:22 	dhclient[79541]: ip length 323 disagrees with bytes received 324.
    Feb 15 15:59:22 	dhclient[79541]: DHCPREQUEST on em2 to 212.XXX.XXX.XXX port 67
    Feb 15 15:29:22 	dhclient[79541]: bound to 85.XXX.XXX.XXX -- renewal in 1800 seconds.
    Feb 15 15:29:22 	dhclient: Creating resolv.conf
    Feb 15 15:29:22 	dhclient: RENEW
    Feb 15 15:29:22 	dhclient[79541]: DHCPACK from 212.XXX.XXX.XXX
    Feb 15 15:29:22 	dhclient[79541]: accepting packet with data after udp payload.
    Feb 15 15:29:22 	dhclient[79541]: ip length 323 disagrees with bytes received 324.
    Feb 15 15:29:22 	dhclient[79541]: DHCPREQUEST on em2 to 212.XXX.XXX.XXX port 67
    Feb 15 14:59:22 	dhclient[79541]: bound to 85.XXX.XXX.XXX -- renewal in 1800 seconds.
    Feb 15 14:59:22 	dhclient: Creating resolv.conf
    Feb 15 14:59:22 	dhclient: RENEW
    Feb 15 14:59:22 	dhclient[79541]: DHCPACK from 212.XXX.XXX.XXX
    Feb 15 14:59:22 	dhclient[79541]: accepting packet with data after udp payload.
    Feb 15 14:59:22 	dhclient[79541]: ip length 323 disagrees with bytes received 324.
    Feb 15 14:59:22 	dhclient[79541]: DHCPREQUEST on em2 to 212.XXX.XXX.XXX port 67
    Feb 15 14:29:22 	dhclient[79541]: accepting packet with data after udp payload.
    Feb 15 14:29:22 	dhclient[79541]: ip length 323 disagrees with bytes received 324.
    Feb 15 14:29:22 	dhclient[72668]: bound to 85.XXX.XXX.XXX -- renewal in 1800 seconds.
    Feb 15 14:29:22 	dhclient: Creating resolv.conf
    Feb 15 14:29:22 	dhclient: /sbin/route add default 85.XXX.XXX.XXX
    Feb 15 14:29:22 	dhclient: Adding new routes to interface: em2
    Feb 15 14:29:22 	dhclient: New Routers (em2): 85.XXX.XXX.XXX
    Feb 15 14:29:22 	dhclient: New Broadcast Address (em2): 85.XXX.XXX.255
    Feb 15 14:29:22 	dhclient: New Subnet Mask (em2): 255.255.255.0
    Feb 15 14:29:22 	dhclient: New IP Address (em2): 85.XXX.XXX.XXX
    Feb 15 14:29:22 	dhclient: ifconfig em2 inet 85.XXX.XXX.XXX netmask 255.255.255.0 broadcast 85.XXX.XXX.255
    Feb 15 14:29:22 	dhclient: Starting add_new_address()
    Feb 15 14:29:22 	dhclient: Comparing IPs: Old: New: 85.XXX.XXX.XXX
    Feb 15 14:29:22 	dhclient: Starting delete_old_states()
    Feb 15 14:29:22 	dhclient: REBOOT
    Feb 15 14:29:22 	dhclient[72668]: DHCPACK from 85.XXX.XXX.XXX
    Feb 15 14:29:22 	dhclient[72668]: accepting packet with data after udp payload.
    Feb 15 14:29:22 	dhclient[72668]: ip length 323 disagrees with bytes received 324.
    Feb 15 14:29:22 	dhclient[72668]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 14:29:22 	dhclient: Comparing IPs: Old: New:
    Feb 15 14:29:22 	dhclient: Starting delete_old_states()
    Feb 15 14:29:22 	dhclient: PREINIT
    Feb 15 14:29:20 	dhclient[9737]: exiting.
    Feb 15 14:29:20 	dhclient[9737]: connection closed
    Feb 15 13:58:37 	dhclient: Creating resolv.conf
    Feb 15 13:58:37 	dhclient: RENEW
    
    HERE I DID RELEASE and RENEW from interface status and all was fine after that...
    BEFORE that inet was NOT working seems like dhclient can`t get IP address but manual release and renew does the trick EVERYTIME...
    
    Feb 15 13:20:18 	dhclient[8017]: bound: renewal in 699 seconds.
    Feb 15 13:20:17 	dhclient: Deleting old routes
    Feb 15 13:20:17 	dhclient: Comparing IPs: Old: New: 85.XXX.XXX.XXX
    Feb 15 13:20:17 	dhclient: Starting delete_old_states()
    Feb 15 13:20:16 	dhclient: New Routers (em2): 85.XXX.XXX.XXX
    Feb 15 13:20:15 	dhclient: New Routers (em2): 85.XXX.XXX.XXX
    Feb 15 13:20:15 	dhclient: New Broadcast Address (em2): 85.XXX.XXX.255
    Feb 15 13:20:15 	dhclient: New Subnet Mask (em2): 255.255.255.0
    Feb 15 13:20:15 	dhclient: New IP Address (em2): 85.XXX.XXX.XXX
    Feb 15 13:20:15 	dhclient: ifconfig em2 inet 85.XXX.XXX.XXX netmask 255.255.255.0 broadcast 85.XXX.XXX.255
    Feb 15 13:20:15 	dhclient: Starting add_new_address()
    Feb 15 13:20:15 	dhclient: TIMEOUT
    Feb 15 13:20:15 	dhclient[8017]: Trying recorded lease 85.XXX.XXX.XXX
    Feb 15 13:20:15 	dhclient[8017]: No DHCPOFFERS received.
    Feb 15 13:20:10 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 5
    Feb 15 13:19:58 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 12
    Feb 15 13:19:46 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 12
    Feb 15 13:19:27 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 19
    Feb 15 13:19:21 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 6
    Feb 15 13:19:18 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 3
    Feb 15 13:19:16 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 2
    Feb 15 13:19:15 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 1
    Feb 15 13:19:14 	dhclient[8017]: DHCPDISCOVER on em2 to 255.255.255.255 port 67 interval 1
    Feb 15 13:19:12 	dhclient[8017]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 13:19:10 	dhclient[8017]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 13:19:08 	dhclient[8017]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 13:19:06 	dhclient[8017]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 13:19:05 	dhclient[8017]: DHCPREQUEST on em2 to 255.255.255.255 port 67
    Feb 15 13:19:05 	dhclient: Comparing IPs: Old: New:
    Feb 15 13:19:05 	dhclient: Starting delete_old_states()
    Feb 15 13:19:05 	dhclient: PREINIT
    ELECTRICITY CAME BACK IN MODEM is already online and ready.
    

    I dont get it… Why pfsense does not obtain IP address by itself? When I manually do RELEASE&RENEW interface gets correct IP but it wont do it automatically...
    As in log from 13:19 till 13:58 modem was fully functional everything was working (IPTV and VOIP) except internet.

    Is this maybe a bug or misconfigured WAN iface?

    Thanks!



  • Can you packet capture that failure and email me the pcap file (cmb at pfsense dot org) with a link to this thread?

    I think it's likely from "ip length 323 disagrees with bytes received 324" but why you're seeing that isn't clear without a pcap.



  • Hi!

    I can`t reproduce the issue…
    If I power-cycle modem it does connect without a problem...
    Or if I reboot pfsense it also reconnects fine...

    Its very specific problem, if you have any idea at all how to reproduce it, then I can produce pcap without problem...



  • And one more thing…

    It does obtain gateway IP address but iface IP 85.XX.XX.XX is not there...

    Gateway shows as pending but its IP is listed...

    So its like all is fine except iface IP address is missing :)



  • If it's a renewal issue, it should happen every 30 minutes since your lease appears to be 1 hour. Does it not start logging that after 30 minutes?



  • What do you mean by logging?

    In DHCP logs there is dhclient but it won`t renew it even after 1 hour…

    But this is very specific, it happened only 2 times in 3 months and there is no way I can think of on how to reproduce it.



  • im also seeing similar issues



  • Can you reproduce?

    I can`t tell if 2.1 did the same as I was using PPPoE back then :)



  • for me its an internal 3g router which provides internet to pfsense and pfsense is set to dhcp and at times fails to renew



  • Huh this sounds like same issue to me…



  • I wonder if this might be one of the issues with the newer version of the em driver. These newer versions were pulled from pfSense 2.1.1 after February 24th.

    I was having occasional "DHCP failues" on the WAN interface (em0) as well. However, for the last few days, everything appeared to work fine again.