[PATCH 1/3] unbound-dhcp-leases-bridge : fix bug 12694 - DHCP hosts not reliably propagated to DNS
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files. --- unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
+ # base mask for a completed file change + mask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO + # IN_MODIFY since dhcpd appends lease updates to an open file + self.watches = { + self.leases_file: mask | inotify.constants.IN_MODIFY, + self.fix_leases_file: mask, + self.hosts_file: mask + } + self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup - self.hosts = self.read_static_hosts() - self.update_dhcp_leases() + update_hosts = True + update_leases = True + + i = inotify.adapters.Inotify()
- i = inotify.adapters.Inotify([ - self.leases_file, - self.fix_leases_file, - self.hosts_file, - ]) + for f in self.watches: + i.add_watch(os.path.dirname(f), self.watches[f])
for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
+ # Make pending updates once inotify queue is empty if event is None: + if update_hosts: + self.hosts = self.read_static_hosts() + update_hosts = False + if update_leases: + self.update_dhcp_leases() + update_leases = False continue
header, type_names, watch_path, filename = event
- # Update leases after leases file has been modified - if "IN_MODIFY" in type_names: - # Reload hosts - if watch_path == self.hosts_file: - self.hosts = self.read_static_hosts() + file = os.path.join(watch_path, filename) + + if not file in self.watches: + continue + + log.debug("Inotify %s: %s", file, " ".join(type_names))
- self.update_dhcp_leases() + update_leases = True
- # If the file is deleted, we re-add the watcher - if "IN_IGNORED" in type_names: - i.add_watch(watch_path) + if file == self.hosts_file: + update_hosts = True
log.info("Unbound DHCP Leases Bridge terminated")
The script is rereading the ethernet and dhcp settings files for every lease in every update. Since dhcpd does not have a reload mechanism and is just restarted for settings changes, and so this bridge is restarted too, it seems fine just to read these at startup. --- unbound-dhcp-leases-bridge | 69 ++++++++++++++++++++------------------ 1 file changed, 36 insertions(+), 33 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index 6e22066..814cf0c 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -329,6 +329,42 @@ class FixLeases(object):
return leases
+def read_settings(filename): + settings = {} + + with open(filename) as f: + for line in f.readlines(): + # Remove line-breaks + line = line.rstrip() + + k, v = line.split("=", 1) + settings[k] = v + + return settings + +def load_subnets(): + # Load ethernet settings + ethernet_settings = read_settings("/var/ipfire/ethernet/settings") + + # Load DHCP settings + dhcp_settings = read_settings("/var/ipfire/dhcp/settings") + + subnets = {} + for zone in ("GREEN", "BLUE"): + if not dhcp_settings.get("ENABLE_%s" % zone) == "on": + continue + + netaddr = ethernet_settings.get("%s_NETADDRESS" % zone) + submask = ethernet_settings.get("%s_NETMASK" % zone) + + subnet = ipaddress.ip_network("%s/%s" % (netaddr, submask)) + domain = dhcp_settings.get("DOMAIN_NAME_%s" % zone) + + subnets[subnet] = domain + + return subnets + +subnets = load_subnets()
class Lease(object): def __init__(self, ipaddr, properties): @@ -396,25 +432,6 @@ class Lease(object):
@property def domain(self): - # Load ethernet settings - ethernet_settings = self.read_settings("/var/ipfire/ethernet/settings") - - # Load DHCP settings - dhcp_settings = self.read_settings("/var/ipfire/dhcp/settings") - - subnets = {} - for zone in ("GREEN", "BLUE"): - if not dhcp_settings.get("ENABLE_%s" % zone) == "on": - continue - - netaddr = ethernet_settings.get("%s_NETADDRESS" % zone) - submask = ethernet_settings.get("%s_NETMASK" % zone) - - subnet = ipaddress.ip_network("%s/%s" % (netaddr, submask)) - domain = dhcp_settings.get("DOMAIN_NAME_%s" % zone) - - subnets[subnet] = domain - address = ipaddress.ip_address(self.ipaddr)
for subnet in subnets: @@ -424,20 +441,6 @@ class Lease(object): # Fall back to localdomain if no match could be found return "localdomain"
- @staticmethod - def read_settings(filename): - settings = {} - - with open(filename) as f: - for line in f.readlines(): - # Remove line-breaks - line = line.rstrip() - - k, v = line.split("=", 1) - settings[k] = v - - return settings - @property def fqdn(self): if self.hostname:
Minor tweaks to logging which were helpful while debugging, including logging to stderr when running in foreground. --- unbound-dhcp-leases-bridge | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index 814cf0c..17a00f6 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -26,6 +26,7 @@ import ipaddress import logging import logging.handlers import os +import sys import re import signal import stat @@ -36,22 +37,21 @@ import inotify.adapters
LOCAL_TTL = 60
+log = logging.getLogger("dhcp-bridge") + def setup_logging(loglevel=logging.INFO): - log = logging.getLogger("dhcp") log.setLevel(loglevel) - - handler = logging.handlers.SysLogHandler(address="/dev/log", facility="daemon") + if args.daemon: + handler = logging.handlers.SysLogHandler(address="/dev/log", facility="daemon") + else: + handler = logging.StreamHandler(sys.stderr) handler.setLevel(loglevel)
- formatter = logging.Formatter("%(name)s[%(process)d]: %(message)s") + formatter = logging.Formatter("%(name)s: %(message)s") handler.setFormatter(formatter)
log.addHandler(handler)
- return log - -log = logging.getLogger("dhcp") - def ip_address_to_reverse_pointer(address): parts = address.split(".") parts.reverse() @@ -602,7 +602,7 @@ if __name__ == "__main__": bridge = UnboundDHCPLeasesBridge(args.dhcp_leases, args.fix_leases, args.unbound_leases, args.hosts)
- ctx = daemon.DaemonContext(detach_process=args.daemon) + ctx = daemon.DaemonContext(detach_process=args.daemon, stderr=(None if args.daemon else sys.stderr)) ctx.signal_map = { signal.SIGHUP : bridge.update_dhcp_leases, signal.SIGTERM : bridge.terminate,
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Sorry for interrupting this train of thought. Wouldn’t it be easier to use the tools available from dhcpd?
dhcpd seems to have a way execute commands. And I would guess this would be cleaner than "watching" a file.
There are three execute commands: on commit on release on expiry
and these could be used to launch the needed unbound bridge command.
Here is where I found this: https://jpmens.net/2011/07/06/execute-a-script-when-isc-dhcp-hands-out-a-new... https://jpmens.net/2011/07/06/execute-a-script-when-isc-dhcp-hands-out-a-new-lease/
And here is additional info: https://wiki.samba.org/index.php/Configure_DHCP_to_update_DNS_records https://wiki.samba.org/index.php/Configure_DHCP_to_update_DNS_records
(Search for "on commit" on this page)
Jon
On Mar 28, 2022, at 12:00 PM, Michael Tremer <michael.tremer@ipfire.org mailto:michael.tremer@ipfire.org> wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading <ajrh@ajrh.net mailto:ajrh@ajrh.net> wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info http://log.info/("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Since I'm new here, and was just aiming for a (somewhat) minimal inotify bug-fix, I defer and won't comment. But I was unaware of the capability and appreciate the pointer.
On Mon, Mar 28, 2022, at 3:32 PM, Jon Murphy wrote:
Sorry for interrupting this train of thought. Wouldn’t it be easier to use the tools available from dhcpd?
dhcpd seems to have a way execute commands. And I would guess this would be cleaner than "watching" a file.
There are three execute commands: on commit on release on expiry
and these could be used to launch the needed unbound bridge command.
Here is where I found this: https://jpmens.net/2011/07/06/execute-a-script-when-isc-dhcp-hands-out-a-new...
And here is additional info: https://wiki.samba.org/index.php/Configure_DHCP_to_update_DNS_records
(Search for "on commit" on this page)
Jon
On Mar 28, 2022, at 12:00 PM, Michael Tremer michael.tremer@ipfire.org wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
- # base mask for a completed file change
- mask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO
- # IN_MODIFY since dhcpd appends lease updates to an open file
- self.watches = {
- self.leases_file: mask | inotify.constants.IN_MODIFY,
- self.fix_leases_file: mask,
- self.hosts_file: mask
- }
self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
- self.hosts = self.read_static_hosts()
- self.update_dhcp_leases()
- update_hosts = True
- update_leases = True
- i = inotify.adapters.Inotify()
- i = inotify.adapters.Inotify([
- self.leases_file,
- self.fix_leases_file,
- self.hosts_file,
- ])
- for f in self.watches:
- i.add_watch(os.path.dirname(f), self.watches[f])
for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
- # Make pending updates once inotify queue is empty
if event is None:
- if update_hosts:
- self.hosts = self.read_static_hosts()
- update_hosts = False
- if update_leases:
- self.update_dhcp_leases()
- update_leases = False
continue
header, type_names, watch_path, filename = event
- # Update leases after leases file has been modified
- if "IN_MODIFY" in type_names:
- # Reload hosts
- if watch_path == self.hosts_file:
- self.hosts = self.read_static_hosts()
- file = os.path.join(watch_path, filename)
- if not file in self.watches:
- continue
- log.debug("Inotify %s: %s", file, " ".join(type_names))
- self.update_dhcp_leases()
- update_leases = True
- # If the file is deleted, we re-add the watcher
- if "IN_IGNORED" in type_names:
- i.add_watch(watch_path)
- if file == self.hosts_file:
- update_hosts = True
log.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Hello,
This is indeed an absolute nightmare what I built here.
It has some advantages over the alternatives of which one is to have the DHCP server execute a couple of commands. The problems there are as follows:
* unbound does not keep a state, so we will have to make sure that we keep the state of all records somewhere and can reload it when the system roboots.
* I have installations with thousands of devices in a single subnet. The DHCP server would just be busy constantly executing any commands which would cause a lot of load. The current Python bridge can use up to 40% of one CPU core at busy times on the same system. I would argue that this approach does not scale well.
* RFC2136 would be great, but we lack too many things to run this properly.
That being said, this is not a great way to solve this problem. I would like to replace some components entirely but probably not soon. The approach that we have works and - apart from the bug - doesn’t suck too hard. Should we do it this way again? No, but we had to try to learn that lesson.
-Michael
On 28 Mar 2022, at 20:32, Jon Murphy jcmurphy26@gmail.com wrote:
Sorry for interrupting this train of thought. Wouldn’t it be easier to use the tools available from dhcpd?
dhcpd seems to have a way execute commands. And I would guess this would be cleaner than "watching" a file.
There are three execute commands: on commit on release on expiry
and these could be used to launch the needed unbound bridge command.
Here is where I found this: https://jpmens.net/2011/07/06/execute-a-script-when-isc-dhcp-hands-out-a-new...
And here is additional info: https://wiki.samba.org/index.php/Configure_DHCP_to_update_DNS_records
(Search for "on commit" on this page)
Jon
On Mar 28, 2022, at 12:00 PM, Michael Tremer michael.tremer@ipfire.org wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Hello Michael,
That was exactly it, just sidestepping an intuitive race with dhcpd writing. Somewhat hypothetical why that would happen, e.g. clustered updates for multiple NICs or whatever similar non-atomicity, but it was easy to express that way, put the update logic in one place (including the initial one at startup), and made the event timestamps sequences a little easier to follow when it wasn't clear why the updates were getting lost at all. I thought the boolean variables helped document the admittedly simple logic too. But none of that is critical.
A
On Mon, Mar 28, 2022, at 1:00 PM, Michael Tremer wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Hello,
On 28 Mar 2022, at 20:55, Anthony Heading ajrh@ajrh.net wrote:
Hello Michael,
That was exactly it, just sidestepping an intuitive race with dhcpd writing. Somewhat hypothetical why that would happen, e.g. clustered updates for multiple NICs or whatever similar non-atomicity, but it was easy to express that way, put the update logic in one place (including the initial one at startup), and made the event timestamps sequences a little easier to follow when it wasn't clear why the updates were getting lost at all. I thought the boolean variables helped document the admittedly simple logic too. But none of that is critical.
Okay. Thank you for the explanation.
I will take this into account, but I will add some more changes, since we are performing a reload every time something changes which is causing a lot of load on busy systems.
Reloading this all multiple times a second isn’t a good idea. We should rather reload and then wait at least 5 seconds and then reload again if we had another inotify event.
This is probably slightly unrelated with your patch, but since we are already on it, I would like to have those changes implemented now.
I will get back to the list with those changes and submit them for review.
Best, -Michael
A
On Mon, Mar 28, 2022, at 1:00 PM, Michael Tremer wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Please see the patch set that I just posted which is strongly based on your patches, but incorporates a couple of new changes, too.
Let me know if this looks good to you.
Best, -Michael
On 29 Mar 2022, at 10:39, Michael Tremer michael.tremer@ipfire.org wrote:
Hello,
On 28 Mar 2022, at 20:55, Anthony Heading ajrh@ajrh.net wrote:
Hello Michael,
That was exactly it, just sidestepping an intuitive race with dhcpd writing. Somewhat hypothetical why that would happen, e.g. clustered updates for multiple NICs or whatever similar non-atomicity, but it was easy to express that way, put the update logic in one place (including the initial one at startup), and made the event timestamps sequences a little easier to follow when it wasn't clear why the updates were getting lost at all. I thought the boolean variables helped document the admittedly simple logic too. But none of that is critical.
Okay. Thank you for the explanation.
I will take this into account, but I will add some more changes, since we are performing a reload every time something changes which is causing a lot of load on busy systems.
Reloading this all multiple times a second isn’t a good idea. We should rather reload and then wait at least 5 seconds and then reload again if we had another inotify event.
This is probably slightly unrelated with your patch, but since we are already on it, I would like to have those changes implemented now.
I will get back to the list with those changes and submit them for review.
Best, -Michael
A
On Mon, Mar 28, 2022, at 1:00 PM, Michael Tremer wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Michael,
Looks great to me. Glad we're getting it fixed. Only very minor comments:
1) It looks like stderr is now left open even in daemon mode? I doubt it's connected to anything that would block, nor even that anything is actually written to stderr, but not sure if you intended it.
2) More generally, the bridge is somewhat taciturn in comparison to both dhcpd and unbound, I think a little more logging by default would be helpful for users looking at the syslog logs. Either adding a single '-v' to the init.d script, or perhaps you might want to rebalance it differently, but logging the DNS changes that are being made would be very useful I think, and that would not be heavy when compared to what dhcpd is already generating in syslog.
Regards
Anthony
On Tue, Mar 29, 2022, at 7:35 AM, Michael Tremer wrote:
Please see the patch set that I just posted which is strongly based on your patches, but incorporates a couple of new changes, too.
Let me know if this looks good to you.
Best, -Michael
On 29 Mar 2022, at 10:39, Michael Tremer michael.tremer@ipfire.org wrote:
Hello,
On 28 Mar 2022, at 20:55, Anthony Heading ajrh@ajrh.net wrote:
Hello Michael,
That was exactly it, just sidestepping an intuitive race with dhcpd writing. Somewhat hypothetical why that would happen, e.g. clustered updates for multiple NICs or whatever similar non-atomicity, but it was easy to express that way, put the update logic in one place (including the initial one at startup), and made the event timestamps sequences a little easier to follow when it wasn't clear why the updates were getting lost at all. I thought the boolean variables helped document the admittedly simple logic too. But none of that is critical.
Okay. Thank you for the explanation.
I will take this into account, but I will add some more changes, since we are performing a reload every time something changes which is causing a lot of load on busy systems.
Reloading this all multiple times a second isn’t a good idea. We should rather reload and then wait at least 5 seconds and then reload again if we had another inotify event.
This is probably slightly unrelated with your patch, but since we are already on it, I would like to have those changes implemented now.
I will get back to the list with those changes and submit them for review.
Best, -Michael
A
On Mon, Mar 28, 2022, at 1:00 PM, Michael Tremer wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
Hello,
On 30 Mar 2022, at 04:30, Anthony Heading ajrh@ajrh.net wrote:
Michael,
Looks great to me. Glad we're getting it fixed. Only very minor comments:
- It looks like stderr is now left open even in daemon mode? I doubt it's connected to anything that would block, nor even that anything is actually written to stderr, but not sure if you intended it.
Yeah, I couldn’t merge your patch straight away and so I carried over the change manually. Since I am not entirely sure what all the daemon stuff is doing there, I thought that it would be enough to do what I did.
I will look into it again and fix this. Thank you for pointing this out.
- More generally, the bridge is somewhat taciturn in comparison to both dhcpd and unbound, I think a little more logging by default would be helpful for users looking at the syslog logs. Either adding a single '-v' to the init.d script, or perhaps you might want to rebalance it differently, but logging the DNS changes that are being made would be very useful I think, and that would not be heavy when compared to what dhcpd is already generating in syslog.
Getting logging right is one of the hardest thing in software development I think. There is normally way too much logging or way too little. Balancing it exactly right is quite impossible for the developer, because they think about the program differently. I probably care about different things when writing software than a user.
I suppose changing the default log level doesn’t hurt anyone, and I suppose logging what you said into the syslog isn’t a bad idea. But is it needed during regular operation? No, because it should just work. We don’t want to clutter the logs with unnecessary stuff (there is already way too much in there that makes it impossible to follow it). I will have a look as well what I can change.
Best, -Michael
Regards
Anthony
On Tue, Mar 29, 2022, at 7:35 AM, Michael Tremer wrote:
Please see the patch set that I just posted which is strongly based on your patches, but incorporates a couple of new changes, too.
Let me know if this looks good to you.
Best, -Michael
On 29 Mar 2022, at 10:39, Michael Tremer michael.tremer@ipfire.org wrote:
Hello,
On 28 Mar 2022, at 20:55, Anthony Heading ajrh@ajrh.net wrote:
Hello Michael,
That was exactly it, just sidestepping an intuitive race with dhcpd writing. Somewhat hypothetical why that would happen, e.g. clustered updates for multiple NICs or whatever similar non-atomicity, but it was easy to express that way, put the update logic in one place (including the initial one at startup), and made the event timestamps sequences a little easier to follow when it wasn't clear why the updates were getting lost at all. I thought the boolean variables helped document the admittedly simple logic too. But none of that is critical.
Okay. Thank you for the explanation.
I will take this into account, but I will add some more changes, since we are performing a reload every time something changes which is causing a lot of load on busy systems.
Reloading this all multiple times a second isn’t a good idea. We should rather reload and then wait at least 5 seconds and then reload again if we had another inotify event.
This is probably slightly unrelated with your patch, but since we are already on it, I would like to have those changes implemented now.
I will get back to the list with those changes and submit them for review.
Best, -Michael
A
On Mon, Mar 28, 2022, at 1:00 PM, Michael Tremer wrote:
Hello Anthony,
Thank you very much for submitting this patch and welcome to the list.
I understand that it is easier to track any changes in the directory, but I don’t quite understand why the logic had to be changed that the changes will be applied at the end only.
Is this just to avoid that multiple updates happen one after the other or what are you trying to achieve?
-Michael
On 22 Mar 2022, at 03:47, Anthony Heading ajrh@ajrh.net wrote:
Switch from inotify watching individual files to monitoring the containing directories, as because dhcpd renames its leases file into a backup, monitoring the single inode does not work well. Additionally, python appears to have a bug with replacing expired inotify watches on single files.
unbound-dhcp-leases-bridge | 47 +++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 16 deletions(-)
diff --git unbound-dhcp-leases-bridge unbound-dhcp-leases-bridge index a2df5f1..6e22066 100644 --- unbound-dhcp-leases-bridge +++ unbound-dhcp-leases-bridge @@ -72,6 +72,15 @@ class UnboundDHCPLeasesBridge(object): self.fix_leases_file = fix_leases_file self.hosts_file = hosts_file
# base mask for a completed file changemask = inotify.constants.IN_CLOSE_WRITE | inotify.constants.IN_MOVED_TO# IN_MODIFY since dhcpd appends lease updates to an open fileself.watches = {self.leases_file: mask | inotify.constants.IN_MODIFY,self.fix_leases_file: mask,self.hosts_file: mask}- self.unbound = UnboundConfigWriter(unbound_leases_file) self.running = False
@@ -80,36 +89,42 @@ class UnboundDHCPLeasesBridge(object): self.running = True
# Initial setup
self.hosts = self.read_static_hosts()self.update_dhcp_leases()
update_hosts = Trueupdate_leases = Truei = inotify.adapters.Inotify()
i = inotify.adapters.Inotify([self.leases_file,self.fix_leases_file,self.hosts_file,])
for f in self.watches:i.add_watch(os.path.dirname(f), self.watches[f])for event in i.event_gen(): # End if we are requested to terminate if not self.running: break
# Make pending updates once inotify queue is empty if event is None:if update_hosts:self.hosts = self.read_static_hosts()update_hosts = Falseif update_leases:self.update_dhcp_leases()update_leases = False continue header, type_names, watch_path, filename = event
# Update leases after leases file has been modifiedif "IN_MODIFY" in type_names:# Reload hostsif watch_path == self.hosts_file:self.hosts = self.read_static_hosts()
file = os.path.join(watch_path, filename)if not file in self.watches:continuelog.debug("Inotify %s: %s", file, " ".join(type_names))
self.update_dhcp_leases()
update_leases = True
# If the file is deleted, we re-add the watcherif "IN_IGNORED" in type_names:i.add_watch(watch_path)
if file == self.hosts_file:update_hosts = Truelog.info("Unbound DHCP Leases Bridge terminated")
-- 2.34.1
-
Anthony Heading -
Jon Murphy -
Michael Tremer