24.7.8 - ISC DHCPv4 does not register new leases in Unbound

[gyrex]

Important notices

Before you add a new report, we ask you kindly to acknowledge the following:

• I have read the contributing guide lines at https://github.com/opnsense/core/blob/master/CONTRIBUTING.md
• I am convinced that my issue is new after having checked both open and closed issues at https://github.com/opnsense/core/issues?q=is%3Aissue

Describe the bug

Note: This is a duplicate of Issue #7376 which was closed but it appears that there are other people who are experiencing this issue too. I opened a forum post on this issue here: https://forum.opnsense.org/index.php?topic=43814

New registered DHCP names are not registered inside the DNS (Unbound) even though so "Register ISC DHCP4 Leases" is enabled.

I think the issue is there since 24.1 but not 100%.
At least I can say it since 24.1.3.

To Reproduce

Steps to reproduce the behavior:

1. Register new hostname through DHCP
2. Request the IP via hostname from DNS -> no response
3. Reload Unbound server
4. Request the IP via hostname from DNS -> working

Expected behavior

Hostname should be registered automatically in the Unbound DNS.

Describe alternatives you considered

Restart of Unbound fixes the issue.

Screenshots

N/A

Relevant log files

Please let me know which logs are required

Additional context

Add any other context about the problem here.

Environment

OPNsense 24.7.8-amd64
Running under Proxmox 8.2.10

[fichtner]

The most common issue here is the unbound DHCP watcher daemon being stopped most likely because of garbage host names given by strange devices in the network. You can check if the watcher is running...

# pgrep -F /var/run/unbound_dhcpd.pid

Cheers,
Franco

[gyrex]

Thanks for your response Franco. I don't have an unbound_dhcp.pid process in that directory. I've got an unbound.pid and a unbound_logger.pid and unbound.pid is running.

What would you recommend in terms of logging to diagnose the issue?

[fichtner]

Just to be sure are we talking about dynamic or static leases from ISC DHCP?

[gyrex]

Dynamic

[fichtner]

Ok, and Services: Unbound DNS: General: Register ISC DHCP4 Leases is enabled?

[gyrex]

Sure is. Here's a screenshot of my settings.

[fichtner]

OK, When you hit apply there should be a /var/run/unbound_dhcpd.pid ? If not we can try running it manually...

[gyrex]

Sorry mate, I'm a little confused. It's always been selected so shouldn't that process be running already?

Edit: OK, so I pressed apply even though I didn't change anything and the process appears to be running. Is this the process which registers DHCP leases? Is there some way to find out why this process might be terminating?

[fichtner]

Is there some way to find out why this process might be terminating?

That would be the next question. For now let's see when it stops and try to run it manually when it disappears:

# /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --domain "YOURDOMAIN"

[brotkastn]

I found this issue since i am currently running 24.7.9_1-amd64 and the leases that ISC DHCPv4 issues are not recognized by unbound. After reading through this issue, i have found that the python-script was not running.

1. check if the "unbound_watcher.py" is running, if not
2. go to the "Services"->"Unbound"->"General" in the opnsense Webinterface, disable the "Register ISC DHCP4 Leases" checkbox, hit Apply
3. enable the "Register ISC DHCP4 Leases" checkbox, and hit apply again
4. the "unbound_watcher.py" script should now be running

root@OPNsense:~ # ps aux | grep unb
unbound  4598   3.9  0.6 91280 51328  -  Ss   13:33       0:00.08 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
root    14357   0.0  0.0 12720  2036  0  S+   13:33       0:00.00 grep unb

# disable / enable "Register ISC DHCP4 Leases" on the Webinterface

root@OPNsense:~ # ps aux | grep unb
unbound 51322   0.0  0.6 91280 51480  -  Ss   13:33       0:00.10 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
root    54046   0.0  0.2 28880 17920  -  Ss   13:33       0:00.51 /usr/local/bin/python3 /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --domain lan (python3.11)
root    61554   0.0  0.0 12720  2036  0  S+   13:33       0:00.00 grep unb

Meanwhile, the unbound log shows only the "daemonize unbound dhcpd watcher." message emitted from the python script, and no reason why it stopped.

Thank you for your work on opnsense. If i can do anything to help to debug this issue, feel free to ask!
Michael

[fichtner]

@brotkastn see here on how to debug #8075 (comment)

[brotkastn]

@brotkastn see here on how to debug #8075 (comment)

Easier said than done:

root@OPNsense:~ # kill 58160 && /usr/local/bin/python3 -m pdb /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --domain lan
> /usr/local/opnsense/scripts/dhcp/unbound_watcher.py(3)<module>()
-> """
(Pdb) continue
The program exited via sys.exit(). Exit status: 0
> /usr/local/opnsense/scripts/dhcp/unbound_watcher.py(3)<module>()
-> """
(Pdb) quit
root@OPNsense:~ # ps aux | grep unb
root    56149   1.0  0.3  34712 21032  -  Ss   21:54       0:00.51 /usr/local/bin/python3 -m pdb /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --domain lan (python3.11)
unbound 51322   0.0  0.8 113296 67448  -  Ss   13:33       0:13.86 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
root    92366   0.0  0.0  12720  2040  1  S+   21:55       0:00.00 grep unb

however, i started this inside tmux. maybe i get debug output once it dies.

Thanks for your help, have a nice day,
Michael

[fichtner]

Looks like I forgot the --foreground option, sorry!

# /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --foreground --domain "YOURDOMAIN"

[gyrex]

Good to see some activity on this issue. Just an update from my end: unbound_dhcpd.pid is still running after I restarted it but I think this is a somewhat sporadic issue where the process dies/terminates randomly. Should I also run a debug log?

[fichtner]

To catch a specific issue in your environment that would help fix it, yes :)

[Hr46ph]

I seem to have been suffering from a similar issue and got redirected from the opnsense forums after posting about my issue.

In my case, the process was running, I killed it and restarted it:

# pgrep -F /var/run/unbound_dhcpd.pid
75176
root@singularity:~ # kill 75176
root@singularity:~ # /usr/local/opnsense/scripts/dhcp/unbound_watcher.py --foreground --domain "internal.domain.net"
removed 1 datas
added 2 datas

It seems a restart of the proces was enough in my case. After that, a dig against unbound resolves a new lease. I'll monitor the situation.