Dhcp_host_domain_ng.py: Add_lease, hostname check failed

Noticed in 5.0.0 (HBT) that this is a very frequent message in logs (I have dynamic_domains enabled). Typically looks like this (and this is logged over and over again)

Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Jun  9 04:13:46 turris /dhcp_host_domain_ng.py: Refresh kresd leases

Looking at the code, the most common reason is that the host either has no name, or has underscores in the name, so it is not possible to put a hostname in DNS. That’s fine, but does it make sense to log it repeatedly? Most of my syslog is just this message.

1 Like

Underscores should be allowed already: https://gitlab.labs.nic.cz/turris/turris-os-packages/-/commit/3d33390c94bd570bea7571c24e39a03da6eba3cd#03cddcb71fc09bf2f78dd565d90691120e9cb918_21_20

Unfortunately I can’t see how to log it once per name or something (reasonably easily). The script is ran repeatedly, so it can’t well carry state across those invocations. /cc @paja in case he’s got an idea.

Logging the offending name might be nice generally (escaped somehow?), but by itself that would increase the logs rather than decrease them.

1 Like

A temporary file with a list of already reported hostnames? That could even come handy as the quickest source of the bad hostnames

you’re correct, it seems to be the ones with “blank” hostnames that are leading to the logging.

in my case some hostnames have lease refreshed/added normally (with upper/lower case letters, with dashes)
, but other ones still causing “wrong format in lease file” message to be in syslog (seems caused by hostnames with underscore in name)
, but luckily “hostname check failed” message are no longer in my syslog.

if i compare /tmp/dhcp.lease and /tmp/dhcp.lease.dynamic content. The ‘dhcp.lease" has lease time, mac_address, ip, hostname without local domain, 01:mac_address the "dhcp.lease.dynamic’ has only ip and hostname including local domain. btw: why there are two files ?

So what is wrong with format of that lease file? Is it still the “underscore” in name main root-cause or that last attribute “01:mac_address” or anything else? --> like expand hosts option in resolver/dnsmasq vs format/value of hostnames (in luci) and/or in /etc/hosts. I mean it might be that expanding hosts are/are not occuring at steps where needed.

Suprisingly my guest’s devices are server nicely (add lease, refresh lease) and i do not have them in hostnames (luci/hostnames or /etc/hosts).

1 Like

My whole logfile is full of these too.
So far I have been unable to find out why.

Sep  3 17:03:41 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:42 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:43 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:43 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:43 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:44 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:44 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:44 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:45 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:45 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:45 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:45 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:45 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:46 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:46 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:46 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:46 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:47 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:47 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:47 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep  3 17:03:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep  3 17:03:48 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep  3 17:03:48 turris /dhcp_host_domain_ng.py: Refresh kresd leases

I did investigate this a bit further by modifying /etc/resolver/dhcp_host_domain_ng.py to actually show also the type of operation, hostname and IP address for each of these “DHCP unknown update operation” lines.

What I found is that I get one line for each and every DHCP client connected to my router, apparently an “update” of the DHCP (don’t ask me why this happens so often, the lease time is configured to be 24h). After each of these updates, the kresd leases are refreshed.

For me this doesn’t happen “every once in a while” but the whole process is started again about every 2-3 minutes. For each host it takes about 2 seconds, given I have about 30 hosts, the system keeps writing these entries into the logfile almost all of the time in a 1s rythm… So far I haven’t understood what triggers this. Probably there’s a parameter somewhere to configure DHCP lease times default value?

Do you have ‘option leasefile’ in dhcp uci config? Are you using static or dynamic domains? (for some reason i have to use option static_domains '0' together with option dynamic_domains '1' in resolver uci config together with “expand hosts” in dhcp uci config (and rebind domain …).

I think you have issue with hostname check mainly. If you pass that check , kresd refresh might be fine actually. I think that “myhost” vs “myhost.mydomain.lan” will result in true for one and false for the other one depending on the static vs dynamic domain setup,…

I really see 100… lines every day without any idea what to do? Is there a guideline or resolution tips available? Is the option “static domains 0” dynamic domains “1” solving this issue or is it just a personal setting?

Thanks for any tip!

Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:17 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep 14 13:54:18 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed
Sep 14 13:54:18 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed

The only simple way I know right now is not to have *.lan names in DNS (checkbox in (re)Foris), in case you don’t need them.

btw: even if you manage to mitigate that failure and reduce syslog entries. You will have another three lines in syslog per each hostname.

2020-09-13 08:41:26 info /dhcp_host_domain_ng.py[]: DHCPv4 new lease
2020-09-13 08:41:26 info /dhcp_host_domain_ng.py[]: DHCP update hostname [old, xxxxxxx, xxxxxx]
2020-09-13 08:41:26 info /dhcp_host_domain_ng.py[]: Refresh kresd leases

So at the end your syslog will be flooded in similar way anyway.

notes

It will be nice to have some option/switch which will log only warning or/and errors. Aside i am now editing that python script and commenting the lines which are logging to syslog using LOG_INFO for “Add_leases” and “Refresh kresd leases” and “Refresh unbound leases”. Will see.
As second option, i see the syslog-ng and filtering/redirecting to own file and handle it aside.

+1.
Actually I went to a shop to buy a Netgear R7800 last Friday. This whole DNS/DHCP of the Turris MOX is just way too unstable right now to completely rely on it for Teleworking. I really like the approach, but the SW quality is just not there yet, as these issues show :frowning:

I have changed the py script to write the hostname which failed into the log. It seems like it fails where hostname is the wildcard * . Any ideas?

Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: DHCP unknown update operation
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Refresh kresd leases
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Add_lease, hostname check failed: *
Sep 15 08:43:48 turris /dhcp_host_domain_ng.py: Refresh kresd leases

1 Like

Which option do you mean?
This in Network Settings/DNS-> “Enable DHCP clients in DNS” This will enable your DNS resolver to place DHCP client’s names among the local DNS records.

However, that doesnt change anything?

Or do I need to go to advanced settings in the Network->DHCP & DNS area luci configuration?

It seems like there are time the router is flooded for 1-2 minutes which block full DHCP access to other clients for 1-2min. I really need to get rid of this. Thanks for a hint!

:thinking: that is the one I meant.

Ok, thanks. However, disabling the tick in reForis “enable dhcp clients in dns” doesnt change anything.

Is there a way to disableDhcp_host_domain_ng.py script completely?

I dont need dynamic or local DNS for local clients?

Just a quick update what I did and it seems to run more stable now:
I am on Turris 5.1.0
a) I added/changed the two lines manually in the .py file from here:

b) for each IP which could not be resolved (Add_lease, hostname check failed), I looked up the MAC address of the device and added a hostname entry into LUCI -> Network -> DHCP and DNS -> Static leases (just hostname and MAC).

These two steps seem to bring this under control in my environment.

3 Likes

… just adding my feedback …
For some time i have all fine. Add/Refresh/Delete lease steps were working fine. Yesterday i found that there are again “hostname check failed” with following “DHCP unknown operation” messages in syslog.

I did the diff/check of actual version with above linked change/fix. That does not helped much (later i found that there are hardcoded definitions for path where lease files are located. (i have them in /srv not in /tmp). That helped for most of the hosts/hostnames (dynamic domain ones). When i tried wlan0 to wlan1 or to gues0 wifis, it was having some more warnings (issue during delete and upcoming new add).
I found that one of static lease entry with “*” instead of hostname that in lease file (static one) is probably reason why it behave like that. --> causing warnings/errors during “kresd refresh lease” and “add_lease” steps.
So i’ve put that static-lease host /hostname to my LuCi/Hostnames (without domain suffix and in lower case) as well together with changing the /etc/hosts accordingly (i have only fullname entries there).

Now it seems that “dhcp uknown operation” is no longer poping-up in log neither “hostname check failed” during add/update(del/add) lease. In my case that * in lease file and missing entry in luci/hostnames was root cause. Seems my SmartTV is having option to change netbios name, but not hostname (actually i think there is none, so maybe that is reflected by * ).

I can confirm @datapool hints and script fix are working pretty nice. Just ensure that after adding static lease entry via Luci is reflected correctly in dhcp.lease (eventually add that static-lease host to luci/hostnames).

notes:

i am using different location for dhcp files instead of /tmp i have it /srv …so i had to change hardcoded path/locations in that .py script as well (and create dhcp.empty , that one was not present on my system so far). for backward compatibility i have symlink in /tmp created for each file. I am wondering why those locations in dhcp uci config are not used like any other uci entries.

It sounds like this should have been fixed, but I’m still getting it on 5.1.4 with Enable DHCP clients in DNS enabled or disabled in Foris.

Adding a static lease or hostname entry for every device that doesn’t have a hostname isn’t really a solution. Are there any other ways to fix it?