Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    How often 'should' clients be making DHCPREQUEST queries?

    Scheduled Pinned Locked Moved DHCP and DNS
    6 Posts 3 Posters 2.2k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • W
      wkearney99
      last edited by

      It's been a bunch of fun setting up my new pfsense router.  All sorts of discoveries like devices ignoring DHCP-provided DNS server info and making direct requests (chromecast, hue, blink etc).

      As I delve through the various logs I happened to notice a lot of what look like repetitive DHCP negotiations.  Like these:

      
      Feb 9 10:06:41	dhcpd		DHCPACK on 192.168.12.50 to 2c:54:91:13:d2:70 via igb1
      Feb 9 10:07:15	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:07:15	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:07:15	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:07:15	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:07:25	dhcpd		DHCPREQUEST for 192.168.12.28 from 00:0b:82:c3:80:3a via igb1
      Feb 9 10:07:25	dhcpd		DHCPACK on 192.168.12.28 to 00:0b:82:c3:80:3a via igb1
      Feb 9 10:08:35	dhcpd		DHCPREQUEST for 192.168.12.47 from 00:23:38:11:cd:0c via igb1
      Feb 9 10:08:35	dhcpd		DHCPACK on 192.168.12.47 to 00:23:38:11:cd:0c via igb1
      Feb 9 10:08:36	dhcpd		DHCPREQUEST for 192.168.12.40 from 94:10:3e:30:c4:ad via igb1
      Feb 9 10:08:36	dhcpd		DHCPACK on 192.168.12.40 to 94:10:3e:30:c4:ad via igb1
      Feb 9 10:09:01	dhcpd		DHCPREQUEST for 192.168.12.84 from 00:11:d9:61:e6:f5 via igb1
      Feb 9 10:09:01	dhcpd		DHCPACK on 192.168.12.84 to 00:11:d9:61:e6:f5 via igb1
      Feb 9 10:09:21	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:09:21	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:09:21	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:09:21	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:10:57	dhcpd		DHCPREQUEST for 192.168.12.19 from 00:17:eb:0e:29:d0 via igb1
      Feb 9 10:10:57	dhcpd		DHCPACK on 192.168.12.19 to 00:17:eb:0e:29:d0 via igb1
      Feb 9 10:11:28	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:11:28	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:11:28	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:11:28	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:11:44	dhcpd		DHCPREQUEST for 192.168.12.151 (192.168.12.1) from 02:42:a2:eb:cb:5e via igb1
      Feb 9 10:11:44	dhcpd		DHCPACK on 192.168.12.151 to 02:42:a2:eb:cb:5e via igb1
      Feb 9 10:11:44	dhcpleases		Sending HUP signal to dns daemon(74966)
      Feb 9 10:13:07	dhcpd		DHCPREQUEST for 192.168.12.75 from 00:e0:4c:36:43:ef via igb1
      Feb 9 10:13:07	dhcpd		DHCPACK on 192.168.12.75 to 00:e0:4c:36:43:ef via igb1
      Feb 9 10:13:34	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:13:34	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:13:34	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:13:34	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:14:35	dhcpd		DHCPREQUEST for 192.168.12.51 from 28:18:78:ea:aa:1e via igb1
      Feb 9 10:14:35	dhcpd		DHCPACK on 192.168.12.51 to 28:18:78:ea:aa:1e via igb1
      Feb 9 10:15:41	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:15:41	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:15:41	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:15:41	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:17:47	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:17:47	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:17:47	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:17:47	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:19:51	dhcpd		DHCPREQUEST for 192.168.12.122 from 00:0e:58:71:74:f8 via igb1
      Feb 9 10:19:51	dhcpd		DHCPACK on 192.168.12.122 to 00:0e:58:71:74:f8 via igb1
      Feb 9 10:19:54	dhcpd		DHCPDISCOVER from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:19:54	dhcpd		DHCPOFFER on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:19:54	dhcpd		DHCPREQUEST for 192.168.12.22 (192.168.12.1) from 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:19:54	dhcpd		DHCPACK on 192.168.12.22 to 00:03:7f:1b:4c:b2 via igb1
      Feb 9 10:20:59	dhcpd		DHCPREQUEST for 192.168.12.60 from 00:23:24:ae:e8:20 via igb1
      Feb 9 10:20:59	dhcpd		DHCPACK on 192.168.12.60 to 00:23:24:ae:e8:20 via igb1
      
      

      These are all devices that have DHCP leases set up for them.  They're on the leased addresses.  They're all 'devices' not computers.  Various gizmos like Sonos speakers, camera gateways, thermostats and the like.  None are PCs, at least not in the sense that they have any sort of on-board log or UI that would assist in explaining themselves.  They're not emitting errors or otherwise malfunctioning.  They're just repeatedly making the DHCP negotiations and I'm curious as to why.

      They're not even all coming through the same network path to the router.  Although I do have to revisit the rats nest of cabling leading to all the various switches and access points.  Things 'grow' over time and I'd wonder if this is a 'canary in the coal mine' telling me there's a switch somewhere in the mix that's acting up?

      So let me ask, what's a normal amount of DHCP negotiation for a LAN client?  And where would I properly determine/debug when something's abnormal?

      1 Reply Last reply Reply Quote 0
      • JKnottJ
        JKnott
        last edited by

        Normally, a client will renew the lease part way through, perhaps 1/2 or 2/3, of the lease time.  What's the lease time set for?  Normally, it's 7200 seconds (2 hours).

        PfSense running on Qotom mini PC
        i5 CPU, 4 GB memory, 32 GB SSD & 4 Intel Gb Ethernet ports.
        UniFi AC-Lite access point

        I haven't lost my mind. It's around here...somewhere...

        1 Reply Last reply Reply Quote 0
        • johnpozJ
          johnpoz LAYER 8 Global Moderator
          last edited by

          As the client gets closer to the end of the lease it will start to panic and send out lots of requests for renewal.. When the lease finally expires then it would send out discover..

          Looks like your clients are getting offers and asking for them and even getting back the ack, etc.  Its possible you just have set a really short lease time?  Look to the actual lease for these clients you can view the leases on pfsense.

          An intelligent man is sometimes forced to be drunk to spend time with his fools
          If you get confused: Listen to the Music Play
          Please don't Chat/PM me for help, unless mod related
          SG-4860 24.11 | Lab VMs 2.7.2, 24.11

          1 Reply Last reply Reply Quote 0
          • W
            wkearney99
            last edited by

            There's no entry in the default least time field in the pfsense, the caption text indicates the default is 7200 seconds.

            When I check on a client win7 PC it states: "Lease Obtained: Thursday, January 25, 2018 5:29:39 PM  Lease Expires: Saturday, February 10, 2018 8:07:48 AM".  Which I have to think the 1/25 date being when it was initial obtained, not necessarily the current lease origination.  When I check on the router itself I see another dynamic lease as "2018/02/10 06:16:43 2018/02/10 08:16:43"… the two hour window.

            Curiously, the static leases (on the /status_dhcp_leases.php page) show no Start/End timestamps, just online or offline.  I get that they're static, and not bound by a timeframe, but is there a way to see when they were issued?

            It's possible that might matter as the devices spewing these requests ARE all on static leases.

            I generally prefer to put all my devices on static leases, if just to make it simpler to tell distinguish devices when looking at logs and such.  Whenever possible I manually configure them (on device) as static, but many newer gizmos don't always have a UI for setting that up.  Thus static leases handle it.

            1 Reply Last reply Reply Quote 0
            • johnpozJ
              johnpoz LAYER 8 Global Moderator
              last edited by

              I rarely set anything static on the device and always just do a reservation in the dhcp server for what IP I want them to have..

              That lease windows seems to be an odd length of time?  Jan 25th to odd time on feb 10th??  Normally they would be in even increments.. Off the top of the head I do not believe dhcpd keeps a copy of static leases (reservations) in the .leases or .leases~ files

              It think its up to the client in such cases on keeping track.. Its quite possible could be something going funky on there - what if you do a full release and renew on the client, this should get you a new lease with new obtained and expired times that match up exactly with whatever your lease times are set for, etc.

              My box is actually showing odd times as well..

              Lease Obtained. . . . . . . . . . : Monday, January 29, 2018 5:45:44 AM
              Lease Expires . . . . . . . . . . : Thursday, February 15, 2018 5:45:44 AM

              At most it should be 4 days..  So I just did a renew

              Lease Obtained. . . . . . . . . . : Monday, January 29, 2018 5:45:44 AM
              Lease Expires . . . . . . . . . . : Thursday, February 15, 2018 10:34:20 AM

              And while the obtained date did not change since it was a renew and not a discover, etc. The new expired jumped by 2 days… I would have to sniff and see what actually happened.

              If you have a client that just keeps asking and asking for renewal, etc.. I would prob release it at the client and let it do a new discover, etc.

              An intelligent man is sometimes forced to be drunk to spend time with his fools
              If you get confused: Listen to the Music Play
              Please don't Chat/PM me for help, unless mod related
              SG-4860 24.11 | Lab VMs 2.7.2, 24.11

              1 Reply Last reply Reply Quote 0
              • W
                wkearney99
                last edited by

                @johnpoz:

                I would prob release it at the client and let it do a new discover, etc.

                Hard to do sometimes on devices that have no UI.  Many are typically set up via an app on a phone/tablet or sometimes via on-device web server page.  But few, if any, offer actual release/renew features on what little UI they offer.

                I've shelved this into the "it ain't broke, don't fix it" slot for now.  At some point I'd like to figure it out, but stuff's working so I'm going to stop looking at the log…

                1 Reply Last reply Reply Quote 0
                • First post
                  Last post
                Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.