Unbound: umount: /var/unbound/lib: not a file system root directory

Started by Rumor, March 15, 2024, 09:32:16 PM

Previous topic - Next topic
With every OPNsense reboot the following unbound-related errors appear in opnsense logs:

2024-03-15T00:15:22 Error opnsense /usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'
2024-03-15T00:15:22 Error opnsense /usr/local/sbin/pluginctl: The command '/bin/kill -'TERM' '39073''(pid:/var/run/unbound.pid) returned exit code '1', the output was 'kill: 39073: No such process'
2024-03-15T00:15:22 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_start (execute task : unbound_configure_do(1))
2024-03-15T00:15:22 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_start (1)


If I reboot the unbound service manually the following errors appear in the log:

2024-03-15T22:02:01 Error opnsense /usr/local/sbin/pluginctl: The command '/sbin/mount -r -t nullfs '/lib' '/var/unbound/lib'' returned exit code '1', the output was 'mount_nullfs: /var/unbound/lib: Resource deadlock avoided'
2024-03-15T22:02:01 Error opnsense /usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: unmount of /var/unbound/lib failed: Device busy'


Unbound is working correctly and the /var/unbound/lib folder is mounted/present on the host.

It's a very fresh OPNsense 24.1.3_1-amd64 installation. I've googled and searched this forum for these errors with no luck.
Is there anything I can do to get rid of them?

I have the same exact problem. Everything seems to work fine, but the errors are discerning.
I would like to get to/ understand the root cause and fix the issue if possible.

It is concerning that Unbound is reporting this as an error; so something is definitely amiss.

Unbound is a stable pice of software, the main DNS resolver - so any errors in this crucial component are worrying... although there does not seem to be any consequences at the moment.

I'm facing the same problem and yet can't find anything online that helps me fixing it.
Opnsense is able to talk to Unbound just fine, but no clients on the LAN network can do it.
DNSMasq works as an alternative but would like to know why is it that Unbound just throws those errors.

/usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'

Nearly the same with version "OPNsense 24.1.5_1-amd64". After reboot the following error msg is in the system log,
2024-04-04T15:06:38 Error opnsense /usr/local/etc/rc.bootup: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'

I'm on OPNsense 24.1.5_3-amd64 and seeing similar errors in the log upon reboot:
2024-04-08T16:39:41
[Error]
opnsense /usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'
2024-04-08T16:39:41
[Error]
opnsense /usr/local/sbin/pluginctl: The command '/bin/kill -'TERM' '56369''(pid:/var/run/unbound.pid) returned exit code '1', the output was 'kill: 56369: No such process'
2024-04-08T16:39:41
[Error]
opnsense /usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'
2024-04-08T16:39:41
[Error]
opnsense /usr/local/sbin/pluginctl: The command '/bin/kill -'TERM' '56369''(pid:/var/run/unbound.pid) returned exit code '1', the output was 'kill: 56369: No such process'
2024-04-08T16:35:38
[Error]
opnsense /usr/local/etc/rc.linkup: The command '/sbin/mount -r -t nullfs '/lib' '/var/unbound/lib'' returned exit code '1', the output was 'mount_nullfs: /var/unbound/lib: Resource deadlock avoided'
2024-04-08T16:35:38
[Error]
opnsense /usr/local/etc/rc.linkup: The command '/sbin/mount -r -t nullfs '/usr/local/lib/python3.9' '/var/unbound/usr/local/lib/python3.9'' returned exit code '1', the output was 'mount_nullfs: /var/unbound/usr/local/lib/python3.9: Resource deadlock avoided'
2024-04-08T16:35:37
[Error]
opnsense /usr/local/etc/rc.linkup: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: unmount of /var/unbound/lib failed: Device busy'
2024-04-08T16:35:36
[Error]
configctl error in configd communication Traceback (most recent call last): File "/usr/local/sbin/configctl", line 65, in exec_config_cmd line = sock.recv(65536).decode() socket.timeout: timed out


Everything seems to be working, though.

I have the following error after updating version 24.1.5_3

# /usr/local/sbin/unbound -dc /var/unbound/unbound.conf
[1712673321] unbound[54802:0] error: can't bind socket: Address already in use for 127.0.0.1 port 953
[1712673321] unbound[54802:0] error: cannot open control interface 127.0.0.1 953
[1712673321] unbound[54802:0] fatal error: could not open ports

I'm also seeing this error:


2024-04-13T04:00:56-04:00 Error opnsense /usr/local/etc/rc.restart_webgui: The command '/usr/sbin/daemon -f -p '/var/run/updaterrd.pid' '/var/db/rrd/updaterrd.sh'' returned exit code '3', the output was 'daemon: process already running, pid: 31061'
2024-04-13T04:00:56-04:00 Error opnsense /usr/local/etc/rc.newwanipv6: The command '/usr/local/sbin/ntpd -g -c '/var/etc/ntpd.conf'' returned exit code '1', the output was ''
2024-04-13T04:00:49-04:00 Error dhcp6c transmit failed: Can't assign requested address
2024-04-13T04:00:48-04:00 Error opnsense /usr/local/etc/rc.bootup: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'


Versions:

OPNsense 24.1.5_3-amd64
FreeBSD 13.2-RELEASE-p11
OpenSSL 3.0.13

Also seeing this, my filesystem was also full, had to restart unbound dns. This is not the first day i had problems. Ever since OPNsense 24.1.5_1 i gotten issues. Also this is very fresh build!!!

Running in a proxmox vm if that makes any difference?

OPNsense 24.1.5_3-amd64
FreeBSD 13.2-RELEASE-p11
OpenSSL 3.0.13


2024-04-14T17:16:52 Error opnsense /usr/local/sbin/pluginctl: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'
2024-04-14T17:16:52 Error opnsense /usr/local/sbin/pluginctl: The command '/bin/kill -'TERM' '29609''(pid:/var/run/unbound.pid) returned exit code '1', the output was 'kill: 29609: No such process'
2024-04-14T17:16:52 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_start (execute task : unbound_configure_do(1))
2024-04-14T17:16:52 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_start (1)
2024-04-14T17:16:51 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_stop (execute task : unbound_service_stop(1))
2024-04-14T17:16:51 Notice opnsense /usr/local/sbin/pluginctl: plugins_configure unbound_stop (1)

Quote from: Botanist on April 14, 2024, 05:36:34 PM
Also seeing this, my filesystem was also full, had to restart unbound dns.

How did you tell your filesystem was full and how did you resolve it?


If I run "dh -h" on opnsense, I see that /var/unbound/dev is at 100%. That seems bad. I don't know why it's setup that way. Is that something I should fix? if so -- how?


root@OPNsense:~ # df -h
Filesystem                  Size    Used   Avail Capacity  Mounted on
zroot/ROOT/default          442G    1.2G    441G     0%    /
devfs                       1.0K    1.0K      0B   100%    /dev
/dev/gpt/efiboot0           260M    1.8M    258M     1%    /boot/efi
zroot/var/mail              441G     96K    441G     0%    /var/mail
zroot/tmp                   441G     96K    441G     0%    /tmp
zroot                       441G     96K    441G     0%    /zroot
zroot/var/audit             441G     96K    441G     0%    /var/audit
zroot/var/crash             441G     96K    441G     0%    /var/crash
zroot/usr/ports             441G     96K    441G     0%    /usr/ports
zroot/var/log               441G    1.1M    441G     0%    /var/log
zroot/usr/home              441G     96K    441G     0%    /usr/home
zroot/var/tmp               441G     96K    441G     0%    /var/tmp
zroot/usr/src               441G     96K    441G     0%    /usr/src
tmpfs                       3.1G    1.8M    3.1G     0%    /var/log
tmpfs                       806M    1.3M    804M     0%    /tmp
devfs                       1.0K    1.0K      0B   100%    /var/dhcpd/dev
devfs                       1.0K    1.0K      0B   100%    /var/unbound/dev
/usr/local/lib/python3.9    442G    1.2G    441G     0%    /var/unbound/usr/local/lib/python3.9
/lib                        442G    1.2G    441G     0%    /var/unbound/lib

I think that jus how it is, however for me, the /lib dir was full before i restarted it. Not a couple of hours after it seems fine. Idk..

root@opnsense:~ # df -h
Filesystem                  Size    Used   Avail Capacity  Mounted on
/dev/gpt/rootfs              23G     11G     10G    52%    /
devfs                       1.0K    1.0K      0B   100%    /dev
/dev/gpt/efifs              256M    1.7M    254M     1%    /boot/efi
devfs                       1.0K    1.0K      0B   100%    /var/dhcpd/dev
devfs                       1.0K    1.0K      0B   100%    /var/unbound/dev
/usr/local/lib/python3.9     23G     11G     10G    52%    /var/unbound/usr/local/lib/python3.9
/lib                         23G     11G     10G    52%    /var/unbound/lib


EDIT: I noticed it from the gui on the dashboard first. Lib was full and Unbound was not on.

/var/unbound/dev is a devfs - a virtual filesystem presenting device nodes to applications. It is always at 100%. You cannot write files to it.
Deciso DEC750
People who think they know everything are a great annoyance to those of us who do. (Isaac Asimov)

Yea that was what i was thinking!


Anyways, this seems to go kind of deep. I feel like there been problems with unbound from as early as 2022. Reading forum right now and this can be interesting to read. https://forum.opnsense.org/index.php?topic=35527.msg181074#msg181074

Really would want to sort this out

I also have the same problem, well kinda? I don't actually use unbound, and it isn't active. So getting errors related to it is a bit odd. One the one hand, it isn't surprising the mounts for it don't exist since I'm no using unbound. It is surprising that upon every WAN-reconnect (and boot, I think) something tries to unmount those non-existant mounts.

This is the exact log message (imagine the time stamp at the start ;) ):
Error opnsense /usr/local/etc/rc.newwanipv6: The command '/sbin/umount '/var/unbound/lib'' returned exit code '1', the output was 'umount: /var/unbound/lib: not a file system root directory'

And this is what I get as existing mounts:
/dev/gpt/rootfs on / (ufs, local, soft-updates, journaled soft-updates)
devfs on /dev (devfs)
/dev/gpt/efifs on /boot/efi (msdosfs, local)
devfs on /var/dhcpd/dev (devfs)


The umount part is an oversight.

https://github.com/opnsense/core/commit/1afe0405

The mount part probably means it could not be unmounted because still in use. Both are not tragic or fatal as far as I can tell.

Yet I wonder why addling /lib suddenly surfaces a problem with Nullfs that wasn't there for the other chroot mounts?


Cheers,
Franco