Unbound not logging queries

maverick_slo

Hi.
I have a strange one here...
On reboot, unbound stops logging queries and it send nothing to log file.
If I restart unbound, then it works just fine until next reboot.

I set log level to 0 and in custom options I have:

server:
log-queries: yes
domain-insecure:localdomain.local

This happens only on reboot, if I manually restart unbound, logging works as expected.
It almost seems like custom options are not there on reboot...
Any ideas what is going on here?
Thanks!

jimp

Are your custom directives present in /var/unbound/unbound.conf at boot time?

I haven't seen any issues here with logging, but there could be a timing issue depending on what happens at boot time.

maverick_slo

Files are identical.
After reboot and after manual restart, files are the same.

Weird is, that it:

starts logging,
then it starts to resolve aliases:
Feb 6 17:57:19 filterdns 8609 Adding host open.oneplus.net
Feb 6 17:57:19 filterdns 8609 Adding Action: pf table: BADSITES host: open.oneplus.net
dark, no more logs

and after this, no more logging.
Its like something is interfering with it, after boot only...

maverick_slo

Resolving is working just fine during this period...

jimp

Do you have any specific interfaces selected in the Unbound config, such as for Network Interfaces or Outgoing Network Interfaces?

Do you mind posting your /var/unbound/unbound.conf file? You can mask any private info such as subnets, so long as it's replaced by an equivalent dummy value (e.g. replace 10.1.2.3/24 with x.x.x.3/24 and soon).

maverick_slo

Sure, here it is:

##########################
# Unbound Configuration
##########################

##
# Server configuration
##
server:

chroot: /var/unbound
username: "unbound"
directory: "/var/unbound"
pidfile: "/var/run/unbound.pid"
use-syslog: yes
port: 53
verbosity: 0
hide-identity: yes
hide-version: yes
harden-glue: yes
do-ip4: yes
do-ip6: yes
do-udp: yes
do-tcp: yes
do-daemonize: yes
module-config: "validator iterator"
unwanted-reply-threshold: 0
num-queries-per-thread: 512
jostle-timeout: 200
infra-keep-probing: yes
infra-host-ttl: 900
infra-cache-numhosts: 10000
outgoing-num-tcp: 10
incoming-num-tcp: 10
edns-buffer-size: 1432
cache-max-ttl: 86400
cache-min-ttl: 0
harden-dnssec-stripped: no
msg-cache-size: 10m
rrset-cache-size: 20m

num-threads: 3
msg-cache-slabs: 2
rrset-cache-slabs: 2
infra-cache-slabs: 2
key-cache-slabs: 2
outgoing-range: 4096
#so-rcvbuf: 4m
auto-trust-anchor-file: /var/unbound/root.key
prefetch: yes
prefetch-key: yes
use-caps-for-id: no
serve-expired: no
aggressive-nsec: no
# Statistics
# Unbound Statistics
statistics-interval: 0
extended-statistics: yes
statistics-cumulative: yes

# TLS Configuration
tls-cert-bundle: "/etc/ssl/cert.pem"

# Interface IP addresses to bind to
interface: 10.10.0.1
interface: 2001:XXX:XXXX::1
interface: 172.16.16.1
interface: 2001:XXX:XXXX:1::1
interface: 192.168.100.1
interface: 2001:XXX:XXXX:2::1
interface: 192.168.200.1
interface: 127.0.0.1
interface: ::1


# DNS Rebinding




# Access lists
include: /var/unbound/access_lists.conf

# Static host entries
include: /var/unbound/host_entries.conf

# dhcp lease entries
include: /var/unbound/dhcpleases_entries.conf

# OpenVPN client entries
include: /var/unbound/openvpn.*.conf

# Domain overrides
include: /var/unbound/domainoverrides.conf


# Unbound custom options
server:
log-queries: yes
domain-insecure:localdomain.local



###
# Remote Control Config
###
include: /var/unbound/remotecontrol.conf

maverick_slo

@jimp
As for interfaces, outgoing: ALL
Listening on:

jimp

As a test can you try to see if it happens if you have nothing selected in either interface box? Having 'all' selected should be equivalent, but it's still better to test with everything unset.

Also, are all of the selected interfaces static (IPv4 and IPV6)?

maverick_slo

@jimp The following input errors were detected:

One or more Network Interfaces must be selected for binding.
One or more Outgoing Network Interfaces must be selected.

All interfaces are static

jimp

OK, so pick 'All' there, that must have been fixed up at some point. In some of those controls in other parts of the GUI, selecting nothing is the same as selecting "All".

maverick_slo

Did it:

##########################
# Unbound Configuration
##########################

##
# Server configuration
##
server:

chroot: /var/unbound
username: "unbound"
directory: "/var/unbound"
pidfile: "/var/run/unbound.pid"
use-syslog: yes
port: 53
verbosity: 0
hide-identity: yes
hide-version: yes
harden-glue: yes
do-ip4: yes
do-ip6: yes
do-udp: yes
do-tcp: yes
do-daemonize: yes
module-config: "validator iterator"
unwanted-reply-threshold: 0
num-queries-per-thread: 512
jostle-timeout: 200
infra-keep-probing: yes
infra-host-ttl: 900
infra-cache-numhosts: 10000
outgoing-num-tcp: 10
incoming-num-tcp: 10
edns-buffer-size: 1232
cache-max-ttl: 86400
cache-min-ttl: 0
harden-dnssec-stripped: no
msg-cache-size: 10m
rrset-cache-size: 20m

num-threads: 3
msg-cache-slabs: 2
rrset-cache-slabs: 2
infra-cache-slabs: 2
key-cache-slabs: 2
outgoing-range: 4096
#so-rcvbuf: 4m
auto-trust-anchor-file: /var/unbound/root.key
prefetch: yes
prefetch-key: yes
use-caps-for-id: no
serve-expired: no
aggressive-nsec: no
# Statistics
# Unbound Statistics
statistics-interval: 0
extended-statistics: yes
statistics-cumulative: yes

# TLS Configuration
tls-cert-bundle: "/etc/ssl/cert.pem"

# Interface IP addresses to bind to
interface-automatic: yes


# DNS Rebinding




# Access lists
include: /var/unbound/access_lists.conf

# Static host entries
include: /var/unbound/host_entries.conf

# dhcp lease entries
include: /var/unbound/dhcpleases_entries.conf

# OpenVPN client entries
include: /var/unbound/openvpn.*.conf

# Domain overrides
include: /var/unbound/domainoverrides.conf


# Unbound custom options
server:
log-queries: yes
domain-insecure:localdomain.local



###
# Remote Control Config
###
include: /var/unbound/remotecontrol.conf

Same result..

jimp

OK, I wanted to rule out some changes I made that would only trigger in certain cases when specific interfaces were selected. If it's the same with/without then you can put it back the way it was for now.

maverick_slo

I noticed that last lines in resolver logs are always

Maybe race condition?

jimp

Wouldn't be related, filterdns isn't tied into unbound except that it would run queries against it (if the system is set to do so).

maverick_slo

Hmm maybe just delay unbound start, move it down the list?

jimp

There are a lot of catch-22/chicken-egg scenarios there because a lot of things need DNS so Unbound has to be up early.

It's not clear why it isn't logging for you when it is for others (including me).

maverick_slo

From what I see, it respects the logging level set to "0" in advanced config.
If I select query level log there it will log... But it will also send huge amount of data to my siem which I dont want it to... I just want to log queries and no more... It seems like its not respecting custom options at boot time...