known bugs or local issue? (db-time-format and 'Lease with binding state free not on its queue'

[Jiri Popelka]

On 06/16/2010 03:35 AM, Dorsey, Chris wrote:
>
> A while ago I turned on 'db-time-format local' to get the '# Tue Jun 
> 15 18:07:38 2010' type comments in myhost dhcpd.leases.  The problem 
> is that myhost dhcpd restarts cause tens of thousands of lines like:
>
> /var/myhost dhcpd/etc/myhost dhcpd.leases line 75620: semicolon expected.
>
>   atsfp
>
>    ^
>
> /var/myhost dhcpd/etc/myhost dhcpd.leases line 75627: semicolon expected.
>
>   tstp
>
>    ^
>
> /var/myhost dhcpd/etc/myhost dhcpd.leases line 75629: semicolon expected.
>
>   atsfp
>
>    ^
>
> and causes myhost dhcpd a while to restart.  Seems like a bug with 
> myhost dhcpd parsing itw own time comments.  I reverted back to 
> 'db-time-format local' and after the second restart (to clear up the 
> file after writing) all seems well again.  Is this a known bug or an 
> issue on my end?  I've seen this in at least (2) different versions of 
> 4 including 4.1.1 running on Redhat 5 (2.6.18-164.9.1.el5) using failover.
>
Hi,

Couple days ago I submitted to dhcp-bugs at isc.org a patch for this 
problem with this comment:
"   Since 4.0.0 common/parse.c::parse_date()
has been renamed to parse_date_core()
and new parse_date() function has been created
as a wrapper around parse_date_core()
to consume the semicolon after the date.
However parse_date_core() has not been properly
updated and still tries to consume semicolon on it's own
with parse_semi() or skip_to_semi().   "

The ticket has been assigned an ID of [ISC-Bugs #21501].

I'm attaching the patch also here for the case that you are interested.

Jiri Popelka
Red Hat, inc.


> Also, I noticed once the other day and twice today that myhost dhcpd 
> failed to restart on the failover server, but the primary restarted 
> fine.  In both cases, I see the following 'Lease with binding state 
> free not on its queue' message in the /var/log/boot.log:
>
> Jun 15 17:05:41 myhost dhcpd: Wrote 0 class decls to leases file.
>
> Jun 15 17:05:41  myhost dhcpd: Wrote 0 deleted host decls to leases file.
>
> Jun 15 17:05:41  myhost dhcpd: Wrote 0 new dynamic host decls to 
> leases file.
>
> Jun 15 17:05:41  myhost dhcpd: Wrote 575 leases to leases file.
>
> Jun 15 17:05:41  myhost dhcpd: Listening on 
> LPF/eth0/00:17:a4:aa:46:80/10.10.41.0/24
>
> Jun 15 17:05:41  myhost dhcpd: Sending on   
> LPF/eth0/00:17:a4:aa:46:80/10.10.41.0/24
>
> Jun 15 17:05:41  myhost dhcpd: Sending on   Socket/fallback/fallback-net
>
> Jun 15 17:05:41  myhost dhcpd: failover peer dhcp-yellow: I move from 
> recover to startup
>
> Jun 15 17:05:41  myhost dhcpd: data: hardware: raw packet not available
>
> Jun 15 17:05:41  myhost dhcpd: data: packet: raw packet not available
>
> Jun 15 17:05:41  myhost dhcpd: failover peer dhcp-yellow: I move from 
> startup to recover
>
> Jun 15 17:05:41  myhost dhcpd: failover peer dhcp-yellow: peer moves 
> from unknown-state to communications-interrupted
>
> Jun 15 17:05:41  myhost dhcpd: Sent update request all message to 
> dhcp-yellow
>
> Jun 15 17:05:41  myhost dhcpd: failover peer dhcp-yellow: peer moves 
> from communications-interrupted to partner-down
>
> Jun 15 17:05:41  myhost dhcpd: Lease with binding state free not on 
> its queue.
>
> From the list archives, it seems this might have been patched in 4.1.0 
> according to the release notes, but it still seems like a major issue 
> (failover server down).
>
> Thanks in advance for any help,
>
> Chris
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.isc.org/pipermail/dhcp-users/attachments/20100616/245fa442/attachment.html>
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: dhcp-4.1.1-P1-parse_date.patch
URL: <https://lists.isc.org/pipermail/dhcp-users/attachments/20100616/245fa442/attachment.ksh>