When is a Commit... Not Really a Commit

[Duane Bailey]

Here's a new version:

**************

As a coder working under Norman, I'd just like to add to his note.  
Logging is, in many ways, the primary way to see what the server is  
doing. We parse the logs to record current leases because it's  
straightforward and works fairly well. Some of the events that the  
server provides, like the COMMIT we're dealing with here, help  
immensely, but it seems as if some of the information could easily be  
moved over to the default logs with little issue and, as a result,  
much more informative and readable logs, meaning an easier to audit  
system and, as an additional boon, logs that are easier to parse.

Here are a few specific suggestions that we thought would help. The  
first is to log a lease time with every ACK packet—I've implemented  
this locally, and it seems to work fine, whereas the commit log  
appears to be failing every so often. If this feature along could be  
implemented, it would help the logging situation greatly. Secondly,  
recording a transaction ID along with each packet transaction would  
also provide an easier to read and parse system. Both of these are  
easy to implement and do not provide any additional burden to the  
server while making the lives of dhcp users everywhere a little easier.

Thanks,
Duane R. Bailey

On Oct 23, 2009, at 10:07 AM, Norman Elton wrote:

> We're using event scripting in our config file to log a message each
> time a lease is committed (using the "on commit" functionality). This
> seems to be working well for 99% of the leases. But, occasionally, a
> client gets a new IP address without anything getting logged. So we're
> curious... what exactly qualifies as a "commit"?
>
> In our case, we're doing failover between two servers. Here's are the
> logs from the two servers of a transaction that I would have expected
> to produce a commit message:
>
> SERVER-1: DHCPREQUEST for 192.168.1.4 from 00:13:02:70:03:08 via
> 128.239.168.5: wrong network.
> SERVER-1: DHCPNAK on 192.168.1.4 to 00:13:02:70:03:08 via  
> 128.239.168.5
> SERVER-1: DHCPDISCOVER from 00:13:02:70:03:08 via 128.239.168.5: load
> balance to peer wm-dhcp-03-04
> SERVER-1: DHCPREQUEST for 128.239.169.17 (128.239.10.124) from
> 00:13:02:70:03:08 via 128.239.168.5: lease owned by peer
>
> SERVER-2: DHCPREQUEST for 192.168.1.4 from 00:13:02:70:03:08 via
> 128.239.168.5: wrong network.
> SERVER-2: DHCPNAK on 192.168.1.4 to 00:13:02:70:03:08 via  
> 128.239.168.5
> SERVER-2: DHCPDISCOVER from 00:13:02:70:03:08 via 128.239.168.5
> SERVER-2: DHCPOFFER on 128.239.169.17 to 00:13:02:70:03:08
> (2006WM-3234409E) via 128.239.168.5
> SERVER-2: DHCPREQUEST for 128.239.169.17 (128.239.10.124) from
> 00:13:02:70:03:08 via 128.239.168.5: lease owned by peer
> SERVER-2: DHCPREQUEST for 128.239.169.17 (128.239.10.124) from
> 00:13:02:70:03:08 (2006WM-3234409E) via 128.239.168.5
> SERVER-2: DHCPACK on 128.239.169.17 to 00:13:02:70:03:08
> (2006WM-3234409E) via 128.239.168.5
>
> Client comes line, tries to ask for an invalid IP, gets NAK'd. Turns
> around, broadcasts a DISCOVER, which our router forwards to the
> server. The second server responds. The client broadcasts a REQUEST,
> two which the second server ACK's.
>
> I'm a little curious why both servers show "lease owned by peer".
> Could this be part of the problem?
>
> Any other reason why the "on commit" script isn't firing under these
> circumstances?
>
> Thanks
>
> Norman
> _______________________________________________
> dhcp-users mailing list
> dhcp-users at lists.isc.org
> https://lists.isc.org/mailman/listinfo/dhcp-users