Project

General

Profile

For the first time login tigase server will report errors

MarsLuo Mars
Added over 4 years ago

Dear All

Whenever I server from kai, through PSI client for the first time login error, PSI will pop up There was an error communicating with the server Details: Disconnected, log in again, the back of the user is not on the server from the rev. For the first time login error, when this kind of mistake in my test environment sometimes, sometimes not, don't know why, always someone you know.

Appear this kind of circumstance, the server logs

2014-05-06 11:13:27.245 [ConnectionOpenThread]  ConnectionManager$ConnectionListenerImpl.accept()  FINEST: Accept called for service: null@null
2014-05-06 11:13:27.250 [ConnectionOpenThread]  ConnectionManager.serviceStarted()  FINER: [[c2s]] Connection started: null, type: accept, Socket: nullSocket[addr=/182.151.205.33,port=32381,localport=5222], jid: null
2014-05-06 11:13:27.253 [ConnectionOpenThread]  SocketThread.<clinit>()       WARNING:  5 socketReadThreads started.
2014-05-06 11:13:27.256 [ConnectionOpenThread]  SocketThread.<clinit>()       WARNING:  5 socketWriteThreads started.
2014-05-06 11:13:27.258 [pool-16-thread-1]  IOUtil.<clinit>()                 CONFIG:   using direct byte buffers with size 43,690 per buffer
2014-05-06 11:13:27.260 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {to=test.com, xmlns:stream=http://etherx.jabber.org/streams, xmlns:xml=http://www.w3.org/XML/1998/namespace, xml:lang=en, xmlns=jabber:client, version=1.0}
2014-05-06 11:13:27.260 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: No Session ID, generating a new one: 85d09c53-74e6-47ee-b756-df72070f90d2
2014-05-06 11:13:27.261 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: Writing raw data to the socket: <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' from='test.com' id='85d09c53-74e6-47ee-b756-df72070f90d2' version='1.0' xml:lang='en'>
2014-05-06 11:13:27.261 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: DONE
2014-05-06 11:13:27.263 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: Sending a system command to SM: from=null, to=null, DATA=<iq type="set" id="c2s--c2s1" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>85d09c53-74e6-47ee-b756-df72070f90d2</value></field><field var="hostname"><value>test.com</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=419, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.264 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq type="set" id="c2s--c2s1" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>85d09c53-74e6-47ee-b756-df72070f90d2</value></field><field var="hostname"><value>test.com</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=419, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.264 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.265 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.265 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@test, from=null, to=null, DATA=<iq type="set" id="c2s--c2s1" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>85d09c53-74e6-47ee-b756-df72070f90d2</value></field><field var="hostname"><value>test.com</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=419, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.265 [in_5-sess-man]    SessionManager.processCommand()    FINER:    STREAM_OPENED command from: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.266 [session-open Queue Worker 1]  SessionManager$SessionOpenProc.process()  FINER: Adding resource connection for: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.267 [session-open Queue Worker 1]  SessionManager.createUserSession()  FINEST: Setting hostname test.com for connection: c2s@test/182.92.129.9_5222_182.151.205.33_32381, VHostItem: Domain: test.com, enabled: true, anonym: false, register: false, maxusers: 0, tls: false, s2sSecret: null, domainFilter: ALL
2014-05-06 11:13:27.267 [session-open Queue Worker 1]  SessionManager.createUserSession()  FINEST: Domain set for connectionId c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.268 [session-open Queue Worker 1]  SessionManager$SessionOpenProc.process()  FINEST: Setting session-id 85d09c53-74e6-47ee-b756-df72070f90d2 for connection: user_jid=null, packets=0, connectioId=c2s@test/182.92.129.9_5222_182.151.205.33_32381, domain=test.com, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-05-06 11:13:27.269 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="c2s--c2s1" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"/>, SIZE=108, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.269 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.269 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.270 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.270 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.270 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@test, from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="c2s--c2s1" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"/>, SIZE=108, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.271 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq type="get" id="eba891c9-8c63-469e-8e28-7aa762b80791" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"/></iq>, SIZE=209, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-05-06 11:13:27.271 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.271 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.271 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@test, from=null, to=null, DATA=<iq type="get" id="eba891c9-8c63-469e-8e28-7aa762b80791" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"/></iq>, SIZE=209, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-05-06 11:13:27.272 [in_5-sess-man]    SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.274 [pool-16-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: DOEN 2
2014-05-06 11:13:27.275 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="eba891c9-8c63-469e-8e28-7aa762b80791" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"><ver xmlns="urn:xmpp:features:rosterver"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=550, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.276 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.276 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.276 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.276 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.277 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@test, from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="eba891c9-8c63-469e-8e28-7aa762b80791" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"><ver xmlns="urn:xmpp:features:rosterver"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=550, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.277 [in_2-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="eba891c9-8c63-469e-8e28-7aa762b80791" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"><ver xmlns="urn:xmpp:features:rosterver"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>CData size: 5</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=550, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.278 [in_2-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@test/182.92.129.9_5222_182.151.205.33_32381, type: accept, Socket: c2s@test/182.92.129.9_5222_182.151.205.33_32381 Socket[addr=/182.151.205.33,port=32381,localport=5222], jid: null, Writing packet: from=null, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<stream:features><ver xmlns="urn:xmpp:features:rosterver"/><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=364, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-05-06 11:13:27.533 [pool-16-thread-2]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>, SIZE=51, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.533 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@test/182.92.129.9_5222_182.151.205.33_32381, to=sess-man@test, DATA=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>, SIZE=51, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-05-06 11:13:27.533 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.534 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@test, from=c2s@test/182.92.129.9_5222_182.151.205.33_32381, to=sess-man@test, DATA=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>, SIZE=51, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-05-06 11:13:27.534 [in_2-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@test/182.92.129.9_5222_182.151.205.33_32381, to=sess-man@test, DATA=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>, SIZE=51, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=null, packets=0, connectioId=c2s@test/182.92.129.9_5222_182.151.205.33_32381, domain=test.com, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-05-06 11:13:27.534 [in_2-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: StartTLS (starttls)Request: from=c2s@test/182.92.129.9_5222_182.151.205.33_32381, to=sess-man@test, DATA=<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>, SIZE=51, XMLNS=urn:ietf:params:xml:ns:xmpp-tls, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=null, packets=1, connectioId=c2s@test/182.92.129.9_5222_182.151.205.33_32381, domain=test.com, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-05-06 11:13:27.536 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@test, to=null, DATA=<iq type="set" id="tig1" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="STARTTLS"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=273, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-05-06 11:13:27.536 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.536 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.537 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.537 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.537 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@test, from=sess-man@test, to=null, DATA=<iq type="set" id="tig1" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="STARTTLS"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=273, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-05-06 11:13:27.537 [in_2-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@test, to=null, DATA=<iq type="set" id="tig1" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"><command xmlns="http://jabber.org/protocol/commands" node="STARTTLS"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=273, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-05-06 11:13:27.537 [in_2-c2s]         ClientConnectionManager.processCommand()  FINER: Starting TLS for connection: c2s@test/182.92.129.9_5222_182.151.205.33_32381, type: accept, Socket: c2s@test/182.92.129.9_5222_182.151.205.33_32381 Socket[addr=/182.151.205.33,port=32381,localport=5222], jid: null
2014-05-06 11:13:27.539 [in_2-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [starttls]
2014-05-06 11:13:27.583 [pool-16-thread-3]  ConnectionManager.serviceStopped()  FINER:  [[c2s]] Connection stopped: c2s@test/182.92.129.9_5222_182.151.205.33_32381, type: accept, Socket: c2s@test/182.92.129.9_5222_182.151.205.33_32381 Socket[unconnected], jid: null
2014-05-06 11:13:27.584 [pool-16-thread-3]  ClientConnectionManager.xmppStreamClosed()  FINER: Stream closed: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.585 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq type="set" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_CLOSED"/></iq>, SIZE=211, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.585 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.586 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@test
2014-05-06 11:13:27.586 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@test, from=null, to=null, DATA=<iq type="set" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_CLOSED"/></iq>, SIZE=211, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.586 [in_5-sess-man]    SessionManager.processCommand()    FINER:    STREAM_CLOSED command from: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.586 [session-close Queue Worker 1]  SessionManager$SessionCloseProc.process()  FINEST: Executing connection close for: from=null, to=null, DATA=<iq type="set" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_CLOSED"/></iq>, SIZE=211, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.587 [session-close Queue Worker 1]  SessionManager.closeConnection()  FINER: Stream closed from: c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.587 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"/>, SIZE=135, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.587 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.587 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.588 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@test/182.92.129.9_5222_182.151.205.33_32381
2014-05-06 11:13:27.588 [in_2-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@test/182.92.129.9_5222_182.151.205.33_32381, for map: {pubsub@test=tigase.pubsub.PubSubComponent@64c0a4ae, proxy@test=tigase.socks5.Socks5ProxyComponent@66420f8b, cl-comp@test=tigase.cluster.ClusterConnectionManager@41109845, c2s@test=tigase.cluster.ClientConnectionClustered@5b6f67bb, cluster-contr@test=tigase.cluster.ClusterController@52847b05, sess-man@test=tigase.cluster.SessionManagerClustered@1553f9b2, vhost-man@test=tigase.cluster.VHostManagerClustered@7e2c946e, ssend@test=tigase.server.ssender.StanzaSender@4a2c7e37, bosh@test=tigase.cluster.BoshConnectionClustered@43c7208e, s2s@test=tigase.cluster.S2SConnectionClustered@45bbd91, ws2s@test=tigase.cluster.WebSocketClientConnectionClustered@64763385, basic-conf@test=tigase.conf.Configurator@4299c84a, srecv@test=tigase.server.sreceiver.StanzaReceiver@1dd527ea, message-archive@test=tigase.archive.MessageArchiveComponent@2e08a85e, monitor@test=tigase.cluster.MonitorClustered@1fd70207, muc@test=tigase.muc.MUCComponent@acaf0ac, stats@test=tigase.stats.StatisticsCollector@3854e123}
2014-05-06 11:13:27.588 [in_2-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@test, from=sess-man@test, to=c2s@test/182.92.129.9_5222_182.151.205.33_32381, DATA=<iq type="result" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="sess-man@test" to="c2s@test/182.92.129.9_5222_182.151.205.33_32381"/>, SIZE=135, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-05-06 11:13:27.594 [pool-16-thread-3]  ClientConnectionManager.xmppStreamClosed()  FINE: Service stopped, sending packet: from=null, to=null, DATA=<iq type="set" id="457b5d18-dbde-42ab-8f5f-ad04d90a3d88" from="c2s@test/182.92.129.9_5222_182.151.205.33_32381" to="sess-man@test"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_CLOSED"/></iq>, SIZE=211, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-05-06 11:13:27.757 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Supported protocols: (+)SSLv2Hello,(+)SSLv3,(+)TLSv1,(+)TLSv1.1,(+)TLSv1.2
2014-05-06 11:13:27.767 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Supported ciphers: (+)TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,(+)TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384,(+)TLS_RSA_WITH_AES_256_CBC_SHA256,(+)TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,(+)TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384,(+)TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,(+)TLS_DHE_DSS_WITH_AES_256_CBC_SHA256,(+)TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,(+)TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,(+)TLS_RSA_WITH_AES_256_CBC_SHA,(+)TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,(+)TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,(+)TLS_DHE_RSA_WITH_AES_256_CBC_SHA,(+)TLS_DHE_DSS_WITH_AES_256_CBC_SHA,(+)TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,(+)TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256,(+)TLS_RSA_WITH_AES_128_CBC_SHA256,(+)TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,(+)TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256,(+)TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,(+)TLS_DHE_DSS_WITH_AES_128_CBC_SHA256,(+)TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,(+)TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,(+)TLS_RSA_WITH_AES_128_CBC_SHA,(+)TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,(+)TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,(+)TLS_DHE_RSA_WITH_AES_128_CBC_SHA,(+)TLS_DHE_DSS_WITH_AES_128_CBC_SHA,(+)TLS_ECDHE_ECDSA_WITH_RC4_128_SHA,(+)TLS_ECDHE_RSA_WITH_RC4_128_SHA,(+)SSL_RSA_WITH_RC4_128_SHA,(+)TLS_ECDH_ECDSA_WITH_RC4_128_SHA,(+)TLS_ECDH_RSA_WITH_RC4_128_SHA,(+)TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA,(+)TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA,(+)SSL_RSA_WITH_3DES_EDE_CBC_SHA,(+)TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA,(+)TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA,(+)SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA,(+)SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA,(+)SSL_RSA_WITH_RC4_128_MD5,(+)TLS_EMPTY_RENEGOTIATION_INFO_SCSV,(-)TLS_DH_anon_WITH_AES_256_CBC_SHA256,(-)TLS_ECDH_anon_WITH_AES_256_CBC_SHA,(-)TLS_DH_anon_WITH_AES_256_CBC_SHA,(-)TLS_DH_anon_WITH_AES_128_CBC_SHA256,(-)TLS_ECDH_anon_WITH_AES_128_CBC_SHA,(-)TLS_DH_anon_WITH_AES_128_CBC_SHA,(-)TLS_ECDH_anon_WITH_RC4_128_SHA,(-)SSL_DH_anon_WITH_RC4_128_MD5,(-)TLS_ECDH_anon_WITH_3DES_EDE_CBC_SHA,(-)SSL_DH_anon_WITH_3DES_EDE_CBC_SHA,(-)TLS_RSA_WITH_NULL_SHA256,(-)TLS_ECDHE_ECDSA_WITH_NULL_SHA,(-)TLS_ECDHE_RSA_WITH_NULL_SHA,(-)SSL_RSA_WITH_NULL_SHA,(-)TLS_ECDH_ECDSA_WITH_NULL_SHA,(-)TLS_ECDH_RSA_WITH_NULL_SHA,(-)TLS_ECDH_anon_WITH_NULL_SHA,(-)SSL_RSA_WITH_NULL_MD5,(-)SSL_RSA_WITH_DES_CBC_SHA,(-)SSL_DHE_RSA_WITH_DES_CBC_SHA,(-)SSL_DHE_DSS_WITH_DES_CBC_SHA,(-)SSL_DH_anon_WITH_DES_CBC_SHA,(-)SSL_RSA_EXPORT_WITH_RC4_40_MD5,(-)SSL_DH_anon_EXPORT_WITH_RC4_40_MD5,(-)SSL_RSA_EXPORT_WITH_DES40_CBC_SHA,(-)SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA,(-)SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA,(-)SSL_DH_anon_EXPORT_WITH_DES40_CBC_SHA,(-)TLS_KRB5_WITH_RC4_128_SHA,(-)TLS_KRB5_WITH_RC4_128_MD5,(-)TLS_KRB5_WITH_3DES_EDE_CBC_SHA,(-)TLS_KRB5_WITH_3DES_EDE_CBC_MD5,(-)TLS_KRB5_WITH_DES_CBC_SHA,(-)TLS_KRB5_WITH_DES_CBC_MD5,(-)TLS_KRB5_EXPORT_WITH_RC4_40_SHA,(-)TLS_KRB5_EXPORT_WITH_RC4_40_MD5,(-)TLS_KRB5_EXPORT_WITH_DES_CBC_40_SHA,(-)TLS_KRB5_EXPORT_WITH_DES_CBC_40_MD5
2014-05-06 11:13:27.768 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Hardened mode is disabled
2014-05-06 11:13:27.769 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Enabled protocols: default
2014-05-06 11:13:27.770 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Workaround for TLS/SSL bug is enabled
2014-05-06 11:13:27.771 [in_2-c2s]         TLSWrapper.<clinit>()              CONFIG:   Enabled ciphers: [SSL_RSA_WITH_RC4_128_MD5, SSL_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
2014-05-06 11:13:27.777 [in_2-c2s]         TLSWrapper.<init>()                INFO:     Created server TLSWrapper. Protocols:[SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]; Ciphers:[SSL_RSA_WITH_RC4_128_MD5, SSL_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
2014-05-06 11:13:27.781 [in_2-c2s]         ClientConnectionManager$StoppedHandler.responseReceived()  FINEST: Response for stop received...

Replies (1)

Added by Wojciech Kapcia TigaseTeam over 4 years ago

Can you rephrase your problem? Do you mean that sometimes when you try to connect Psi client won't connect with the error 'disconnected'?

What Tigase version do you use? In what environment (operating system, jvm version)? What settings do you use? Could you provide log output with the following debugging options enabled:

--debug=server,xmpp,io,net

    (1-1/1)