unbound flooding syslog with 'sendto failed: Cannot assign requested address'

Unbound
1

Hi,

I’m running unbound 1.4.22 from debian unstable on my laptop.
Since yesterday unbound started behaving strangely, flooding the syslog
with failure messages. Example:
Oct 16 10:23:20 frustcomp unbound: [26958:0] notice: sendto failed: Cannot assign requested address
Oct 16 10:23:20 frustcomp unbound: [26958:0] notice: remote address is 2001:500:3::42 port 53

The pattern is always the same: 'sendto failed' followed by 'remote
address is' with varying IPv6 addresses. You can find full unbound-logs
for yesterday in [0], created using this command:
grep 'unbound' /var/log/syslog.1 > /tmp/unbound_failures.log
(Careful: this file is 339M big and has 3642512 lines.)

IPv6 is disabled on this system, it has neither an IPv6 address on any
interface nor a route set.

Today I tried just restarting unbound and that failed as well:
# service unbound restart
Restarting recursive DNS server: unbound[1444991903] unbound[22562:0] error: can't bind socket: Cannot assign requested address
[1444991903] unbound[22562:0] debug: failed address ::1 port 8953
[1444991903] unbound[22562:0] error: cannot open control interface ::1 8953
[1444991903] unbound[22562:0] fatal error: could not open ports
failed!

# ss -apen | grep 8953
returns nothing listening on that port, just to make sure that’s not
the problem. Since the message refers to 'requested address' and
probably means ::1, I doubt it is. ::1 is not configured on any
interface, as IPv6 is disabled.

I can’t figure out either of these problems, and I’m not sure if they
are related but the timing seems to suggest that.

Can anyone help me understand any of the error messages please? What
might cause them? Why do they appear on a system without IPv6
configured?

Please tell me (off-list maybe) what other info I should provide.

Thank you very much.

Sincerely

henk

[0]: http://henk.hnjs.ch/20151015_unbound_failures.txt

2

Hi Hendrik,

Hi,

I’m running unbound 1.4.22 from debian unstable on my laptop. Since
yesterday unbound started behaving strangely, flooding the syslog
with failure messages. Example: Oct 16 10:23:20 frustcomp unbound:
[26958:0] notice: sendto failed: Cannot assign requested address
Oct 16 10:23:20 frustcomp unbound: [26958:0] notice: remote address
is 2001:500:3::42 port 53

The newer versions of unbound have many fixes. Several of them have
related to squelching log messages.

The pattern is always the same: 'sendto failed' followed by
'remote address is' with varying IPv6 addresses. You can find full
unbound-logs for yesterday in [0], created using this command: grep
'unbound' /var/log/syslog.1 > /tmp/unbound_failures.log (Careful:
this file is 339M big and has 3642512 lines.)

That is big! I did not check, because you already give lots of
information here :slight_smile:

IPv6 is disabled on this system, it has neither an IPv6 address on
any interface nor a route set.

Unbound does not know IPv6 is disabled, so it tries. The failure is
harmless (apart from annoying with a log message in this unbound
version you are using). You could do-ip6: no in unbound.conf to make
the log messages go away. Or upgrade to a newer version.

Today I tried just restarting unbound and that failed as well: #
service unbound restart Restarting recursive DNS server:
unbound[1444991903] unbound[22562:0] error: can't bind socket:
Cannot assign requested address [1444991903] unbound[22562:0]
debug: failed address ::1 port 8953 [1444991903] unbound[22562:0]
error: cannot open control interface ::1 8953 [1444991903]
unbound[22562:0] fatal error: could not open ports failed!

# ss -apen | grep 8953 returns nothing listening on that port, just
to make sure that’s not the problem. Since the message refers to
'requested address' and probably means ::1, I doubt it is. ::1 is
not configured on any interface, as IPv6 is disabled.

I can’t figure out either of these problems, and I’m not sure if
they are related but the timing seems to suggest that.

Well if you disable IPv6 and then ::1 does not exist, then you'd also
have to disable ::1 for unbound, i.e. do-ip6: no. In any case, you
could either disable ipv6 for unbound, or configure it with 127.0.0.1
as the interface to bind to with interface: and control-interface:.

In later versions of unbound this error may also go away, but there
have been many releases in the meantime, so I am not sure. (it would
detect ipv6 is disabled and not fail and not bother you about it).

Can anyone help me understand any of the error messages please?
What might cause them? Why do they appear on a system without IPv6
configured?

Apart from all of the above, would you enable IPv6? This is not to
fix the issue you have with your Unbound configuration, but because
IPv6 is necessary for connecting future internet users?

Best regards, Wouter

3

I'm running unbound 1.4.22 from debian unstable on my laptop. Since

   > yesterday unbound started behaving strangely, flooding the syslog
   > with failure messages. Example: Oct 16 10:23:20 frustcomp unbound:
   > [26958:0] notice: sendto failed: Cannot assign requested address
   > Oct 16 10:23:20 frustcomp unbound: [26958:0] notice: remote address
   > is 2001:500:3::42 port 53

   The newer versions of unbound have many fixes. Several of them have
   related to squelching log messages.

On many versions of Unbound, on NetBSD 5 and 6, when the network goes
down, whether or not IPv6 is involved, I have seen it spew essentially
this message to the log, e.g.:

[1444927008] unbound[27554:0] notice: remote address is 192.228.79.201 port 53
[1444927008] unbound[27554:0] notice: sendto failed: Can't assign requested address

However, even if the log is sent to /dev/null, Unbound is spinning
trying and failing to do sendto as fast as it can and draining my
laptop battery. So I'm worried that `squelching log messages' may
paper over a legitimate error here, and I wonder whether any bugs
involving loops with sendto -- whether or not logging -- have been
fixed.

4

Hi Wouter

> IPv6 is disabled on this system, it has neither an IPv6 address on
> any interface nor a route set.

Unbound does not know IPv6 is disabled, so it tries. The failure is
harmless (apart from annoying with a log message in this unbound
version you are using). You could do-ip6: no in unbound.conf to make
the log messages go away. Or upgrade to a newer version.

Ah, that explains it, and probably solves it, thanks.

Well if you disable IPv6 and then ::1 does not exist, then you'd also
have to disable ::1 for unbound, i.e. do-ip6: no. In any case, you
could either disable ipv6 for unbound, or configure it with 127.0.0.1
as the interface to bind to with interface: and control-interface:.

Seems I only did that for interface: but missed control-interface:
because it did not show up at all in the config …

In later versions of unbound this error may also go away, but there
have been many releases in the meantime, so I am not sure. (it would
detect ipv6 is disabled and not fail and not bother you about it).

Nice.

Apart from all of the above, would you enable IPv6? This is not to
fix the issue you have with your Unbound configuration, but because
IPv6 is necessary for connecting future internet users?

Generally yes. I have been using IPv6 since 2009 both on my server and
at home. Some time this year I got a new uplink at home and with that a
new router from mikrotik. I ran into some kind of bug with
autoconfiguration though which might be the issue explained in [0]. I
didn’t have the time to figure that out exactly at the time and just
disabled IPv6 altogether. I reenabled it now after upgrading to a new
routeros firmware and will see how it turns out.
I appreciate you asking the question like you did! IPv6 needs more
proponents and implementors. Things have been going way too slow!

[0]: http://forum.mikrotik.com/viewtopic.php?t=77404

Thank you very much and best regards

henk