Project

General

Profile

Message was not recevied by destination client

Mauro Carrio
Added about 5 years ago

Hi, we're still experimenting lost messages. An example, user 5553405304@mydomain.com/android sent to 5553016950@mydomain.com a composing and a chat message with body: Djjdj. That chat message was not received by the destination user.

I got the Tigase logs of that moment and I would like you could check the log messages:

2014-02-10 11:54:40.962 [in_6-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [gv-push-service, gv-simple-presence-v2, gv-presence-ack, amp]
2014-02-10 11:54:40.991 [pool-8-thread-1]  ConnectionManager$1.run()          FINE:     Reconnecting service for component: s2s, to remote host: chat.mydomain.com on port: 5,269
2014-02-10 11:54:40.992 [ConnectionOpenThread]  ConnectionManager$ConnectionListenerImpl.accept()  FINEST: Accept called for service: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [ConnectionOpenThread]  ConnectionManager$ConnectionListenerImpl.accept()  FINEST: Problem reconnecting the service: CID: mydomain.com@chat.mydomain.com, null, type: connect, Socket: null, jid: null, cid: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [ConnectionOpenThread]  CIDConnections.checkOpenConnections()  FINEST: Scheduling task for openning a new connection for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [pool-9-thread-1]  CIDConnections$2.run()             FINEST:   Running scheduled task for openning a new connection for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [pool-9-thread-1]  CIDConnections.openOutgoingConnections()  FINEST: Checking DNS for host: chat.mydomain.com for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [pool-9-thread-1]  CIDConnections.initNewConnection()  FINEST:  STARTING new connection: mydomain.com@chat.mydomain.com
2014-02-10 11:54:40.992 [pool-9-thread-1]  CIDConnections.initNewConnection()  FINEST:  mydomain.com@chat.mydomain.com connection params: {cid=mydomain.com@chat.mydomain.com, ifc=[Ljava.lang.String;@2cd643e1, local-hostname=mydomain.com, port-no=5269, remote-hostname=chat.mydomain.com, remote-ip=10.40.58.204, s2s-connection-key=S2S: null, socket=plain, srv-type=_xmpp-server._tcp, type=connect}
2014-02-10 11:54:40.993 [pool-9-thread-1]  ConnectionManager.reconnectService()  FINER: Reconnecting service for: s2s, scheduling next try in 2secs, cid: mydomain.com@chat.mydomain.com
2014-02-10 11:54:41.221 [pool-14-thread-5]  XMPPIOService.processSocketData()  FINEST:  null, type: accept, Socket: nullSocket[addr=/10.40.58.208,port=37602,localport=5275], jid: null, READ: 
2014-02-10 11:54:41.313 [pool-14-thread-2]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_107.107.184.231_22725, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_107.107.184.231_22725 Socket[addr=/107.107.184.231,port=22725,localport=5222], jid: 1000881523@mydomain.com/iphone, READ: 
2014-02-10 11:54:41.314 [pool-14-thread-1]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_223.255.229.17_34062, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_223.255.229.17_34062 Socket[addr=/223.255.229.17,port=34062,localport=5222], jid: 1000865965@mydomain.com/iphone, READ: 
2014-02-10 11:54:42.219 [pool-14-thread-3]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278 Socket[addr=/65.34.162.38,port=45278,localport=5222], jid: 5553405304@mydomain.com/android, READ:<message id="nSuei-39" to="5553016950@mydomain.com" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>
2014-02-10 11:54:42.219 [pool-14-thread-3]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278 Socket[addr=/65.34.162.38,port=45278,localport=5222], jid: 5553405304@mydomain.com/android, Read packet: <message to="5553016950@mydomain.com" id="nSuei-39" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>
2014-02-10 11:54:42.220 [pool-14-thread-3]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=110, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278
2014-02-10 11:54:42.220 [pool-14-thread-3]  ClientConnectionManager.processSocketData()  FINEST: XMLNS set for packet: from=null, to=null, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=132, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=132, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@localhost.localdomain
2014-02-10 11:54:42.220 [in_0-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@localhost.localdomain, from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=132, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=132, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=132, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=5553405304@mydomain.com/android, packets=28, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.221 [in_4-sess-man]    PacketDefaultHandler.preprocess()  FINEST:   Setting correct from attribute: 5553405304@mydomain.com/android
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: PushNotification (gv-push-service)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=5553405304@mydomain.com/android, packets=29, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAckPlugin (gv-message-ack)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=5553405304@mydomain.com/android, packets=29, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAmp (amp)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=5553405304@mydomain.com/android, packets=29, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageCarbons (message-carbons)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=5553405304@mydomain.com/android, packets=29, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.221 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [gv-push-service, gv-message-ack, amp, message-carbons]
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:42.222 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:42.223 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:42.223 [in_3-message-router]  MessageRouter.processPacket()  FINEST:   2. Packet will be processed by: sess-man@localhost.localdomain, from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.getXMPPResourceConnection()  FINEST: Searching for resource connection for: 5553016950@mydomain.com
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.getResourceConnection()  FINEST: Session not null, searching session for jid: 5553016950@mydomain.com
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.getResourceConnection()  FINEST: Found session: user_jid=5553016950@mydomain.com/iphone, packets=38, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false, for jid: 5553016950@mydomain.com
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null, connection: user_jid=5553016950@mydomain.com/iphone, packets=38, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: PushNotification (gv-push-service)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null, conn: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.223 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAckPlugin (gv-message-ack)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null, conn: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.224 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAmp (amp)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null, conn: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.224 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageCarbons (message-carbons)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null, conn: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:42.224 [in_3-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [gv-push-service, gv-message-ack, amp, message-carbons]
2014-02-10 11:54:42.224 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.224 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:42.224 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:42.224 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:42.224 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:42.225 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941
2014-02-10 11:54:42.225 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.
RestMessageReceiver@6a2c4842, amp@localhost.localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:42.225 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@localhost.localdomain, from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.225 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.225 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, Writing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.225 [in_1-c2s]         XMPPIOService.processWaitingPackets()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, Sending packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>, SIZE=169, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=null
2014-02-10 11:54:42.225 [in_1-c2s]         XMPPIOService.processWaitingPackets()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, SENT: <message to="5553016950@mydomain.com" id="nSuei-39" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><x xmlns="jabber:x:event"><composing/></x></message>
2014-02-10 11:54:42.226 [pool-14-thread-4]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_178.61.164.69_58759, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_178.61.164.69_58759 Socket[addr=/178.61.164.69,port=58759,localport=5222], jid: 5553293331@mydomain.com/iphone, READ: 
2014-02-10 11:54:42.317 [pool-14-thread-5]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_37.237.8.60_49816, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_37.237.8.60_49816 Socket[addr=/37.237.8.60,port=49816,localport=5222], jid: 1000786255@mydomain.com/iphone, READ: 
2014-02-10 11:54:42.993 [pool-8-thread-1]  ConnectionManager$1.run()          FINE:     Reconnecting service for component: s2s, to remote host: chat.mydomain.com on port: 5,269
2014-02-10 11:54:42.994 [ConnectionOpenThread]  ConnectionManager$ConnectionListenerImpl.accept()  FINEST: Accept called for service: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.994 [ConnectionOpenThread]  ConnectionManager$ConnectionListenerImpl.accept()  FINEST: Problem reconnecting the service: CID: mydomain.com@chat.mydomain.com, null, type: connect, Socket: null, jid: null, cid: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.994 [ConnectionOpenThread]  CIDConnections.checkOpenConnections()  FINEST: Scheduling task for openning a new connection for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.995 [pool-9-thread-1]  CIDConnections$2.run()             FINEST:   Running scheduled task for openning a new connection for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.995 [pool-9-thread-1]  CIDConnections.openOutgoingConnections()  FINEST: Checking DNS for host: chat.mydomain.com for: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.995 [pool-9-thread-1]  CIDConnections.initNewConnection()  FINEST:  STARTING new connection: mydomain.com@chat.mydomain.com
2014-02-10 11:54:42.995 [pool-9-thread-1]  CIDConnections.initNewConnection()  FINEST:  mydomain.com@chat.mydomain.com connection params: {cid=mydomain.com@chat.mydomain.com, ifc=[Ljava.lang.String;@359237d1, local-hostname=mydomain.com, port-no=5269, remote-hostname=chat.mydomain.com, remote-ip=10.40.58.204, s2s-connection-key=S2S: null, socket=plain, srv-type=_xmpp-server._tcp, type=connect}
2014-02-10 11:54:42.995 [pool-9-thread-1]  ConnectionManager.reconnectService()  FINER: Reconnecting service for: s2s, scheduling next try in 2secs, cid: mydomain.com@chat.mydomain.com
2014-02-10 11:54:43.258 [pool-14-thread-2]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278 Socket[addr=/65.34.162.38,port=45278,localport=5222], jid: 5553405304@mydomain.com/android, READ:<message id="nSuei-40" to="5553016950@mydomain.com" type="chat" ttl="0"><body>Djjdjd</body></message>
2014-02-10 11:54:43.258 [pool-14-thread-2]  XMPPIOService.processSocketData()  FINEST:  c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278 Socket[addr=/65.34.162.38,port=45278,localport=5222], jid: 5553405304@mydomain.com/android, Read packet: <message to="5553016950@mydomain.com" type="chat" id="nSuei-40" ttl="0"><body>Djjdjd</body></message>
2014-02-10 11:54:43.258 [pool-14-thread-2]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" ttl="0"><body>CData size: 6</body></message>, SIZE=99, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat from connection: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278
2014-02-10 11:54:43.258 [pool-14-thread-2]  ClientConnectionManager.processSocketData()  FINEST: XMLNS set for packet: from=null, to=null, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0"><body>CData size: 6</body></message>, SIZE=121, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat from connection: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278
2014-02-10 11:54:43.258 [in_0-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0"><body>Djjdjd</body></message>, SIZE=121, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat
2014-02-10 11:54:43.258 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:43.258 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:43.258 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:43.259 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:43.259 [in_0-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@localhost.localdomain
2014-02-10 11:54:43.259 [in_0-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@localhost.localdomain, from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0"><body>Djjdjd</body></message>, SIZE=121, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat
2014-02-10 11:54:43.259 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0"><body>CData size: 6</body></message>, SIZE=121, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat
2014-02-10 11:54:43.259 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0"><body>CData size: 6</body></message>, SIZE=121, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat, connection: user_jid=5553405304@mydomain.com/android, packets=29, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.259 [in_4-sess-man]    PacketDefaultHandler.preprocess()  FINEST:   Setting correct from attribute: 5553405304@mydomain.com/android
2014-02-10 11:54:43.259 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: PushNotification (gv-push-service)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat, conn: user_jid=5553405304@mydomain.com/android, packets=30, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.259 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAckPlugin (gv-message-ack)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat, conn: user_jid=5553405304@mydomain.com/android, packets=30, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.260 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAmp (amp)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat, conn: user_jid=5553405304@mydomain.com/android, packets=30, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:43.260 [in_3-message-router]  MessageRouter.processPacket()  FINEST:   2. Packet will be processed by: sess-man@localhost.localdomain, from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=sess-man@localhost.localdomain, to=null, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>CData size: 6</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.getXMPPResourceConnection()  FINEST: Searching for resource connection for: 5553016950@mydomain.com
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.getResourceConnection()  FINEST: Session not null, searching session for jid: 5553016950@mydomain.com
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.getResourceConnection()  FINEST: Found session: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false, for jid: 5553016950@mydomain.com
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>CData size: 6</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat, connection: user_jid=5553016950@mydomain.com/iphone, packets=39, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: PushNotification (gv-push-service)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat, conn: user_jid=5553016950@mydomain.com/iphone, packets=40, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.261 [in_4-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageCarbons (message-carbons)Request: from=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=chat, conn: user_jid=5553405304@mydomain.com/android, packets=30, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_45278, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAckPlugin (gv-message-ack)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat, conn: user_jid=5553016950@mydomain.com/iphone, packets=40, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.261 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageAmp (amp)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat, conn: user_jid=5553016950@mydomain.com/iphone, packets=40, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false
2014-02-10 11:54:43.261 [in_4-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [gv-push-service, gv-message-ack, amp, message-carbons]
2014-02-10 11:54:43.261 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : 5553016950@mydomain.com
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): 5553016950@mydomain.com, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.RestMessageReceiver@6a2c4842, amp@localhost.
localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Still no comp name matches (VHost lookup): 5553016950@mydomain.com, for map: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, for all VHosts: {3}
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Component match failed: 5553016950@mydomain.com, for comp: {ext=tigase.server.ext.ComponentProtocol@a08447c, c2s=tigase.server.xmppclient.ClientConnectionManager@40c7b387, basic-conf=tigase.conf.Configurator@386fd9da, s2s=tigase.server.xmppserver.S2SConnectionManager@1290b599, rest=tigase.http.rest.RestMessageReceiver@6a2c4842, bosh=tigase.server.bosh.BoshConnectionManager@79c06e97, vhost-man=tigase.vhosts.VHostManager@37479428, sess-man=tigase.server.xmppsession.SessionManager@3f6f10fa, ws2s=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, message-router=tigase.server.MessageRouter@3c4fea72, stats=tigase.stats.StatisticsCollector@7334f9ca, amp=tigase.server.amp.AmpComponent@36e22c47, monitor=tigase.server.monitor.MonitorComponent@5b55cfe6, webrtc=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6}, basename: com
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, for map: {ws2s@localhost.localdomain=tigase.server.websocket.WebSocketClientConnectionManager@2ab43408, c2s@localhost.localdomain=tigase.server.xmppclient.ClientConnectionManager@40c7b387, stats@localhost.localdomain=tigase.stats.StatisticsCollector@7334f9ca, s2s@localhost.localdomain=tigase.server.xmppserver.S2SConnectionManager@1290b599, vhost-man@localhost.localdomain=tigase.vhosts.VHostManager@37479428, webrtc@localhost.localdomain=tigase.mydomain.webrtc.WebRTCComponent@3d63ba6, sess-man@localhost.localdomain=tigase.server.xmppsession.SessionManager@3f6f10fa, bosh@localhost.localdomain=tigase.server.bosh.BoshConnectionManager@79c06e97, ext@localhost.localdomain=tigase.server.ext.ComponentProtocol@a08447c, basic-conf@localhost.localdomain=tigase.conf.Configurator@386fd9da, rest@localhost.localdomain=tigase.http.rest.
RestMessageReceiver@6a2c4842, amp@localhost.localdomain=tigase.server.amp.AmpComponent@36e22c47, monitor@localhost.localdomain=tigase.server.monitor.MonitorComponent@5b55cfe6}
2014-02-10 11:54:43.262 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@localhost.localdomain, from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.262 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>CData size: 6</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.262 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, Writing packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.262 [in_1-c2s]         XMPPIOService.processWaitingPackets()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, Sending packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat
2014-02-10 11:54:43.262 [in_1-c2s]         XMPPIOService.processWaitingPackets()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, SENT: <message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>
2014-02-10 11:54:43.262 [in_3-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: MessageCarbons (message-carbons)Request: from=sess-man@localhost.localdomain, to=sess-man@localhost.localdomain, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat, conn: user_jid=5553016950@mydomain.com/iphone, packets=40, connectioId=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, domain=mydomain.com, authState=AUTHORIZED, isAnon=false, isTmp=false

I'm using Tigase-5.2.0-RC1 on Fedora 15 the clients have implemented Stream Management with resumption enabled. I would like to find out where is the problem, whether is on server, client side or a lacking connectivity network. Any other information you think that will be helpful please let me know.

Really this problem is very serious for us, I would appreciate a lot your help.

Thanks in advance.


Replies (9)

Added by Andrzej Wójcik IoT 1 CloudTigaseTeam about 5 years ago

Hi, I part of a log you provided, we can see that message is delivered to ClientConnectionManager, but socket to which ClientConnectionManager tries to write this messages is closed. If Stream Resumption is enabled this is ok, as when client will resume connection(stream) client should receive this message and all should work well, but from the part of a log you provided there is no way to tell if Stream Resumption is enabled, or if client tried or will try to resume stream.

Below part of a log in which you can see that socket is closed - look for Socket[unconnected]

2014-02-10 11:54:43.262 [in_1-c2s]         XMPPIOService.processWaitingPackets()  FINEST: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone, Sending packet: from=sess-man@localhost.localdomain, to=c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, DATA=<message to="5553016950@mydomain.com" type="chat" id="nSuei-40" xmlns="jabber:client" ttl="0" from="5553405304@mydomain.com/android"><body>Djjdjd</body></message>, SIZE=158, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=chat

Added by Mauro Carrio about 5 years ago

Andrzej, thanks for your answer.

The client didnt resume the session because the resumption timeout on client had expired so when it login it enabled a new one. But to Tigase the client session was still active when really was disconnected abruptly and then the mobile app was closed.

I have configured watchdog in ConnectionManager to run every 10" and set maxInactiveTime to 30". Tigase detected inactive time exceeded so stopped the service for the client (I saw this in log), but it remained active because it tried to deliver the message. So the resumption timeout on server never started so the messages were lost. I think that whatchdog really is not stopping inactive services.

I could send you all log activity if you want. Any thought?

Thanks

Added by Mauro Carrio about 5 years ago

Whatchdog log:

2014-02-10 12:15:35.677 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_108.228.204.69_53317, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_108.228.204.69_53317 Socket[unconnected], jid: 1000499570@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_173.209.207.238_49801, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_173.209.207.238_49801 Socket[unconnected], jid: 5553030622@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_173.209.204.240_60281, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_173.209.204.240_60281 Socket[unconnected], jid: 5553030622@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_166.147.116.153_2280, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_166.147.116.153_2280 Socket[unconnected], jid: 5553010691@mydomain.com/android
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_174.141.168.231_56591, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_174.141.168.231_56591 Socket[unconnected], jid: 5553015516@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_174.141.168.231_57741, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_174.141.168.231_57741 Socket[unconnected], jid: 5553015516@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_47941 Socket[unconnected], jid: 5553016950@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_166.147.108.42_55799, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_166.147.108.42_55799 Socket[unconnected], jid: 1000499570@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_166.147.108.42_33405, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_166.147.108.42_33405 Socket[unconnected], jid: 1000499570@mydomain.com/iphone
2014-02-10 12:15:35.678 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_108.228.204.69_51414, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_108.228.204.69_51414 Socket[unconnected], jid: 1000499570@mydomain.com/iphone
2014-02-10 12:15:35.679 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_172.56.26.12_32023, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_172.56.26.12_32023 Socket[unconnected], jid: 5553015516@mydomain.com/iphone
2014-02-10 12:15:35.679 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_41811, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_65.34.162.38_41811 Socket[unconnected], jid: 5553016950@mydomain.com/iphone

All those connections should be stopped by tigase, but the services for these users seem to be active if whatchdog process still loop into these services. This messages repeat every time.

Added by Andrzej Wójcik IoT 1 CloudTigaseTeam about 5 years ago

I checked stream resumption implementation in case it might contain code which would lead to keep stale services for undetermined period of time. It look like it might lead to this situation in rare cases in which stream resumption will fail during resumption. I added code which will detect if stale connection which started resumption after some period of time is stilll available. If so, then this service will be closed and unregistered. I suppose that this fix will be released after release 5.2.0 and as a part of release 5.2.1

Added by Mauro Carrio about 5 years ago

Ok, I'm glad to know from where the problem could be. We're experiencing this issue very often, if you could send the fix (code or changed file) would be very important for us and also we could easily test it in our development environment.

Thanks a lot!

Avatar?id=6023&size=32x32

Added by Artur Hefczyc TigaseTeam about 5 years ago

As far as I know the bug is fixed already and the fix is committed to our code repository.

Added by Mauro Carrio about 5 years ago

Yes, it does. Thank you!

Added by Mauro Carrio about 5 years ago

Hi guys, after testing these days the fix you made in stream resumption it seems to be working better.

Looking inside the log files I found that Tigase is still logging that connection max inactive time exceeded for a user over different connection ports so I'm guessing that maybe one user has many sessions active in Tigase.

2014-02-18 17:53:37.580 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_27381, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_27381 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.580 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2sFound dead connection, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_27381, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_27381 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_21903, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_21903 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2sFound dead connection, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_21903, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_21903 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_22873, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_22873 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2sFound dead connection, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_22873, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_22873 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2s: Max inactive time exceeded, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_10359, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_10359 Socket[unconnected], jid: 1000866940@mydomain.com/android
2014-02-18 17:53:37.581 [Watchdog - c2s]   ConnectionManager$Watchdog$1.check()  INFO:  c2sFound dead connection, stopping: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_10359, type: accept, Socket: c2s@localhost.localdomain/10.40.58.209_5222_186.38.21.122_10359 Socket[unconnected], jid: 1000866940@mydomain.com/android

What do you think about it?

Thanks.

Added by Andrzej Wójcik IoT 1 CloudTigaseTeam about 5 years ago

From what I see during 10 minutes your client connection failed at least 4 times and your client failed during resumption of stream. Due to failed resumption connection was still available in list of active connections and 4 of them were found and closed due to max inactivity time exceeded.

    (1-9/9)