isc-dhcp3.6.p1 restart problems

Fri Oct 12 11:49:38 UTC 2018

I just realised that the "incomplete" logs come from the configtest (-t
option) of dhcpd.

Why we don't have any logs from 12:00 to 13:00 is still unclear to me. The
REQUESTs came in during that time (checked with wireshark on the server)

On Fri, 12 Oct 2018 at 08:15, Philippe Maechler <plcmaechler at gmail.com>
wrote:

> Hello dhcp-users
>
>
> Sorry if this posts is redundant. I first sent it using the wrong
> mailaddress
>
>
> Today we faces a strange issue. Our dhcp server was working fine when we
> checked the log files but the server did not hand
>
> out any ip addresses. After consulting the logs we found several “issues”
>
>
>
>
>
> *background:*
>
> We have two servers in an active – cold standby scenario. Both servers
> have the same config and the same lease time
>
> (copied with rsync after a server restart). Only one server is active, the
> other server is ready that we can put them into production
>
> if the server 1 fails.
>
>
>
> Our provisioning system creates a config snippet with classes and host
> statements. At the end of the file we write down the
>
> number  of lines in this include file.
>
> The server checks every 5 min if we have a new file. If so we put all the
> different snippets into one file (after checking that we
>
> still have the same number of lines) and makes a diff of the running and
> the new dhcpd.conf. If we have differences, we restart the dhcpd.
>
>
>
> In the configuration we have a global on commit statement, that checks the
> ip range the request is coming from.
>
> If it is from 10.21.0.0/16 or 10.23.0.0/16 we execute a php-script which
> generates a config file, that then can be downloaded via tftp.
>
> Otherwise we don’t execute anything.
>
>
>
>
>
> *dhcpd.logs*
>
> *# everything was working fine*
>
> Oct 11 11:57:37 FTTH-DHCP-01 dhcpd: on commit statement for 026004
> 10.21.15.152 0:1e:80:1c:b7:1e
>
> Oct 11 11:57:37 FTTH-DHCP-01 dhcpd: execute_statement argv[0] =
> /usr/local/bin/php
>
> Oct 11 11:57:37 FTTH-DHCP-01 dhcpd: execute_statement argv[1] =
> /etc/scripts/provisioning/createCfgFile.php
>
> Oct 11 11:57:37 FTTH-DHCP-01 dhcpd: execute_statement argv[2] = -c026004
>
> Oct 11 11:57:37 FTTH-DHCP-01 dhcpd: execute_statement argv[3] =
> -i10.21.15.152
>
>
>
> *# planed service restart*
>
> Oct 11 11:58:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 11:58:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 11:58:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 11:58:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:03:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:03:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:03:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:03:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:08:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:08:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:08:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:08:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:13:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:13:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:13:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:13:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:18:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:18:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:18:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:18:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:23:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:23:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:23:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:23:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:28:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:28:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:28:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:28:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:33:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:33:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:33:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:33:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:38:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:38:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:38:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:38:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:43:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:43:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:43:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:43:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:48:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:48:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:48:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:48:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:53:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:53:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:53:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:53:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 12:58:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 12:58:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 12:58:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 12:58:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 13:03:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 13:03:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 13:03:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 13:03:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 13:08:04 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 13:08:04 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 13:08:04 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 13:08:04 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> Oct 11 13:11:14 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 13:11:14 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 13:11:14 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 13:11:14 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
>
>
> *# here we realised that the issue is the dhcp server and restarted the
> daemon by hand.*
>
> Oct 11 13:11:19 FTTH-DHCP-01 dhcpd: Internet Systems Consortium DHCP
> Server 4.3.6-P1
>
> Oct 11 13:11:19 FTTH-DHCP-01 dhcpd: Copyright 2004-2018 Internet Systems
> Consortium.
>
> Oct 11 13:11:19 FTTH-DHCP-01 dhcpd: All rights reserved.
>
> Oct 11 13:11:19 FTTH-DHCP-01 dhcpd: For info, please visit
> https://www.isc.org/software/dhcp/
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 class decls to leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 deleted host decls to leases
> file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 new dynamic host decls to
> leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 8909 leases to leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce3/98:4b:e1:75:f1:3e/10.255.254.32/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce3/98:4b:e1:75:f1:3e/10.255.254.32/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce2/98:4b:e1:75:f1:3c/10.255.254.24/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce2/98:4b:e1:75:f1:3c/10.255.254.24/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce1/98:4b:e1:75:f1:56/10.255.254.16/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce1/98:4b:e1:75:f1:56/10.255.254.16/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce0/98:4b:e1:75:f1:54/10.20.0.0/24
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce0/98:4b:e1:75:f1:54/10.20.0.0/24
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> Socket/fallback/fallback-net
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Server starting service.
>
>
>
> *# now everything seems to be normal again*
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: CC DHCPDISCOVER from
> 1:0:1e:80:1d:12:85 for 185.82.206.252 via
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: KM DHCPDISCOVER from
> 1:0:1e:80:1d:12:85 for 185.82.206.252 via gaswWAL002 eth 000016/012:0804
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: vendor-class-id: 'i6800' -
> 1:0:1e:80:1d:12:85 - 'i6800'
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: agent.circuit-id (0, 32): 'gaswWAL002
> eth 000016/012:0804' from 1:0:1e:80:1d:12:85
>
>
>
> Between 11:58 and 13:11 there was no dhcpd «running» alltough /usr/local/etc/rc.d/isc-dhcpd
> status was reporting the daemon is running
>
> Normaly if we restart the server we have the following lines in the log
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 class decls to leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 deleted host decls to leases
> file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 0 new dynamic host decls to
> leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Wrote 8909 leases to leases file.
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce3/98:4b:e1:75:f1:3e/10.255.254.32/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce3/98:4b:e1:75:f1:3e/10.255.254.32/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce2/98:4b:e1:75:f1:3c/10.255.254.24/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce2/98:4b:e1:75:f1:3c/10.255.254.24/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce1/98:4b:e1:75:f1:56/10.255.254.16/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce1/98:4b:e1:75:f1:56/10.255.254.16/29
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Listening on
> BPF/bce0/98:4b:e1:75:f1:54/10.20.0.0/24
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> BPF/bce0/98:4b:e1:75:f1:54/10.20.0.0/24
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Sending on
> Socket/fallback/fallback-net
>
> Oct 11 13:11:21 FTTH-DHCP-01 dhcpd: Server starting service.
>
>
>
> During the “down-time” these log lines were not reported.
>
>
>
> That our management has some fancy graphs, we parse the dhcpd-pools output
> and put that data into an rrd.
>
>
> (If the mailinglist drops the image attached: we have about 3k active and
> 277 free leases. Around 12:00 the server immediately reported 223 active
> but 2995 free leases). The whole server has about 9k leases
>
> On all our “bigger” ip pools we have a similar graph. At 12:00 the active
> leases dropped significantly and the free leases jumped up. So dhcpd pools
> also saw a problem too…
>
>
> This is the first time we have such an issue and we use the isc-dhcp since
> version 3.x. Currently we run 4.3.6-p1 on a FreeBSD 11.1 AMD64
>
>
>
> Does anyone has an idea what happened? Or how we can “protect” us against
> this one?
>
> My first idea is to grep for the “Listening on…” or “Server starting
> service.” Line in the logs and do the restart again if me miss the line.
> But since a normal restart from cron didn’t help (12:03, 12:08, 12:13, …)
> I’m not sure. The only alternative I see (atm) is to send an sms or email
> if we miss the “starting service line”
>
>
>
>
>
> Any help is appreciated
>
>
>
> /BR
>
> Philippe
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.isc.org/pipermail/dhcp-users/attachments/20181012/a2db5c85/attachment-0001.html>