#1737 No messages are sent to outgoing servers because of unbound initialization failure
Reporter
codiflow
Owner
Zash
Created
Updated
Stars
★★ (2)
Tags
Status-Fixed
Priority-Medium
Milestone-0.12
Type-Defect
codiflow
on
After upgrading to Prosody 0.12 on my Debian 10 I noticed that I could receive messages from other servers without any problem but couldn't send them any. They got "stuck" on my server and never left it. It also didn't show any error message or something in the logs I could work with. So I thought it must have something to do with the update. As I didn't want to downgrade without knowing the issue I digged deeper.
After enabling verbose logging I found those log entries:
│Apr 04 20:42:26 unbound.querysdcQ2LEmeAhO debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │
│Apr 04 20:42:26 unbound.querysdcQ2LEmeAhO warn Resolver error: initialization failure │
│Apr 04 20:42:26 mod_s2s debug opening a new outgoing connection for this stanza │
│Apr 04 20:42:26 mod_s2s debug stanza [presence] queued until connection complete │
│Apr 04 20:42:26 net.connect debug [pending connection c8Mq6rvxWnSA] Starting connection process │
│Apr 04 20:42:26 net.connect debug [pending connection c8Mq6rvxWnSA] Checking for targets... │
│Apr 04 20:42:26 unbound.queryeqNgcuR0Stkc debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │
│Apr 04 20:42:26 unbound.queryeqNgcuR0Stkc warn Resolver error: initialization failure │
│Apr 04 20:42:26 mod_s2s debug opening a new outgoing connection for this stanza │
│Apr 04 20:42:26 mod_s2s debug stanza [presence] queued until connection complete │
│Apr 04 20:42:26 net.connect debug [pending connection SsrRHzeCzTQX] Starting connection process │
│Apr 04 20:42:26 net.connect debug [pending connection SsrRHzeCzTQX] Checking for targets... │
│Apr 04 20:42:26 unbound.queryF50doYP0HFOs debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │
│Apr 04 20:42:26 unbound.queryF50doYP0HFOs warn Resolver error: initialization failure │
│Apr 04 20:42:26 s2sout55dcbe7c8580 debug trying to send over unauthed s2sout to descentforum.de │
│Apr 04 20:42:26 s2sout55dcbe7c8580 debug stanza [presence] queued
So it seems that the hostnames of the other servers couldn't be resolved and therefore Prosody couldn't eestablish any connection to them.
I don't know why but after uninstalling the package lua-unbound (Version 0.5-2prosody1) using apt and restarting prosody everything worked like it should. No more error messages regarding unbound.
Maybe this helps someone until this issue gets fixed as I couldn't find any details on the unbound implementation in Prosody to understand it further.
Zash
on
Thanks for the report.
Is there no error returned to the sender?
> Resolver error: initialization failure
This comes from libunbound and I am not entirely sure what it means, it seems to be about its internal libevent instance.
Things to check:
Can prosody read /etc/resolv.conf and /etc/hosts ?
Are there any restrictions on threads or forking processes?
Zash
on
Changes
tags Status-NeedInfo
codiflow
on
No error, no notification, nothing.
The messages just not got delivered but there was no hint on that in any client (tried Dino and Conversations)
Prosody should be able to read /etc/resolv.conf and /etc/hosts:
-rw-r--r-- 1 root root 182 Jul 4 2020 /etc/resolv.conf
-rw-r--r-- 1 root root 356 Feb 1 2021 /etc/hosts
But I finally found the error with your hint.
The error was caused by the following line in my /etc/hosts file:
127.0.0.1 localhost login.customwebpage.com workadventure.localhost
After removing the last entry (workadventure.localhost) everything worked as expected.
Thanks for your help.
Zash
on
Strange. Thanks for reporting back. We improve the robustness of error handling here. Tricky when libraries aren't reporting problems with sufficient details.
Changes
tags Status-Accepted Milestone-0.12
Zash
on
I could reproduce with
$ lua -l lunbound
Lua 5.2.4 Copyright (C) 1994-2015 Lua.org, PUC-Rio
> u=lunbound.new({hoststxt="./hosts.txt"}) -- containing the line from comment 4
> return u:resolve(".",1,1)
[1649193251] libunbound[50392:0] error: local-data in redirect zone must reside at top of zone, not at workadventure.localhost A 127.0.0.1
nil initialization failure
So it looks like errors are reported to stderr, which means they go into /dev/null on a typical running prosody.
ffuentes
on
I have a similar issue on OpenBSD 7.1
doas prosodyctl check connectivity
Checking external connectivity for texto-plano.xyz via observe.jabber.network
[1652661066] libunbound[67198:0] error: local-data in redirect zone must reside at top of zone, not at image.localhost A 10.0.2.15
unbound.queryoa-T7syWLynZ warn Resolver error: initialization failure
[1652661066] libunbound[67198:0] error: local-data in redirect zone must reside at top of zone, not at image.localhost A 10.0.2.15
unbound.query0ifTNyR_dvc1 warn Resolver error: initialization failure
And I get no response from external users. Basically they can't see the server, though affilate users can connect and use the service with no problems.
Zash
on
As a workaround, either fix the hosts file or configure prosody with
unbound = { hoststxt = false }
ffuentes
on
I added the line but it keeps throwing the same error and external users can't connect
Zash
on
The line must be in the global section, before any VirtualHost or Component lines, and you likely need to restart Prosody for the change to take effect.
Zash
on
Disabling hosts by default in https://hg.prosody.im/trunk/rev/a92e1de62c9e should fix this for 0.12.1
This reverts to previous behavior and behavior without libunbound which does not support use of hosts.txt.
Note that libunbound is optional, if recommended, and can be uninstalled to revert to the pure Lua net.dns library as a workaround if nothing else works.
Changes
owner Zash
tags Status-Fixed
ffuentes
on
Thanks, that did get rid of the error. However, connectivity issues are still in place
Checking external connectivity for conference.texto-plano.xyz via observe.jabber.network
xmpp-server: Check service failed to establish (secure) connection
Checking external connectivity for texto-plano.xyz via observe.jabber.network
xmpp-client: Check service failed to establish (secure) connection
xmpp-server: Check service failed to establish (secure) connection
Note: The connectivity check only checks the reachability of the domain.
Note: It does not ensure that the check actually reaches this specific prosody instance.
Problems found, see above.
Zash
on
ffuentes: This looks like a different problem unrelated to this. Please open a different issue or ask for troubleshooting help in the chat https://prosody.im/discuss
Zash
on
The fix for this introduced a regression, wherein Prosody would ignore /etc/resolv.conf and resolve names itself, documented in #1763
After upgrading to Prosody 0.12 on my Debian 10 I noticed that I could receive messages from other servers without any problem but couldn't send them any. They got "stuck" on my server and never left it. It also didn't show any error message or something in the logs I could work with. So I thought it must have something to do with the update. As I didn't want to downgrade without knowing the issue I digged deeper. After enabling verbose logging I found those log entries: │Apr 04 20:42:26 unbound.querysdcQ2LEmeAhO debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │ │Apr 04 20:42:26 unbound.querysdcQ2LEmeAhO warn Resolver error: initialization failure │ │Apr 04 20:42:26 mod_s2s debug opening a new outgoing connection for this stanza │ │Apr 04 20:42:26 mod_s2s debug stanza [presence] queued until connection complete │ │Apr 04 20:42:26 net.connect debug [pending connection c8Mq6rvxWnSA] Starting connection process │ │Apr 04 20:42:26 net.connect debug [pending connection c8Mq6rvxWnSA] Checking for targets... │ │Apr 04 20:42:26 unbound.queryeqNgcuR0Stkc debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │ │Apr 04 20:42:26 unbound.queryeqNgcuR0Stkc warn Resolver error: initialization failure │ │Apr 04 20:42:26 mod_s2s debug opening a new outgoing connection for this stanza │ │Apr 04 20:42:26 mod_s2s debug stanza [presence] queued until connection complete │ │Apr 04 20:42:26 net.connect debug [pending connection SsrRHzeCzTQX] Starting connection process │ │Apr 04 20:42:26 net.connect debug [pending connection SsrRHzeCzTQX] Checking for targets... │ │Apr 04 20:42:26 unbound.queryF50doYP0HFOs debug Resolve _xmpps-server._tcp.PUTEXTERNALSERVERDOMAINHERE IN SRV │ │Apr 04 20:42:26 unbound.queryF50doYP0HFOs warn Resolver error: initialization failure │ │Apr 04 20:42:26 s2sout55dcbe7c8580 debug trying to send over unauthed s2sout to descentforum.de │ │Apr 04 20:42:26 s2sout55dcbe7c8580 debug stanza [presence] queued So it seems that the hostnames of the other servers couldn't be resolved and therefore Prosody couldn't eestablish any connection to them. I don't know why but after uninstalling the package lua-unbound (Version 0.5-2prosody1) using apt and restarting prosody everything worked like it should. No more error messages regarding unbound. Maybe this helps someone until this issue gets fixed as I couldn't find any details on the unbound implementation in Prosody to understand it further.
Thanks for the report. Is there no error returned to the sender? > Resolver error: initialization failure This comes from libunbound and I am not entirely sure what it means, it seems to be about its internal libevent instance. Things to check: Can prosody read /etc/resolv.conf and /etc/hosts ? Are there any restrictions on threads or forking processes?
No error, no notification, nothing. The messages just not got delivered but there was no hint on that in any client (tried Dino and Conversations) Prosody should be able to read /etc/resolv.conf and /etc/hosts: -rw-r--r-- 1 root root 182 Jul 4 2020 /etc/resolv.conf -rw-r--r-- 1 root root 356 Feb 1 2021 /etc/hosts But I finally found the error with your hint. The error was caused by the following line in my /etc/hosts file: 127.0.0.1 localhost login.customwebpage.com workadventure.localhost After removing the last entry (workadventure.localhost) everything worked as expected. Thanks for your help.
Strange. Thanks for reporting back. We improve the robustness of error handling here. Tricky when libraries aren't reporting problems with sufficient details.
ChangesI could reproduce with $ lua -l lunbound Lua 5.2.4 Copyright (C) 1994-2015 Lua.org, PUC-Rio > u=lunbound.new({hoststxt="./hosts.txt"}) -- containing the line from comment 4 > return u:resolve(".",1,1) [1649193251] libunbound[50392:0] error: local-data in redirect zone must reside at top of zone, not at workadventure.localhost A 127.0.0.1 nil initialization failure So it looks like errors are reported to stderr, which means they go into /dev/null on a typical running prosody.
I have a similar issue on OpenBSD 7.1 doas prosodyctl check connectivity Checking external connectivity for texto-plano.xyz via observe.jabber.network [1652661066] libunbound[67198:0] error: local-data in redirect zone must reside at top of zone, not at image.localhost A 10.0.2.15 unbound.queryoa-T7syWLynZ warn Resolver error: initialization failure [1652661066] libunbound[67198:0] error: local-data in redirect zone must reside at top of zone, not at image.localhost A 10.0.2.15 unbound.query0ifTNyR_dvc1 warn Resolver error: initialization failure And I get no response from external users. Basically they can't see the server, though affilate users can connect and use the service with no problems.
As a workaround, either fix the hosts file or configure prosody with unbound = { hoststxt = false }
I added the line but it keeps throwing the same error and external users can't connect
The line must be in the global section, before any VirtualHost or Component lines, and you likely need to restart Prosody for the change to take effect.
Disabling hosts by default in https://hg.prosody.im/trunk/rev/a92e1de62c9e should fix this for 0.12.1 This reverts to previous behavior and behavior without libunbound which does not support use of hosts.txt. Note that libunbound is optional, if recommended, and can be uninstalled to revert to the pure Lua net.dns library as a workaround if nothing else works.
ChangesThanks, that did get rid of the error. However, connectivity issues are still in place Checking external connectivity for conference.texto-plano.xyz via observe.jabber.network xmpp-server: Check service failed to establish (secure) connection Checking external connectivity for texto-plano.xyz via observe.jabber.network xmpp-client: Check service failed to establish (secure) connection xmpp-server: Check service failed to establish (secure) connection Note: The connectivity check only checks the reachability of the domain. Note: It does not ensure that the check actually reaches this specific prosody instance. Problems found, see above.
ffuentes: This looks like a different problem unrelated to this. Please open a different issue or ask for troubleshooting help in the chat https://prosody.im/discuss
The fix for this introduced a regression, wherein Prosody would ignore /etc/resolv.conf and resolve names itself, documented in #1763