[ejabberd] problem with s2s (close in wait_for_stream)

Vyacheslav Karpukhin vyacheslav at karpukhin.com
Thu Jun 17 17:43:47 MSD 2010


hi there.

i'm using ejabberd 2.1.4 on centos 5. it worked just fine on FreeBSD, 
but after i moved it to centos -- it started getting weird.

sometimes i see unavailable contacts in my roster with a reason 
"remote server not found", but i know that these servers are available. 
i started investigation, set up separate server for testing it as "remote" 
and enabled debug logs on both servers. here is what i found (main server is 
psihaven.com, remote ("unavailable") server is jabber.karpukhina.ru).

main server logs:
========================================================
=INFO REPORT==== 2010-06-17 04:01:18 ===
D(<0.5383.0>:ejabberd_s2s_out:1106) : inet of jabber.karpukhina.ru resolved to:
				      	      			  [{188,
                                                                    243,
                                                                    231,
                                                                      71}]
                                                                                                                   
=INFO REPORT==== 2010-06-17 04:01:18 ===
D(<0.5383.0>:ejabberd_s2s_out:267) : s2s_out: connecting to 
{188,243,231,71}:5269

=INFO REPORT==== 2010-06-17 04:01:18 ===
I(<0.5383.0>:ejabberd_s2s_out:330) : Closing s2s connection: psihaven.com -> 
jabber.karpukhina.ru (close in wait_for_stream)

=INFO REPORT==== 2010-06-17 04:01:18 ===
D(<0.5383.0>:ejabberd_s2s_out:860) : terminated: {normal,wait_for_stream}
========================================================

and then server notifies my jabber client that remote server is not found.

here are the logs from remote server on the same moment (servers are in 
different timezones and there is also ~1 minute difference in system clock)

========================================================
=INFO REPORT==== 2010-06-17 02:00:20 ===
I(<0.397.0>:ejabberd_listener:232) : (#Port<0.825>) Accepted
connection 
{{81,30,198,26},50022} -> {{188,243,231,71},5269}

=INFO REPORT==== 2010-06-17 02:00:20 ===
D(<0.1226.0>:ejabberd_s2s_in:142) : started: {ejabberd_socket,
                                              {socket_state,gen_tcp,
                                               #Port<0.825>,<0.1225.0>}}

=INFO REPORT==== 2010-06-17 02:00:20 ===
D(<0.1225.0>:ejabberd_receiver:320) : Received XML on stream = "
<?xml version='1.0'?><stream:stream xmlns:stream='
http://etherx.jabber.org/streams' xmlns='jabber:server' 
xmlns:db='jabber:server:dialback' 
to='jabber.karpukhina.ru'
version='1.0'>"

=INFO REPORT==== 2010-06-17 02:00:20 ===
D(<0.1226.0>:ejabberd_s2s_in:609) : terminated: normal
========================================================



any ideas what is wrong with it?

thank you.



More information about the ejabberd mailing list