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

    Syslog running crazy - corrupt dhcpd6 lease

    Scheduled Pinned Locked Moved General pfSense Questions
    7 Posts 4 Posters 1.1k 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.
    • junicastJ Offline
      junicast
      last edited by

      Hi,

      my pfsense router keeps going crazy.
      2.2-RELEASE (i386)
      built on Thu Jan 22 14:04:25 CST 2015
      FreeBSD 10.1-RELEASE-p4

      Syslog is using nearly all cpu time.

      lots of processes:

      
root    5701   0.0  0.1   5992  1676  -  Is    8:19PM    0:00.01 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root    7984   0.0  0.1   5992  1676  -  Is    8:20PM    0:00.01 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   10311   0.0  0.1   5992  1676  -  Is    4:10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   11105   0.0  0.1  10088  1696  -  Is    8:15PM    0:00.02 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   11800   0.0  0.1   5992  1676  -  Is    3:10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   21029   0.0  0.1   5992  1676  -  Is   Sat10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   22436   0.0  0.1   5992  1676  -  Is   10:02AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   30479   0.0  0.1   5992  1676  -  Is    7:18AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   31396   0.0  0.1   5992  1676  -  Is   Sun05AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   36090   0.0  0.1   5992  1676  -  Is    8:21PM    0:00.01 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   38030   0.0  0.1   5992  1676  -  Is    4:10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   40616   0.0  0.1   5992  1676  -  Is   Sat04PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   52334   0.0  0.1   5992  1676  -  Is   Sat10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   52420   0.0  0.1   5992  1676  -  Is    9:33PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   53216   0.0  0.1   5992  1676  -  Is   10:02AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   66686   0.0  0.1   5992  1676  -  Is    4:10PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   68531   0.0  0.1   5992  1676  -  Is    9:29AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   70245   0.0  0.1   5992  1676  -  Is   10:01AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   71469   0.0  0.1   5992  1676  -  Is    7:18AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   73421   0.0  0.1   5992  1676  -  Is    8:22PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   76015   0.0  0.1   5992  1676  -  Is    8:23PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   80441   0.0  0.1   5992  1676  -  Is    1:37PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   91610   0.0  0.1   5992  1676  -  Is   Sat07PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   92077   0.0  0.1   5992  1676  -  Is    8:47AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   93935   0.0  0.1   5992  1676  -  Is   Sat07PM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   94058   0.0  0.1   5992  1676  -  Is   Sun05AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   96604   0.0  0.1   5992  1676  -  Is   10:01AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases
root   97240   0.0  0.1   5992  1676  -  Is   Sun05AM    0:00.00 /usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f /usr/local/sbin/prefixes.php|/bin/sh -l /var/dhcpd/var/db/dhcpd6.leases

      in /var/log/dhcpd.log via clog -f keep getting this:

      
Mar 16 08:47:38 pfsense dhcpd: /var/db/dhcpd6.leases line 111: corrupt lease file; expecting ia_na contents, got ' {   cltt 0 2015/03/15 22:57:20;   iaaddr 2001:870:1909::1275 {     binding state active;     preferred-life 4500;     max-life 7200;     ends 1 2015/03/16 00:57:20;   } }  '

      When I look into /var/dhcpd/dhcpd6.leases there are only 55 lines at all.
      It also seems that those php processes keep eating all RAM.
      I have had this same issue about 2 weeks ago. Deleteing the leases files and restarting dhcpd fixes, but obviously only short-term  :-[
      What's going on here?

      1 Reply Last reply Reply Quote 0
      • junicastJ Offline
        junicast
        last edited by

        no one?

        1 Reply Last reply Reply Quote 0
        • T Offline
          tenortim
          last edited by

          I just hit the exact same problem.
          I killed off all of the dhcpd processes to try to get things back under control.
          Next time, I'll try to gather data first.
          The dhcpd log file is just spammed with messages of the form:
          May 21 13:44:32 fw dhcpd: /var/db/dhcpd6.leases line 43: corrupt lease file; expecting ia_na contents, got '  '
          May 21 13:44:32 fw dhcpd:
          May 21 13:44:32 fw dhcpd: ^

          So dhcpd's error handling leaves a lot to be desired in this case.

          1 Reply Last reply Reply Quote 0
          • H Offline
            heper
            last edited by

            try updating to 2.2.2 first. tons of stuff has been fixed since then.

            1 Reply Last reply Reply Quote 0
            • T Offline
              tenortim
              last edited by

              Sorry, I should have said, this is running 2.2.2. I've never had the problem happen before.
              It seems there was a parsing bug in ISC dhcpd 4.2.1 but that was fixed in 4.2.2 and we seem to be running 4.2.6 here, so unless there was a regression, it would appear to be a new issue.

              1 Reply Last reply Reply Quote 0
              • C Offline
                cmb
                last edited by

                What's the full contents of your /var/dhcpd/var/db/dhcpd6.leases file? Can PM to me if you don't want to post publicly.

                1 Reply Last reply Reply Quote 0
                • T Offline
                  tenortim
                  last edited by

                  Ugh,
                  I did save a copy before removing it from /var/dhcpd/var/db, by copying it to /tmp.
                  As part of trying to get everything fixed (shotgun killing dhcpd processes), I wound up in a state where check_reload_status was spinning so I rebooted the firewall… forgetting that /tmp gets cleaned up on reboot :-(
                  So I've managed to lose the evidence from this incident.

                  If it recurs, I'll make sure I get a copy saved before I reboot.

                  Thanks!

                  Tim

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