Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.debian.bugs.dist > #763761 > unrolled thread

Bug#836236: prosody: doesn't try IPv4 when IPv6 fails

Back to article view | Back to linux.debian.bugs.dist

Contents

  Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Cyril Brulebois <kibi@debian.org> - 2016-08-31 23:30 +0200
    Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Matthew Wild <mwild1@gmail.com> - 2016-09-01 00:00 +0200
      Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Cyril Brulebois <kibi@debian.org> - 2016-09-01 00:10 +0200
        Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Cyril Brulebois <kibi@debian.org> - 2016-09-01 00:30 +0200
          Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Matthew Wild <mwild1@gmail.com> - 2016-09-01 10:40 +0200
            Bug#836236: prosody: doesn't try IPv4 when IPv6 fails Cyril Brulebois <kibi@debian.org> - 2016-09-01 17:20 +0200

#763761 — Bug#836236: prosody: doesn't try IPv4 when IPv6 fails

Package: prosody
Version: 0.9.7-2+deb8u3
Severity: normal

Hi,

My server is trying to initiate a connection to crans.org, which has the
following DNS bits set up:
| _xmpp-server._tcp.crans.org. 466 IN	SRV	5 0 5269 xmpp.crans.org.
| 
| xmpp.crans.org.		466	IN	A	138.231.136.66
| xmpp.crans.org.		466	IN	AAAA	2a01:240:fe3d:4:200:42ff:fe42:4204

Logs say:
| Aug 31 23:02:18 s2soute11b40    info    Beginning new connection attempt to crans.org ([2a01:240:fe3d:4:200:42ff:fe42:4204]:5269)
| Aug 31 23:02:18 s2soute11b40    info    Out of connection options, can't connect to crans.org
| Aug 31 23:02:18 s2soute11b40    info    Sending error replies for 1 queued stanzas because of failed outgoing connection to crans.org

which is fair enough because:
 - trying IPv6 first is the right thing to do;
 - this port appears closed on IPv6 at the time of writing.

But prosody should move to trying a connection on IPv4 instead of simply
giving up and trying again a moment later.

Thanks for your time.


KiBi.

[toc] | [next] | [standalone]

#763770

Hi Cyril,

Thanks for the report. Can you please bump your log level up to
'debug' (there should be comments in your config file explaining how
to do this), and include those logs? The 'info' level logs tend to
give a high-level approximate view of issues, but only the debug logs
can be relied upon when debugging the low-level individual connection
attempts.

Thanks!

On 31 August 2016 at 22:16, Cyril Brulebois <kibi@debian.org> wrote:
> Package: prosody
> Version: 0.9.7-2+deb8u3
> Severity: normal
>
> Hi,
>
> My server is trying to initiate a connection to crans.org, which has the
> following DNS bits set up:
> | _xmpp-server._tcp.crans.org. 466 IN   SRV     5 0 5269 xmpp.crans.org.
> |
> | xmpp.crans.org.               466     IN      A       138.231.136.66
> | xmpp.crans.org.               466     IN      AAAA    2a01:240:fe3d:4:200:42ff:fe42:4204
>
> Logs say:
> | Aug 31 23:02:18 s2soute11b40    info    Beginning new connection attempt to crans.org ([2a01:240:fe3d:4:200:42ff:fe42:4204]:5269)
> | Aug 31 23:02:18 s2soute11b40    info    Out of connection options, can't connect to crans.org
> | Aug 31 23:02:18 s2soute11b40    info    Sending error replies for 1 queued stanzas because of failed outgoing connection to crans.org
>
> which is fair enough because:
>  - trying IPv6 first is the right thing to do;
>  - this port appears closed on IPv6 at the time of writing.
>
> But prosody should move to trying a connection on IPv4 instead of simply
> giving up and trying again a moment later.
>
> Thanks for your time.
>
>
> KiBi.

[toc] | [prev] | [next] | [standalone]

#763773

[Multipart message — attachments visible in raw view] — view raw

Hi Matthew,

Matthew Wild <mwild1@gmail.com> (2016-08-31):
> Thanks for the report. Can you please bump your log level up to
> 'debug' (there should be comments in your config file explaining how
> to do this), and include those logs? The 'info' level logs tend to
> give a high-level approximate view of issues, but only the debug logs
> can be relied upon when debugging the low-level individual connection
> attempts.

This is very strange. While crans.org was still without IPv6, a simple
restart locally made prosody look at both IPv6 (fail) and IPv4
(success). I wonder whether something might have been stuck in a bad
state within prosody after the initial DNS resolution failures which
happened for various domains…

Needless to say, I can't really replicate the issue right now, except
perhaps by rebooting again (which I can't really since I've got ongoing
maintenance elsewhere already). I would also need to remove things like
contact presence information from those logs before posting them…


KiBi.

[toc] | [prev] | [next] | [standalone]

#763777

[Multipart message — attachments visible in raw view] — view raw

Cyril Brulebois <kibi@debian.org> (2016-09-01):
> Hi Matthew,
> 
> Matthew Wild <mwild1@gmail.com> (2016-08-31):
> > Thanks for the report. Can you please bump your log level up to
> > 'debug' (there should be comments in your config file explaining how
> > to do this), and include those logs? The 'info' level logs tend to
> > give a high-level approximate view of issues, but only the debug logs
> > can be relied upon when debugging the low-level individual connection
> > attempts.
> 
> This is very strange. While crans.org was still without IPv6, a simple
> restart locally made prosody look at both IPv6 (fail) and IPv4
> (success). I wonder whether something might have been stuck in a bad
> state within prosody after the initial DNS resolution failures which
> happened for various domains…
> 
> Needless to say, I can't really replicate the issue right now, except
> perhaps by rebooting again (which I can't really since I've got ongoing
> maintenance elsewhere already). I would also need to remove things like
> contact presence information from those logs before posting them…

Just in case it helps you figure out what could have happened, messages
right after reboot for this host:
| Aug 31 02:09:46 s2soutf30410    info    Beginning new connection attempt to crans.org ([2a01:240:fe3d:4:200:42ff:fe42:4204]:5269)
| Aug 31 02:09:46 mod_s2s warn    s2s connect() to crans.org (2a01:240:fe3d:4:200:42ff:fe42:4204:5269) failed: Network is unreachable
| Aug 31 02:09:46 s2soutf30410    info    Out of connection options, can't connect to crans.org
| Aug 31 02:09:46 s2soutf30410    info    Sending error replies for 1 queued stanzas because of failed outgoing connection to crans.org
| Aug 31 02:09:46 mod_s2s warn    Connection to crans.org failed already, destroying session...

Also, a bunch of other hostnames had such issues:
| Aug 31 02:11:27 s2sout1007a70   info    Connection failed (name resolution failed). Attempt #2: This time to alt2.xmpp-server.l.google.com.:5269
| Aug 31 02:11:27 s2sout1007a70   info    Connection failed (name resolution failed). Attempt #3: This time to alt4.xmpp-server.l.google.com.:5269
| Aug 31 02:11:27 s2sout1007a70   info    Connection failed (name resolution failed). Attempt #4: This time to alt3.xmpp-server.l.google.com.:5269
| Aug 31 02:11:27 s2sout1007a70   info    Connection failed (name resolution failed). Attempt #5: This time to alt1.xmpp-server.l.google.com.:5269
| Aug 31 02:11:27 s2sout1007a70   info    Out of connection options, can't connect to [anotherserver]
| Aug 31 02:11:27 s2sout1007a70   info    Sending error replies for 1 queued stanzas because of failed outgoing connection to [anotherserver]

so I'm wondering whether there could have been incomplete DNS
resolution(s) at start-up time, which would not have been attempted
again later, leading me to see some contacts offline with “DNS failures”
as error message in Gajim.

After the prosody restart I triggered manually:
| Aug 31 23:37:49 s2sout231c500   info    Beginning new connection attempt to crans.org ([2a01:240:fe3d:4:200:42ff:fe42:4204]:5269)
| Aug 31 23:37:49 s2sout231c500   info    Beginning new connection attempt to crans.org ([138.231.136.66]:5269)
| Aug 31 23:37:49 s2sout231c500   info    outgoing s2s connection mraw.org->crans.org complete

Incidentally, looking at the IPv4 address for crans.org in the log since
the machine reboot, the first occurrence is when I restarted prosody
manually.

So it looks to me like it could be an initial DNS issue (partial and/or
no resolution depending on the domain) which happened at start-up time,
and failed/incomplete resolutions weren't attempted again later on.

Would this seem even remotely plausible?


KiBi.

[toc] | [prev] | [next] | [standalone]

#763840

On 31 August 2016 at 23:25, Cyril Brulebois <kibi@debian.org> wrote:
> So it looks to me like it could be an initial DNS issue (partial and/or
> no resolution depending on the domain) which happened at start-up time,
> and failed/incomplete resolutions weren't attempted again later on.
>
> Would this seem even remotely plausible?

Yes, this is plausible. I've seen this issue before on some servers,
but I haven't been able to track it down to a cause. One theory is
that if you log into a freshly-started server, and you have a lot of
contacts on remote domains, it triggers a burst of DNS requests. DNS
being UDP, which is lossy, some of the DNS requests fail due to packet
loss caused by temporary network congestion.

Whether that theory is plausible I'm not sure - it doesn't seem like
it would be *that* much traffic to deal with. Perhaps there are some
queue sizes or something we could tweak if that is the problem though.

Eventually the failed s2s connections do establish - they will be
retried as soon as you change status for example, or if any of your
remote contacts change status or try to send you a message.

[toc] | [prev] | [next] | [standalone]

#763930

[Multipart message — attachments visible in raw view] — view raw

Matthew Wild <mwild1@gmail.com> (2016-09-01):
> On 31 August 2016 at 23:25, Cyril Brulebois <kibi@debian.org> wrote:
> > So it looks to me like it could be an initial DNS issue (partial and/or
> > no resolution depending on the domain) which happened at start-up time,
> > and failed/incomplete resolutions weren't attempted again later on.
> >
> > Would this seem even remotely plausible?
> 
> Yes, this is plausible. I've seen this issue before on some servers,
> but I haven't been able to track it down to a cause. One theory is
> that if you log into a freshly-started server, and you have a lot of
> contacts on remote domains, it triggers a burst of DNS requests. DNS
> being UDP, which is lossy, some of the DNS requests fail due to packet
> loss caused by temporary network congestion.

That theory doesn't seem to likely here, since the total of remote
domains is likely under 20 (maybe even 10)…

Maybe I'll get more information at the next reboot, I'll update this bug
report then.

> Eventually the failed s2s connections do establish - they will be
> retried as soon as you change status for example, or if any of your
> remote contacts change status or try to send you a message.

OK. But those won't generate a new DNS request AFAICT? Some contacts
appeared offline (with DNS failure as a reason) for a whole day after
the initial DNS failure; until I restarted prosody manually.


KiBi.

[toc] | [prev] | [standalone]

Back to top | Article view | linux.debian.bugs.dist

csiph-web