search

baiwyc119 / lxmppd

Automatically exported from code.google.com/p/lxmppd
0 stars 0 forks source link

Random disconnections to another XMPP server using CNAMEs #499

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
My server Nekmo.org using Prosody 0.9.8 has random disconnections to another 
server, but only to MUC.

May 28 00:12:00 salas.nekmo.org:saslauth        info    Accepting SASL EXTERNAL 
identity from jabberes.org
May 28 00:12:00 s2sin328ae40    info    incoming s2s connection 
jabberes.org->salas.nekmo.org complete
May 28 00:24:58 s2sout2c38ca0   info    Out of connection options, can't 
connect to conf.jabberes.org
May 28 00:24:58 s2sout2c38ca0   info    Sending error replies for 1 queued 
stanzas because of failed outgoing connection to conf.jabberes.org
May 28 00:25:11 s2sout2541d60   info    Out of connection options, can't 
connect to conf.jabberes.org
May 28 00:25:11 s2sout2541d60   info    Sending error replies for 1 queued 
stanzas because of failed outgoing connection to conf.jabberes.org
May 28 00:25:16 s2sout2d29a90   info    Beginning new connection attempt to 
conf.jabberes.org ([95.211.10.153]:5269)
May 28 00:25:16 s2sout2d29a90   info    outgoing s2s connection 
nekmo.org->conf.jabberes.org complete
May 28 00:26:46 s2sin3631b70    info    incoming s2s stream 
conf.jabberes.org->nekmo.org closed: connection-timeout
May 28 00:51:09 salas.nekmo.org:saslauth        info    Accepting SASL EXTERNAL 
identity from jabberes.org
May 28 00:51:09 s2sin223b200    info    incoming s2s connection 
jabberes.org->salas.nekmo.org complete
May 28 00:51:09 s2sout27caa10   info    Beginning new connection attempt to 
jabberes.org ([95.211.10.153]:5269)
May 28 00:51:10 s2sout27caa10   info    outgoing s2s connection 
salas.nekmo.org->jabberes.org complete
May 28 00:52:27 nekmo.org:saslauth      info    Accepting SASL EXTERNAL 
identity from jabberes.org
May 28 00:52:27 s2sin23898b0    info    incoming s2s connection 
jabberes.org->nekmo.org complete
May 28 00:52:39 s2sin319fd30    info    incoming s2s stream 
jabberes.org->salas.nekmo.org closed: connection-timeout
May 28 00:58:50 s2sout273fd90   info    Out of connection options, can't 
connect to conf.jabberes.org
May 28 00:58:50 s2sout273fd90   info    Sending error replies for 1 queued 
stanzas because of failed outgoing connection to conf.jabberes.org

I think the important line here is:

Out of connection options, can't connect to conf.jabberes.org

This domain does not have SRV, but has DNS alias:

$ host conf.jabberes.org
conf.jabberes.org is an alias for jabberes.org.
jabberes.org has address 95.211.10.153

This error occurs randomly and after several hours (only affects the connection 
to the remote MUC, conf.jabberes.org). Before everything works fine.

Original issue reported on code.google.com by nintux on 27 May 2015 at 11:19

Attachments:

GoogleCodeExporter commented 9 years ago 
Hi, thanks for the report!

Any chance you could enable debug logging? At the info level it doesn't log 
individual attempts, or DNS lookups etc., which would all be useful in trying 
to solve this.

You can enable debug logging in your config, and reload - no need to restart 
Prosody.

Original comment by MWild1 on 27 May 2015 at 11:42

GoogleCodeExporter commented 9 years ago 
Ok, I have enabled debug. I will write again when I have more information. 
Thanks :)

Original comment by nintux on 27 May 2015 at 11:49

GoogleCodeExporter commented 9 years ago 
I filtered through everything that happened at 02:37:xx. Everything happens in 
the second 46.

May 28 02:37:46 s2sin23ab680    debug   Destroying incomplete session 
conf.jabberes.org->nekmo.org due to inactivity
May 28 02:37:46 s2sin23ab680    debug   Disconnecting (unknown 
host)[s2sin_unauthed], <stream:error> is: connection-timeout
May 28 02:37:46 mod_s2s debug   sending: <stream:error>
May 28 02:37:46 mod_s2s debug   sending: </stream:stream>
May 28 02:37:46 s2sin23ab680    info    incoming s2s stream 
conf.jabberes.org->nekmo.org closed: connection-timeout
May 28 02:37:46 s2sin23ab680    debug   Destroying incoming session 
conf.jabberes.org->nekmo.org: connection-timeout
May 28 02:37:46 s2sin23ab680    debug   s2s disconnected: nil->nil (connection 
closed)
May 28 02:37:46 socket  debug   server.lua: closed client handler and removed 
socket from list
May 28 02:37:46 socket  debug   server.lua: accepted new client connection from 
95.211.10.153:59459 to 5269
May 28 02:37:46 s2sin219e1c0    debug   Incoming s2s connection
May 28 02:37:46 s2sin219e1c0    debug   Incoming s2s received <stream:stream 
xmlns='http://etherx.jabber.org/streams' version='1.0' to='nekmo.org' 
from='conf.jabberes.org'>
May 28 02:37:46 mod_s2s debug   sending: <?xml version='1.0'?>
May 28 02:37:46 mod_s2s debug   sending: <stream:stream 
xmlns:db='jabber:server:dialback' 
xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='nekmo.org' 
id='38b2cbb3-90af-4d38-aa01-0694fe197ccd' to='conf.jabberes.org' xml:lang='en' 
xmlns='jabber:server'>
May 28 02:37:46 mod_s2s debug   Sending stream features: 
<stream:features><dialback xmlns='urn:xmpp:features:dialback'/><starttls 
xmlns='urn:ietf:params:xml:ns:xmpp-tls'/></stream:features>
May 28 02:37:46 mod_s2s debug   sending: <stream:features>
May 28 02:37:46 s2sin219e1c0    debug   Received[s2sin_unauthed]: <starttls 
xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
May 28 02:37:46 mod_s2s debug   sending: <proceed 
xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
May 28 02:37:46 socket  debug   server.lua: we need to do tls, but delaying 
until send buffer empty
May 28 02:37:46 s2sin219e1c0    debug   TLS negotiation started for 
s2sin_unauthed...
May 28 02:37:46 socket  debug   server.lua: attempting to start tls on 
tcp{client}: 0x2228878
May 28 02:37:46 socket  debug   server.lua: ssl handshake done
May 28 02:37:46 s2sin219e1c0    debug   Incoming s2s received <stream:stream 
xmlns='http://etherx.jabber.org/streams' version='1.0' to='nekmo.org' 
from='conf.jabberes.org'>
May 28 02:37:46 s2sin219e1c0    debug   certificate chain validation result: 
valid
May 28 02:37:46 s2sin219e1c0    debug   certificate identity validation result: 
invalid
May 28 02:37:46 mod_s2s debug   sending: <?xml version='1.0'?>
May 28 02:37:46 mod_s2s debug   sending: <stream:stream 
xmlns:db='jabber:server:dialback' 
xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='nekmo.org' 
id='56b76a70-bc6e-42be-9940-6c548d046c4c' to='conf.jabberes.org' xml:lang='en' 
xmlns='jabber:server'>
May 28 02:37:46 mod_s2s debug   Sending stream features: 
<stream:features><dialback 
xmlns='urn:xmpp:features:dialback'/></stream:features>
May 28 02:37:46 mod_s2s debug   sending: <stream:features>
May 28 02:37:46 s2sin219e1c0    debug   Received[s2sin_unauthed]: <result 
xmlns='jabber:server:dialback' to='nekmo.org' from='conf.jabberes.org'>
May 28 02:37:46 s2sin219e1c0    debug   asking conf.jabberes.org if key 
1944865565 belongs to them
May 28 02:37:46 mod_s2s debug   opening a new outgoing connection for this 
stanza
May 28 02:37:46 mod_s2s debug   stanza [db:verify] queued until connection 
complete
May 28 02:37:46 mod_s2s debug   First attempt to connect to conf.jabberes.org, 
starting with SRV lookup...
May 28 02:37:46 adns    debug   Records for 
_xmpp-server._tcp.conf.jabberes.org. not in cache, sending query (thread: 
0x2f83080)...
May 28 02:37:46 adns    debug   Sending DNS query to 213.186.33.99
May 28 02:37:46 socket  debug   server.lua: closed client handler and removed 
socket from list
May 28 02:37:46 adns    debug   Reply for _xmpp-server._tcp.conf.jabberes.org. 
(thread: 0x2f83080)
May 28 02:37:46 mod_s2s debug   conf.jabberes.org has no SRV records, falling 
back to A/AAAA
May 28 02:37:46 adns    debug   Records for conf.jabberes.org not in cache, 
sending query (thread: 0x3504110)...
May 28 02:37:46 adns    debug   Sending DNS query to 213.186.33.99
May 28 02:37:46 adns    debug   Records for conf.jabberes.org not in cache, 
sending query (thread: 0x2c153f0)...
May 28 02:37:46 adns    debug   Sending DNS query to 213.186.33.99
May 28 02:37:46 adns    debug   Reply for conf.jabberes.org (thread: 0x3504110)
May 28 02:37:46 mod_s2s debug   Looking up jabberes.org. (DNS depth is 3)
May 28 02:37:46 socket  debug   server.lua: closed client handler and removed 
socket from list
May 28 02:37:46 adns    debug   Reply for conf.jabberes.org (thread: 0x2c153f0)
May 28 02:37:46 mod_s2s debug   DNS lookup failed to get a response for 
conf.jabberes.org
May 28 02:37:46 s2sout22a1440   info    Out of connection options, can't 
connect to conf.jabberes.org
May 28 02:37:46 mod_s2s debug   No other records to try for conf.jabberes.org - 
destroying
May 28 02:37:46 s2sout22a1440   debug   Destroying outgoing session 
nekmo.org->conf.jabberes.org: DNS resolution failed
May 28 02:37:46 s2sout22a1440   info    Sending error replies for 1 queued 
stanzas because of failed outgoing connection to conf.jabberes.org

Original comment by nintux on 28 May 2015 at 1:01

GoogleCodeExporter commented 9 years ago 
I think the reason may be that conf.jabberes.org is an alias and not a record A.

Original comment by nintux on 28 May 2015 at 1:04

GoogleCodeExporter commented 9 years ago 
Correct, CNAME is the issue (you are not the first to report the problem).

We have been working to fix this, and would appreciate it if you could try the 
latest nightly builds: https://prosody.im/nightly/0.9/

As soon as we are sure that the issue is solved, we will release it as 0.9.9.

Original comment by MWild1 on 28 May 2015 at 9:06

GoogleCodeExporter commented 9 years ago 
Ok, I installed from mercurial using this PKGBUILD.

https://aur.archlinux.org/packages/pr/prosody-hg/PKGBUILD

I've modified "trunk" with "0.9". I think that should be enough. I'll tell you 
what's new. Thanks :)

Original comment by nintux on 28 May 2015 at 9:58

GoogleCodeExporter commented 9 years ago 
I have a few days using the latest version of mercurial (0.9) and seems to work 
fine :)

Original comment by nintux on 30 May 2015 at 1:10

GoogleCodeExporter commented 9 years ago 
Excellent, thanks! Considering this issue fixed in 
https://hg.prosody.im/0.9/rev/45222bfb206f

It will be released in 0.9.9 soon.

Original comment by MWild1 on 31 May 2015 at 10:32