I am seeing if I can sort out a bug in /usr/sbin/unbound-dhcp-leases-bridge where it restarts unbound on every renewed lease. In the file there are many lines like log.debug("Reloading Unbound...") and log.info("Reading fix leases from %s" % self.path). Where are these messages output to or how can I see them?
My programming skills are limited and I am trying to dump some values to see what they contain to check my logic is working.
There is a “verbose” command that needs to be enabled in launch of unbound-dhcp-leases-bridge
something like: unbound-dhcp-leases-bridge -v or unbound-dhcp-leases-bridge -vv
Don’t run it from the command line. It is buried in a init.d script.
Let me look for me notes… I’ll be back!
EDIT: See this:
Nick - if you mention what you are looking for I may be able to assist.
I had dug through the code looking for the unbound restart issue…
The problem is partly caused because the script restarts unbound every time the /etc/unbound/dhcp-leases.conf is written, but often the new file is the same as the old because it gets written every time a lease updates… It can be mitigated by increasing the lease time, but …
There is a possible quick and dirty solution to do a filecomp.cmp before the temporary file is copied over the main one. If the notted value of that is returned from the write_dhcp_leases, it can be checked before firing the reload in update_dhcp_leases.
My python knowledge is limited and I don’t have a debugging environment so I need to dump values as I go:
def write_dhcp_leases(self, leases):
log.debug("Writing DHCP leases...")
with tempfile.NamedTemporaryFile(mode="w", delete=False) as f:
for l in leases:
for rr in l.rrset:
f.write("local-data: \"%s\"\n" % " ".join(rr))
RequeirUnboundReload = not filecmp.cmp(f.name, self.path, shallow=False)
log.info("njh During write_dhcp_leases RequeireUnboundReload: %s" % str(RequeirUnboundReload))
log.info("njh Temp file name: %s" % f.name)
log.info("njh Conf file name: %s" % self.path)
# Make file readable for everyone
os.fchmod(f.fileno(), stat.S_IRUSR|stat.S_IWUSR|stat.S_IRGRP|stat.S_IROTH)
# Move the file to its destination
os.rename(f.name, self.path)
You need to add a import filecmp at the top. You can see the four lines I’ve added. I have not added the return yet as I want to check how I am doing first.
My python is very limited also and I did the exact same thing (added log.info lines to the bridge).
edit this init script:
/etc/rc.d/init.d/dhcp
And look for this line:
loadproc /usr/sbin/unbound-dhcp-leases-bridge -d -v
and add -v (like I have above) or -vv for even more verbosity
EDIT: This is the original line:
I think this is verbosity 1 (-v)
Aug 5 21:02:27 ipfire dhcpd: DHCPDISCOVER from 00:07:a6:20:18:2d (LEVDS-Dimmer-7BCA) via blue0
Aug 5 21:02:27 ipfire dhcpd: DHCPOFFER on 192.168.65.157 to 00:07:a6:20:18:2d via blue0
Aug 5 21:02:27 ipfire dhcpd: Commit: IP: 192.168.65.157 MAC: 00:07:a6:20:18:2d Name: LEVDS-Dimmer-7BCA MAC2: 0:7:a6:20:18:2d
Aug 5 21:02:27 ipfire dhcpd: DHCPREQUEST for 192.168.65.157 (192.168.65.1) from 00:07:a6:20:18:2d via blue0
Aug 5 21:02:27 ipfire dhcpd: DHCPACK on 192.168.65.157 to 00:07:a6:20:18:2d (LEVDS-Dimmer-7BCA) via blue0
Aug 5 21:02:28 ipfire unbound: [2058:0] info: service stopped (unbound 1.17.1).
Aug 5 21:02:28 ipfire unbound: [2058:0] info: server stats for thread 0: 559 queries, 240 answers from cache, 319 recursions, 7 prefetch, 0 rejected by ip ratelimiting
Aug 5 21:02:28 ipfire unbound: [2058:0] info: server stats for thread 0: requestlist max 7 avg 0.616564 exceeded 0 jostled 0
Aug 5 21:02:28 ipfire unbound: [2058:0] info: average recursion processing time 0.068321 sec
Aug 5 21:02:28 ipfire unbound: [2058:0] info: histogram of recursion processing times
Aug 5 21:02:28 ipfire unbound: [2058:0] info: [25%]=0.0114627 median[50%]=0.0295915 [75%]=0.09728
Aug 5 21:02:28 ipfire unbound: [2058:0] info: lower(secs) upper(secs) recursions
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.000000 0.000001 53
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.008192 0.016384 67
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.016384 0.032768 49
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.032768 0.065536 47
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.065536 0.131072 48
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.131072 0.262144 50
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.262144 0.524288 3
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 0.524288 1.000000 1
Aug 5 21:02:28 ipfire unbound: [2058:0] info: 1.000000 2.000000 1
Aug 5 21:02:28 ipfire unbound: [2058:0] notice: Restart of unbound 1.17.1.
Aug 5 21:02:28 ipfire unbound: [2058:0] notice: init module 0: validator
Aug 5 21:02:28 ipfire unbound: [2058:0] notice: init module 1: iterator
Aug 5 21:02:28 ipfire unbound: [2058:0] info: start of service (unbound 1.17.1).
Aug 5 21:02:30 ipfire unbound: [2058:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
Hmm my snippet always says the file are different even if I use a filecmp.clear_cache(). May be I’ll need to try a different way of comparing the files.
I cannot help with that part since I don’t speak python.
I ended up writing a “proof-of-concept” script to replace the unbound-dhcp-leases-bridge script. I wrote it to help remove the unbound restarts.
Instead of parsing the DHCP Leases file, it reacts to DHCP “events” and then sends the needed DNS info to unbound.
I’ve been running my PoC script for several months on a 30-ish device home network and it works very well for me! I even changed the
Default lease time (mins): 60 and Max lease time (mins): 120
down to
Default lease time (mins): 5 and Max lease time (mins): 10
to help put more pressure on the process. All was good!
But I don’t have a big network to test and to make sure all works well with BIG. And, since I do not speak python, I am not sure I re-created all of the functions in the original unbound-dhcp-leases-bridge python script.
It is all written in bash. Let me know if you are interested.
I’d be interested. I’ve been through 13254 – CU 177 - LOTS of unbound restarts (1000s per week) and it looks like you were posting there but you have not attached your final script? Perhaps it could interest the devs.
The two approaches for the task “announce DHCP information ( name, IP ) to DNS server unbound” are a bit different:
unbound-dhcp-leases-bridge watches the DHCP leases storage, produces a file in unbound syntax and informs unbound about this change. This is done by a reload of the config, the leases-bridge file is included in the unbound.conf file.commit, release, expire a lease ). The action chosen is a unbound_control operation ( add local data, delete local data ).My experience with these two implementations is, that the first does a little restart. In case of experiments with RPZ it resets the timer for updates of the RPZ definitions.
The second method just hands over the (name, IP ) information without touching other processes inside unbound.
The first does heaps of restarts and is not really a viable solution. It does plenty of unnecessary restarts as well, when the file it generates is the same as the file it replaces.
This is just with 4 - 5 leases in the file:
Mar 22 12:39:11 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 12:49:54 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 12:50:00 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:20:18 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:22:48 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:23:48 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:24:17 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:27:35 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:28:04 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:28:47 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:29:06 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:31:53 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:55:18 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 14:55:35 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 15:25:30 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 15:25:35 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 15:55:41 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 15:55:46 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:25:59 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:26:58 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:28:27 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:45:33 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:49:53 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:50:40 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:56:16 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 16:56:57 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:05:51 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:08:26 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:20:44 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:26:31 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:33:30 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:36:53 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:50:41 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:56:40 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 17:56:57 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:03:33 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:16:14 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:20:50 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:26:54 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:29:11 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:38:08 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:45:14 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:50:53 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:53:15 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:57:06 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 18:57:21 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:20:49 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:23:17 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:27:32 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:39:30 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:50:51 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:57:06 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 19:57:46 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:09:32 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:20:53 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:27:57 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:39:36 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:50:52 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 20:57:07 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:09:35 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:20:50 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:28:00 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:34:21 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:39:36 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 21:50:52 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 22:09:38 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
Mar 22 22:20:54 gateway unbound: [1917:0] notice: Restart of unbound 1.19.1.
I run this command to help determine if my changes are helping (or not).
find /var/log -iname "messages*" | sort -Vr | tail -15 | \
xargs -I % bash -c 'echo ; printf "% \t" % ; \
grep --color -c "start of service" <(zcat -f %) ; \
grep --color "CORE UPGR:" <(zcat -f %)'
In the beginning the numbers are high (Sep 2023), but now nice and low!
[root@ipfire ~] # find /var/log -iname "messages*" | sort -Vr | tail -53 | xargs -I % bash -c 'echo ; printf "% \t" % ; \
grep --color -c "start of service" <(zcat -f %) ; \
grep --color "CORE UPGR:" <(zcat -f %)'
/var/log/messages.28.gz 612
/var/log/messages.27.gz 453
/var/log/messages.26.gz 11
/var/log/messages.25.gz 17
Sep 28 13:57:11 ipfire pakfire: CORE UPGR: Upgrading from release 178 to 179
/var/log/messages.24.gz 5
/var/log/messages.23.gz 623
/var/log/messages.22.gz 527
Oct 16 19:28:34 ipfire pakfire: CORE UPGR: Upgrading from release 179 to 180
/var/log/messages.21.gz 2925
/var/log/messages.20.gz 4089
/var/log/messages.19.gz 4115
/var/log/messages.18.gz 1113
/var/log/messages.17.gz 999
/var/log/messages.16.gz 4234
Nov 26 10:17:01 ipfire pakfire: CORE UPGR: Upgrading from release 180 to 181
/var/log/messages.15.gz 3089
/var/log/messages.14.gz 10
/var/log/messages.13.gz 2
/var/log/messages.12.gz 0
/var/log/messages.11.gz 0
/var/log/messages.10.gz 6
Jan 7 13:07:34 ipfire pakfire: CORE UPGR: Upgrading from release 181 to 182
/var/log/messages.9.gz 3
/var/log/messages.8.gz 1
/var/log/messages.7.gz 5
/var/log/messages.6.gz 246
/var/log/messages.5.gz 8
/var/log/messages.4.gz 1
/var/log/messages.3.gz 131
/var/log/messages.2.gz 35
/var/log/messages.1.gz 4
/var/log/messages 7
[root@ipfire ~] #
WARNING: This is an alpha script. Please experiment in a test environment!
this is the latest and greatest Proof-of-Concept script. There are comments in the files that might help.
Here is the script. Please install this script first. It is named dhcpEvent.sh:
#!/bin/bash
# DHCP commit/release/expiry status drives this process
############### following 7 lines for testing only ###############
# Kill the unbound-dhcp-leases-bridge process
pgrep -f unbound-dhcp-leases-bridge &&
kill -s SIGTERM $(pgrep -d',' -f unbound-dhcp-leases-bridge) &&
/usr/bin/logger --tag dhcpEvent "terminated unbound-dhcp-leases-bridge"
# chmod -v 744 /root/dhcpdconf/dhcpEvent_vN.sh
# ln -vsf /root/dhcpdconf/dhcpEvent_vN.sh /root/dhcpdconf/dhcpEvent.sh
#-------------------------------------------------------------------------
dhcpCREstatus="${1:-}"
clientIP="${2:-}"
clientHostname="${3:-}"
unboundDHCPleases="/etc/unbound/dhcp-leases.conf"
unboundStaticHosts="/etc/unbound/hosts.conf"
TTL="60" # time to live (seconds)
tagName="dhcpEv27" # to be "dhcpEvent"
############### Functions ###############
# write A & PTR records to unbound
#
write-unbound () {
local IPaddr
local clientName
local revIP
local recA
local recPTR
IPaddr=$1
clientName=$2
# create reverse IP for arpa name
revIP=$( echo "${IPaddr}" | /usr/bin/awk -F. '{print $4 "." $3 "." $2 "." $1}' )
# create "A" record and "PTR" record for unbound
recA="${clientName}.${DOMAINNAME}. ${TTL} IN A ${IPaddr}"
recPTR="${revIP}.in-addr.arpa. ${TTL} IN PTR ${clientName}.${DOMAINNAME}."
# send A & PTR records to unbound and dhcp-leases file
echo -e "${recA}\n${recPTR}" | /usr/sbin/unbound-control local_datas
echo "local-data: \"${recA}\"" >> "${unboundDHCPleases}"
echo "local-data: \"${recPTR}\"" >> "${unboundDHCPleases}"
msg_log "${dhcpCREstatus}: added A & PTR records to unbound"
}
# delete A & PTR records from unbound, by IP address
#
delete_unbound () {
local IPaddr
local revIP
local fqdn
local deleteList
local IPaddr=$1
# need IP address to get FQDN and arpa name
revIP=$( echo "${IPaddr}" | /usr/bin/awk -F. '{print $4 "." $3 "." $2 "." $1}' )
fqdn=$( /bin/grep --word-regexp --ignore-case "${IPaddr}" <<< "${ucList}" | \
/usr/bin/awk '{ print $1 }' )
# does a FQDN exist for this IP address? If yes, then remove
if [[ -n "${fqdn}" ]] ; then
# remove fqdn names from unbound AND dhcp-leases file
# look for multiple instances of fqdn (client hostname.domain)
deleteList=$( /bin/grep --word-regexp --ignore-case "${fqdn}" <<< "${ucList}" | \
/usr/bin/awk '{ print $1 }' )
# delete from unbound cache
echo "${deleteList}" | /usr/sbin/unbound-control local_datas_remove
# delete from dhcp-leases.conf file
/bin/sed --in-place "/\b${fqdn}/d" "${unboundDHCPleases}"
msg_log "${dhcpCREstatus}: references to ${fqdn} removed from unbound"
else
msg_log "${dhcpCREstatus}: Oops, no FQDN - exit"
return 1
fi
}
# send message to message log
msg_log () {
if tty --silent ; then
echo "${tagName}:" "$*"
else
/usr/bin/logger --tag "${tagName}" "$*"
fi
}
############### Main ###############
# check parameter count
if (( "$#" < 2 )) || (( $# > 3 )); then
msg_log "Illegal number of parameters - exit"
exit 1
fi
# simple check for valid IP addr ( may be too simple! )
if ! /bin/grep --quiet --extended-regexp '[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}' <<< "${clientIP}" ; then
msg_log "${clientIP} is an invalid IP address - exit"
exit
fi
# need DOMAINNAME value
eval "$(/usr/local/bin/readhash /var/ipfire/main/settings)"
# remove invalid characters in client hostname
#clientHostname=$( echo "${clientHostname}" | /bin/sed 's/[^A-Za-z0-9.-]/_/g' )
# end hostname at first invalid character
clientHostname=$( echo "${clientHostname}" | /bin/sed 's/[^A-Za-z0-9.-]/_/g' | /usr/bin/awk -F_ '{print $1}' )
echo "clientHostname = ${clientHostname}"
# get existing records from unbound-control list_local_data
ucList=$( /usr/sbin/unbound-control list_local_data | /bin/grep -i "${DOMAINNAME}" | expand -t1 )
# Does this Record A already exist?
UC_RecA=$( /bin/grep --ignore-case "^${clientHostname}\.${DOMAINNAME}.*${clientIP}$" <<< "${ucList}" )
# find IP addr in unbound
UC_IP=$( /bin/grep --word-regexp "${clientIP}" <<< "${ucList}" )
# find client name, at start of line, in unbound (looking for record A)
UC_FQDN=$( /bin/grep --word-regexp --ignore-case "^${clientHostname}\.${DOMAINNAME}" <<< "${ucList}" )
case "${dhcpCREstatus}" in
commit)
# if client hostname is blank then exit
if [[ -z "${clientHostname}" ]] ; then
msg_log "${dhcpCREstatus}: received IP ${clientIP} but missing client hostname - exit"
exit
fi
# if client exists in static hosts then exit
if /bin/grep --word-regexp --quiet --ignore-case -e "${clientIP}" -e "${clientHostname}" "${unboundStaticHosts}"
then
msg_log "${dhcpCREstatus}: ${clientHostname} or ${clientIP} found in static hosts - exit"
exit
fi
# (ip fqdn)
if [[ -n "${UC_RecA}" ]] ; then
# existing IP and existing FQDN # ( 1 1 )
msg_log "${dhcpCREstatus}: unbound hostname & IP already exist - exit"
exit
else
if [[ -z "${UC_IP}" ]] ; then
# New IP address! - write info to unbound & dhcp-leases.conf # ( 0 0/1 )
write-unbound "${clientIP}" "${clientHostname}"
else
# Existing IP address!
if [[ -z "${UC_FQDN}" ]] ; then
# Existing IP and new FQDN
# hostname/fqdn changed - delete A & PTR records from unbound # ( 1 0 )
delete_unbound "${clientIP}"
# add new to unbound!
write-unbound "${clientIP}" "${clientHostname}"
fi
fi
fi
;;
release|expiry)
# NOTE: expiry & release are the same since I don't understand the difference :-(
if [[ -z "${clientIP}" ]] ; then
msg_log "${dhcpCREstatus}: missing client IP address - exit"
exit 1
fi
# does IP addr appear in unbound? if yes, delete lines
if [[ -n "${UC_IP}" ]] ; then
delete_unbound "${clientIP}"
else
msg_log "${dhcpCREstatus}: ${clientIP} not found in unbound - done"
fi
;;
*)
msg_log "CRE script: case = no status - exit"
exit
;;
esac
exit
This file must be made executable.
When the script is run, the script will check and make sure the unbound-dhcp-leases-bridge is not running. If it is running, it will terminate it.
And here is the config file. This files goes here: /var/ipfire/dhcp/dhcpd.conf.local
# This file CAN be modified by the user.
# If this file is not needed, just delete the text.
# But, DO NOT completely delete this file!
#
#
# DHCP will fail with an odd message such as:
#
# [root@ipfire ~] # /etc/rc.d/init.d/dhcp start
# Starting DHCP Server... [ FAIL ]
# Starting Unbound DHCP Leases Bridge... [ OK ]
# [root@ipfire ~] # chmod: cannot access '/var/run/dhcpd.pid': No such file or directory
#
#
# commit
#
on commit {
set ClientIP = binary-to-ascii(10, 8, ".", leased-address);
#set NoName = concat("dhcp-", binary-to-ascii(10, 8, "-", leased-address));
# if preferred, NoName can be changed to blank. and then ignored in execute script
set NoName = "";
set ClientName = pick-first-value(option host-name, config-option-host-name, client-name, NoName);
# a MAC address can easily be added for other uses. MAC is not needed for DNS
log(concat("CRE-Commit: ClientIP: ", ClientIP, " Name: ", ClientName));
execute("/root/dhcpdconf/dhcpEvent.sh", "commit", ClientIP, ClientName);
}
#
# release
#
on release {
set ClientIP = binary-to-ascii(10, 8, ".", leased-address);
#set NoName = concat("dhcp-", binary-to-ascii(10, 8, "-", leased-address));
set NoName = "";
set ClientName = pick-first-value(option host-name, config-option-host-name, client-name, NoName);
log(concat("CRE-Release: ClientIP: ", ClientIP, " Name: ", ClientName));
execute("/root/dhcpdconf/dhcpEvent.sh", "release", ClientIP, ClientName);
}
#
# expiry
#
on expiry {
set ClientIP = binary-to-ascii(10, 8, ".", leased-address);
set ClientName = "";
log(concat("CRE-Expiry: ClientIP: ", ClientIP, " Name: ", ClientName));
execute("/root/dhcpdconf/dhcpEvent.sh", "expiry", ClientIP, "");
}
Make sure this line in the config file is correct:
execute("/root/dhcpdconf/dhcpEvent.sh", . . .
My path to dhcpEvent.sh is probably different than your path. There are three (3) execute lines in the config file.
If something goes wrong, just remove the text from dhcpd.conf.local and save a empty file. Then do a /etc/init.d/unbound restart. Everything will return to default.
After installing the above I get no unbound restarts. Except for the manual ones I cause with rpz testing.
WARNING: This is an alpha script. Please experiment in a test environment!
I have something working to stop most of the unnecessary restarts. You need to edit /usr/sbin/unbound-dhcp-leases-bridge. At the top add import filecmp with the other imports. Then change class UnboundConfigWriter(object): to:
class UnboundConfigWriter(object):
def __init__(self, path):
self.path = path
def update_dhcp_leases(self, leases):
# Write out all leases
if self.write_dhcp_leases(leases):
log.debug("Reloading Unbound...")
# Reload the configuration without dropping the cache
self._control("reload_keep_cache")
else:
log.debug("Not reloading Unbound. Nothing changed.")
def write_dhcp_leases(self, leases):
log.debug("Writing DHCP leases...")
with tempfile.NamedTemporaryFile(mode="w", delete=False) as f:
for l in leases:
for rr in l.rrset:
f.write("local-data: \"%s\"\n" % " ".join(rr))
filecmp.clear_cache()
RequeirUnboundReload = not filecmp.cmp(f.name, self.path, shallow=False)
# Make file readable for everyone
os.chmod(f.name, stat.S_IRUSR|stat.S_IWUSR|stat.S_IRGRP|stat.S_IROTH)
# Move the file to its destination
os.rename(f.name, self.path)
return RequeirUnboundReload
def _control(self, *args):
command = ["unbound-control"]
command.extend(args)
try:
subprocess.check_output(command)
# Log any errors
except subprocess.CalledProcessError as e:
log.critical("Could not run %s, error code: %s: %s" % (
" ".join(command), e.returncode, e.output))
raise e
Note, if you are doing the changes manually I have outdented (?) a few lines in write_dhcp_leases to take them outside the with statement or the filecmp always shows a change because the new file has not been terminated. I also changed the os.fchmod to use os.chmod
This is possibly not quite the final version as I want to see if I can sort the leases variable before it is used so it is always in the same order as I’ve seen the order changed although the effective contents was the same and this caused an unnecessary restart.
This reduces the number of reloads/restarts, but doesn’t stops them.
@jon’s version produces no reloads for new DHCP info. The only restarts are initiated by a config change e.g.
Totally agreed. That way mine is just a hack to reduce the reloads and it leverages the current script. I have no real knowledge of the Unbound or Dhcp API’s so would not be able to do what Jon’s done. And I don’t have the Python skills to convert his script to python.
I have no idea of the process of getting a fix submitted? If Jon’s is good, how do we get it implemented? Or even my quick and dirty patch?
FYI, my output of the test in post #12 is
/var/log/messages.52.gz 0
/var/log/messages.51.gz 2
/var/log/messages.50.gz 0
/var/log/messages.49.gz 3
Apr 18 18:40:33 BitschCop pakfire: CORE UPGR: Upgrading from release 173 to 174
/var/log/messages.48.gz 5
/var/log/messages.47.gz 6
/var/log/messages.46.gz 0
/var/log/messages.45.gz 0
/var/log/messages.44.gz 0
/var/log/messages.43.gz 0
/var/log/messages.42.gz 0
/var/log/messages.41.gz 6
Jun 14 22:59:45 BitschCop pakfire: CORE UPGR: Upgrading from release 174 to 175
/var/log/messages.40.gz 0
/var/log/messages.39.gz 0
/var/log/messages.38.gz 0
/var/log/messages.37.gz 2
Jul 11 22:11:01 BitschCop pakfire: CORE UPGR: Upgrading from release 175 to 176
/var/log/messages.36.gz 3
/var/log/messages.35.gz 5
/var/log/messages.34.gz 2
/var/log/messages.33.gz 229
Aug 6 10:41:23 BitschCop pakfire: CORE UPGR: Upgrading from release 176 to 177
/var/log/messages.32.gz 290
/var/log/messages.31.gz 692
Aug 20 20:58:04 BitschCop pakfire: CORE UPGR: Upgrading from release 177 to 178
/var/log/messages.30.gz 571
/var/log/messages.29.gz 433
/var/log/messages.28.gz 659
/var/log/messages.27.gz 596
/var/log/messages.26.gz 494
/var/log/messages.25.gz 589
Oct 6 21:19:09 BitschCop pakfire: CORE UPGR: Upgrading from release 178 to 179
/var/log/messages.24.gz 622
Oct 13 11:47:57 BitschCop pakfire: CORE UPGR: Upgrading from release 179 to 180
/var/log/messages.23.gz 666
/var/log/messages.22.gz 639
/var/log/messages.21.gz 743
/var/log/messages.20.gz 600
/var/log/messages.19.gz 709
/var/log/messages.18.gz 790
/var/log/messages.17.gz 993
Nov 30 13:36:56 BitschCop pakfire: CORE UPGR: Upgrading from release 180 to 181
/var/log/messages.16.gz 906
/var/log/messages.15.gz 879
/var/log/messages.14.gz 886
/var/log/messages.13.gz 907
/var/log/messages.12.gz 809
Jan 4 12:35:51 BitschCop pakfire: CORE UPGR: Upgrading from release 181 to 182
/var/log/messages.11.gz 606
/var/log/messages.10.gz 920
/var/log/messages.9.gz 921
/var/log/messages.8.gz 970
/var/log/messages.7.gz 908
/var/log/messages.6.gz 918
Feb 13 22:01:13 BitschCop pakfire: CORE UPGR: Upgrading from release 182 to 183
/var/log/messages.5.gz 982
/var/log/messages.4.gz 873
/var/log/messages.3.gz 523
/var/log/messages.2.gz 5
Mar 15 16:01:42 BitschCop pakfire: CORE UPGR: Upgrading from release 183 to 184
/var/log/messages.1.gz 2
/var/log/messages 0
I started to use the DHCP event way a short time before the CU 184 installation.
I have not dug into what populates /etc/unbound/dhcp-leases.conf, but from observation it is only DHCP leases which are not covered in the hosts file. If there is an entry in the hosts file, it does not appear in the dhcp-leases.conf. That makes sense as the dhcp-leases.conf contains A and PTR records which are not needed if they are covered by the hosts file.
Every time one of the affected devices renews its lease, /var/state/dhcp/dhcpd.leases gets updated. This triggers the unbound-dhcp-leases-bridge, and normally this then writes to the dhcp-leases.conf and restarts unbound. Every time. It can be mitigated by increasing the lease time, but on a default 60/120, restarts will happen quite a lot.
I have no idea what else may affect that file. I am also using CU 184.