Project

General

Profile

Invalid username or password

Diego Barrera
Added about 5 years ago

Hello,

I am new to Tigase. I have compiled, installed and run Tigase.

I also created users in the database with:

call TigAddUserPlainPw('test', 't3st');

And checked it was working with:

call TigUserLoginPlainPw('test', 't3st');

All good. However I'm trying to login from the same machine with Spark and I get an 'invalid username or password'. The data I input is:

Username: test (I also tried 'test@xmppServer')

Password: t3st

Server: localhost

My init.properties is as follows:

config-type = --gen-config-def
--admins = admin@xmppServer
--virt-hosts = xmppServer
--debug = server
--sm-plugins = +jabber:iq:register

Most importantly, the ddbb shows no failed logins except the ones I failed on purpose with the DDBB call TigUserLoginPlainPw. Any help is most appreciated.

Some other info:

Checking arguments to Tigase: 
OSGI            =  
TIGASE_HOME     =  /home/diego/git/tigase-server/.
TIGASE_JAR      =  /home/diego/git/tigase-server/./jars/tigase-server.jar
TIGASE_PARAMS   =  etc/tigase.conf
TIGASE_RUN      =  tigase.server.XMPPServer  --property-file etc/init.properties 
TIGASE_PID      =  /home/diego/git/tigase-server/./logs/tigase.pid
TIGASE_OPTIONS  =   --property-file etc/init.properties 
JAVA_OPTIONS    =    -Dfile.encoding=UTF-8 -Dsun.jnu.encoding=UTF-8 -Djdbc.drivers=com.mysql.jdbc.Driver:org.postgresql.Driver:org.apache.derby.jdbc.EmbeddedDriver -server -Xms100M -Xmx200M -XX:PermSize=32m -XX:MaxPermSize=256m -XX:MaxDirectMemorySize=128m 
JAVA            =  /usr/lib/jvm/java-7-oracle/bin/java
JAVA_CMD        =  
CLASSPATH       =  /home/diego/git/tigase-server/./jars/derby.jar:/home/diego/git/tigase-server/./jars/derbytools.jar:/home/diego/git/tigase-server/./jars/groovy-all.jar:/home/diego/git/tigase-server/./jars/hamcrest-core.jar:/home/diego/git/tigase-server/./jars/javax.servlet.jar:/home/diego/git/tigase-server/./jars/jdmkrt.jar:/home/diego/git/tigase-server/./jars/jetty-continuation.jar:/home/diego/git/tigase-server/./jars/jetty-deploy.jar:/home/diego/git/tigase-server/./jars/jetty-http.jar:/home/diego/git/tigase-server/./jars/jetty-io.jar:/home/diego/git/tigase-server/./jars/jetty-osgi-boot.jar:/home/diego/git/tigase-server/./jars/jetty-security.jar:/home/diego/git/tigase-server/./jars/jetty-server.jar:/home/diego/git/tigase-server/./jars/jetty-servlet.jar:/home/diego/git/tigase-server/./jars/jetty-util.jar:/home/diego/git/tigase-server/./jars/jetty-webapp.jar:/home/diego/git/tigase-server/./jars/jetty-xml.jar:/home/diego/git/tigase-server/./jars/jstun.jar:/home/diego/git/tigase-server/./jars/jtds.jar:/home/diego/git/tigase-server/./jars/jul-to-slf4j.jar:/home/diego/git/tigase-server/./jars/junit.jar:/home/diego/git/tigase-server/./jars/licence-lib.jar:/home/diego/git/tigase-server/./jars/logback-classic.jar:/home/diego/git/tigase-server/./jars/logback-core.jar:/home/diego/git/tigase-server/./jars/mysql-connector-java.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.bundlerepository.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.configadmin.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.http.bundle.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.main.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.shell.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.shell.remote.jar:/home/diego/git/tigase-server/./jars/org.osgi.core.jar:/home/diego/git/tigase-server/./jars/postgresql.jar:/home/diego/git/tigase-server/./jars/slf4j-api.jar:/home/diego/git/tigase-server/./jars/tigase-acs.jar:/home/diego/git/tigase-server/./jars/tigase-acs-muc.jar:/home/diego/git/tigase-server/./jars/tigase-acs-pubsub.jar:/home/diego/git/tigase-server/./jars/tigase-extras.jar:/home/diego/git/tigase-server/./jars/tigase-http-api.jar:/home/diego/git/tigase-server/./jars/tigase-message-archiving.jar:/home/diego/git/tigase-server/./jars/tigase-muc.jar:/home/diego/git/tigase-server/./jars/tigase-pubsub.jar:/home/diego/git/tigase-server/./jars/tigase-server.jar:/home/diego/git/tigase-server/./jars/tigase-socks5.jar:/home/diego/git/tigase-server/./jars/tigase-stats-collector-library.jar:/home/diego/git/tigase-server/./jars/tigase-stats-collector-provider.jar:/home/diego/git/tigase-server/./jars/tigase-stun.jar:/home/diego/git/tigase-server/./jars/tigase-utils.jar:/home/diego/git/tigase-server/./jars/tigase-xmltools.jar:/home/diego/git/tigase-server/./jars/tigase-server.jar
TIGASE_CMD      =  /usr/lib/jvm/java-7-oracle/bin/java   -Dfile.encoding=UTF-8 -Dsun.jnu.encoding=UTF-8 -Djdbc.drivers=com.mysql.jdbc.Driver:org.postgresql.Driver:org.apache.derby.jdbc.EmbeddedDriver -server -Xms100M -Xmx200M -XX:PermSize=32m -XX:MaxPermSize=256m -XX:MaxDirectMemorySize=128m  -Dlogback.configurationFile=/home/diego/git/tigase-server/./etc/logback.xml -cp /home/diego/git/tigase-server/./jars/derby.jar:/home/diego/git/tigase-server/./jars/derbytools.jar:/home/diego/git/tigase-server/./jars/groovy-all.jar:/home/diego/git/tigase-server/./jars/hamcrest-core.jar:/home/diego/git/tigase-server/./jars/javax.servlet.jar:/home/diego/git/tigase-server/./jars/jdmkrt.jar:/home/diego/git/tigase-server/./jars/jetty-continuation.jar:/home/diego/git/tigase-server/./jars/jetty-deploy.jar:/home/diego/git/tigase-server/./jars/jetty-http.jar:/home/diego/git/tigase-server/./jars/jetty-io.jar:/home/diego/git/tigase-server/./jars/jetty-osgi-boot.jar:/home/diego/git/tigase-server/./jars/jetty-security.jar:/home/diego/git/tigase-server/./jars/jetty-server.jar:/home/diego/git/tigase-server/./jars/jetty-servlet.jar:/home/diego/git/tigase-server/./jars/jetty-util.jar:/home/diego/git/tigase-server/./jars/jetty-webapp.jar:/home/diego/git/tigase-server/./jars/jetty-xml.jar:/home/diego/git/tigase-server/./jars/jstun.jar:/home/diego/git/tigase-server/./jars/jtds.jar:/home/diego/git/tigase-server/./jars/jul-to-slf4j.jar:/home/diego/git/tigase-server/./jars/junit.jar:/home/diego/git/tigase-server/./jars/licence-lib.jar:/home/diego/git/tigase-server/./jars/logback-classic.jar:/home/diego/git/tigase-server/./jars/logback-core.jar:/home/diego/git/tigase-server/./jars/mysql-connector-java.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.bundlerepository.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.configadmin.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.http.bundle.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.main.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.shell.jar:/home/diego/git/tigase-server/./jars/org.apache.felix.shell.remote.jar:/home/diego/git/tigase-server/./jars/org.osgi.core.jar:/home/diego/git/tigase-server/./jars/postgresql.jar:/home/diego/git/tigase-server/./jars/slf4j-api.jar:/home/diego/git/tigase-server/./jars/tigase-acs.jar:/home/diego/git/tigase-server/./jars/tigase-acs-muc.jar:/home/diego/git/tigase-server/./jars/tigase-acs-pubsub.jar:/home/diego/git/tigase-server/./jars/tigase-extras.jar:/home/diego/git/tigase-server/./jars/tigase-http-api.jar:/home/diego/git/tigase-server/./jars/tigase-message-archiving.jar:/home/diego/git/tigase-server/./jars/tigase-muc.jar:/home/diego/git/tigase-server/./jars/tigase-pubsub.jar:/home/diego/git/tigase-server/./jars/tigase-server.jar:/home/diego/git/tigase-server/./jars/tigase-socks5.jar:/home/diego/git/tigase-server/./jars/tigase-stats-collector-library.jar:/home/diego/git/tigase-server/./jars/tigase-stats-collector-provider.jar:/home/diego/git/tigase-server/./jars/tigase-stun.jar:/home/diego/git/tigase-server/./jars/tigase-utils.jar:/home/diego/git/tigase-server/./jars/tigase-xmltools.jar:/home/diego/git/tigase-server/./jars/tigase-server.jar tigase.server.XMPPServer  --property-file etc/init.properties 
TIGASE_CONSOLE_LOG  =  /home/diego/git/tigase-server/./logs/tigase-console.log


Replies (9)

Avatar?id=6023&size=32x32

Added by Artur Hefczyc TigaseTeam about 5 years ago

Thank you for all the detailed information. It certainly helps.

In your case, you forgot that a user ID in XMPP is like email: username@domain. So, when you create an account in DB you have to add a domain name to the username:

call TigAddUserPlainPw('test@xmppServer'', 't3st');
call TigUserLoginPlainPw('test@xmppServer'', 't3st');

This should work, however, just so you know, I do not have any experience with Spark, so I do not know whether you have to provide a user name or user name and domain.

Added by Diego Barrera about 5 years ago

Thanks I just did that but problem still persists. I decided to try a different client so I switched to Pidgin to see if I could get more significant feedback.

I also changed my virtual host to 'piruleta' and created a 'test@piruleta' user in DDBB, I rebooted the server as well. I also added piruleta with my IP to the /etc/hosts file which makes the error "invalid username or password" happen much faster so less waiting!!

Anyway onto pidgin I managed to get asked to Accept a certificate, after I accepted it I get a 'Not Authorized' message from Pidgin. This is what happens in logs/tigase.log.0 when I try to login and get the 'Not Authorized' and still no failed logins in tigasedb table of users:

2014-03-10 23:37:21.613 [ConnectionOpenThread]  ConnectionManager.serviceStarted()  FINER: [[c2s]] Connection started: null, type: accept, Socket: nullSocket[addr=/192.168.1.132,port=39273,localport=5222], jid: null
2014-03-10 23:37:21.623 [ConnectionOpenThread]  SocketThread.<clinit>()       WARNING:  9 socketReadThreads started.
2014-03-10 23:37:21.630 [ConnectionOpenThread]  SocketThread.<clinit>()       WARNING:  9 socketWriteThreads started.
2014-03-10 23:37:21.644 [pool-10-thread-1]  IOUtil.<clinit>()                 CONFIG:   using direct byte buffers with size 43,690 per buffer
2014-03-10 23:37:21.648 [pool-10-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {xmlns:stream=http://etherx.jabber.org/streams, to=piruleta, xmlns=jabber:client, version=1.0}
2014-03-10 23:37:21.652 [pool-10-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: No Session ID, generating a new one: fa0f893a-9739-4889-9116-28b5ba5ad0c4
2014-03-10 23:37:21.654 [pool-10-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='piruleta' id='fa0f893a-9739-4889-9116-28b5ba5ad0c4' version='1.0' xml:lang='en'>
2014-03-10 23:37:21.657 [pool-10-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: DONE
2014-03-10 23:37:21.660 [pool-10-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: Sending a system command to SM: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="c2s--c2s1" to="sess-man@dv7" type="set"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>fa0f893a-9739-4889-9116-28b5ba5ad0c4</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=417, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:21.663 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="c2s--c2s1" to="sess-man@dv7" type="set"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>fa0f893a-9739-4889-9116-28b5ba5ad0c4</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=417, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:21.663 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:21.664 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:21.664 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="c2s--c2s1" to="sess-man@dv7" type="set"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>fa0f893a-9739-4889-9116-28b5ba5ad0c4</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=417, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:21.666 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="c2s--c2s1" to="sess-man@dv7" type="set"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"><field var="session-id"><value>CData size: 36</value></field><field var="hostname"><value>CData size: 8</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=417, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:21.667 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_OPENED command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.668 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINER: Adding resource connection for: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.668 [pool-10-thread-1]  ClientConnectionManager.xmppStreamOpened()  FINER: DOEN 2
2014-03-10 23:37:21.669 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Setting hostname piruleta for connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, VHostItem: Domain: piruleta, enabled: true, anonym: true, register: true, maxusers: 0, tls: false, s2sSecret: null, domainFilter: ALL
2014-03-10 23:37:21.670 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Domain set for connectionId c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.671 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINEST: Setting session-id fa0f893a-9739-4889-9116-28b5ba5ad0c4 for connection: user_jid=null, packets=0, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-10 23:37:21.671 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="c2s--c2s1" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"/>, SIZE=106, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:21.677 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.677 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.678 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.678 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.679 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="c2s--c2s1" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"/>, SIZE=106, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:21.697 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="2894abe1-3579-499a-9c20-46ba95b521de" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:21.702 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:21.702 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:21.703 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="2894abe1-3579-499a-9c20-46ba95b521de" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:21.703 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="2894abe1-3579-499a-9c20-46ba95b521de" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:21.703 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.707 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="2894abe1-3579-499a-9c20-46ba95b521de" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:21.709 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.712 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.718 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.718 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.719 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="2894abe1-3579-499a-9c20-46ba95b521de" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:21.726 [in_4-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="2894abe1-3579-499a-9c20-46ba95b521de" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:21.740 [in_4-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, type: accept, Socket: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273 Socket[addr=/192.168.1.132,port=39273,localport=5222], jid: null, Writing packet: from=null, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, 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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=454, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-10 23:37:21.756 [pool-10-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@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.772 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, 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-03-10 23:37:21.772 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:21.773 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, 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-03-10 23:37:21.775 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, 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-03-10 23:37:21.776 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, 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@dv7/192.168.1.132_5222_192.168.1.132_39273, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-10 23:37:21.777 [in_12-sess-man]   SessionManager.walk()              FINEST:   XMPPProcessorIfc: StartTLS (starttls)Request: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, 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@dv7/192.168.1.132_5222_192.168.1.132_39273, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-10 23:37:21.778 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Packet processed by: [starttls]
2014-03-10 23:37:21.790 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" id="tig1" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="set"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-10 23:37:21.792 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.792 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.792 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:21.792 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:21.793 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" id="tig1" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="set"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-10 23:37:21.798 [in_4-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" id="tig1" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="set"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x type="submit" xmlns="jabber:x:data"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-10 23:37:21.798 [in_4-c2s]         ClientConnectionManager.processCommand()  FINER: Starting TLS for connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, type: accept, Socket: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273 Socket[addr=/192.168.1.132,port=39273,localport=5222], jid: null
2014-03-10 23:37:22.126 [in_4-c2s]         TLSWrapper.<clinit>()              CONFIG:   Supported protocols: (+)SSLv2Hello,(+)SSLv3,(+)TLSv1,(+)TLSv1.1,(+)TLSv1.2
2014-03-10 23:37:22.134 [in_4-c2s]         TLSWrapper.<clinit>()              CONFIG:   Supported ciphers: (+)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_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-03-10 23:37:22.135 [in_4-c2s]         TLSWrapper.<clinit>()              CONFIG:   Hardened mode is disabled
2014-03-10 23:37:22.135 [in_4-c2s]         TLSWrapper.<clinit>()              CONFIG:   Enabled protocols: default
2014-03-10 23:37:22.135 [in_4-c2s]         TLSWrapper.<clinit>()              CONFIG:   Workaround for TLS/SSL bug is enabled
2014-03-10 23:37:22.135 [in_4-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-03-10 23:37:22.139 [in_4-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-03-10 23:37:22.384 [pool-10-thread-6]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {xmlns:stream=http://etherx.jabber.org/streams, to=piruleta, xmlns=jabber:client, version=1.0}
2014-03-10 23:37:22.384 [pool-10-thread-6]  ClientConnectionManager.xmppStreamOpened()  FINER: Session ID is: fa0f893a-9739-4889-9116-28b5ba5ad0c4
2014-03-10 23:37:22.388 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:22.389 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:22.389 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:22.389 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:22.390 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="sess-man@dv7" type="get"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-10 23:37:22.390 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.393 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:22.403 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.403 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:22.404 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.404 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:22.405 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:22.406 [in_4-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="05a0aec6-4768-47b0-87b1-762a1ae2d922" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>CData size: 5</mechanism><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:22.407 [in_4-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, type: accept, Socket: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273 Socket[addr=/192.168.1.132,port=39273,localport=5222], jid: null, Writing packet: from=null, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<stream:features><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=403, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-10 23:37:22.420 [pool-10-thread-7]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.422 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">AHRlc3RhAGFzZA==</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-10 23:37:22.423 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:22.423 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">AHRlc3RhAGFzZA==</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-10 23:37:22.423 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-10 23:37:22.424 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=null, packets=1, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-10 23:37:22.430 [in_12-sess-man]   SessionManager.walk()              FINEST:   XMPPProcessorIfc: SaslAuth (urn:ietf:params:xml:ns:xmpp-sasl)Request: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, to=sess-man@dv7, DATA=<auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true">AHRlc3RhAGFzZA==</auth>, SIZE=179, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=null, packets=2, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-10 23:37:22.430 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Packet processed by: [urn:ietf:params:xml:ns:xmpp-sasl]
2014-03-10 23:37:22.444 [urn:ietf:params:xml:ns:xmpp-sasl Queue Worker 0]  AuthRepositoryMDImpl.otherAuth()  WARNING: Couldn't obtain user repository for domain: piruleta, not even default one!
2014-03-10 23:37:22.447 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-10 23:37:22.448 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.448 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:22.448 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-10 23:37:22.449 [in_4-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl">CData size: 65</failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-10 23:37:22.449 [in_4-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, type: accept, Socket: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273 Socket[addr=/192.168.1.132,port=39273,localport=5222], jid: null, Writing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-10 23:37:22.461 [pool-10-thread-8]  ConnectionManager.serviceStopped()  FINER:  [[c2s]] Connection stopped: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, type: accept, Socket: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273 Socket[unconnected], jid: null
2014-03-10 23:37:22.461 [pool-10-thread-8]  ClientConnectionManager.xmppStreamClosed()  FINER: Stream closed: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.462 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="sess-man@dv7" type="set"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:22.463 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:22.463 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-10 23:37:22.464 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="sess-man@dv7" type="set"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:22.464 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="sess-man@dv7" type="set"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:22.465 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_CLOSED command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.465 [session-close Queue Worker 0]  SessionManager$SessionCloseProc.process()  FINEST: Executing connection close for: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="sess-man@dv7" type="set"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-10 23:37:22.465 [session-close Queue Worker 0]  SessionManager.closeConnection()  FINER: Stream closed from: c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.467 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"/>, SIZE=133, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:22.469 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.469 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:22.470 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_39273
2014-03-10 23:37:22.470 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, for map: {basic-conf@dv7=tigase.conf.Configurator@2a9b74df, amp@dv7=tigase.server.amp.AmpComponent@78741b96, vhost-man@dv7=tigase.vhosts.VHostManager@4415f253, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@43eff72d, bosh@dv7=tigase.server.bosh.BoshConnectionManager@1409bbca, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@70c70bfd, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@778ff1dc, sess-man@dv7=tigase.server.xmppsession.SessionManager@4d863446, stats@dv7=tigase.stats.StatisticsCollector@768ed221, monitor@dv7=tigase.server.monitor.MonitorComponent@43b149e1}
2014-03-10 23:37:22.470 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_39273, DATA=<iq from="sess-man@dv7" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" type="result"/>, SIZE=133, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-10 23:37:22.471 [in_4-c2s]         ClientConnectionManager$StoppedHandler.responseReceived()  FINEST: Response for stop received...
2014-03-10 23:37:22.473 [pool-10-thread-8]  ClientConnectionManager.xmppStreamClosed()  FINE: Service stopped, sending packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_39273" id="5788ec7a-01ff-4432-87a0-cde995e3f46f" to="sess-man@dv7" type="set"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set

Thanks for any help.

Avatar?id=6023&size=32x32

Added by Artur Hefczyc TigaseTeam about 5 years ago

You send a user name only from your client: AHRlc3RhAGFzZA== which decodes to: testaasd. It probably contains both user name and password but as you can see there is no domain name.

By the way, what kind of client do you use? In the auth request it advertises: xmlns:ga="http://www.google.com/talk/protocol/auth" ga:client-uses-full-bind-result="true" which might be some Google specific stuff, hence not fully compatible with XMPP protocol and Tigase server.

Added by Diego Barrera about 5 years ago

Thanks for the answer. I'm looking it, could you tell by what means AHRlc3RhAGFzZA== decodes to testaasd? What kind of encryption is it?

Added by Diego Barrera about 5 years ago

Nevermind about the encryption, it's base64 :P.

I changed client to freetalk GNU and this is what the logs show, but basically still google talk stuff and a base64 encoded string which is a concatenation of user+password and no domain name.

My input into freetalk is:

Jabber ID: test@piruleta
Password: (t3st)
Connecting ...
Connected.
Authenticating ...
Could not login.
Disconnected from piruleta: Invalid authentication

And this is the log for that login attempt:

2014-03-11 11:15:35.198 [ConnectionOpenThread]  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-03-11 11:15:35.198 [ConnectionOpenThread]  ConnectionManager.serviceStarted()  FINER: [[c2s]] Connection started: null, type: accept, Socket: TLS: nullSocket[addr=/10.205.238.159,port=37644,localport=5223], jid: null
2014-03-11 11:15:35.499 [pool-10-thread-5]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {id=451143457591, to=piruleta, xmlns:stream=http://etherx.jabber.org/streams, xmlns=jabber:client, version=1.0}
2014-03-11 11:15:35.500 [pool-10-thread-5]  ClientConnectionManager.xmppStreamOpened()  FINER: No Session ID, generating a new one: 30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f
2014-03-11 11:15:35.500 [pool-10-thread-5]  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='piruleta' id='30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f' version='1.0' xml:lang='en'>
2014-03-11 11:15:35.501 [pool-10-thread-5]  ClientConnectionManager.xmppStreamOpened()  FINER: DONE
2014-03-11 11:15:35.503 [pool-10-thread-5]  ClientConnectionManager.xmppStreamOpened()  FINER: Sending a system command to SM: from=null, to=null, DATA=<iq to="sess-man@dv7" id="c2s--c2s22" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="set"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=420, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 11:15:35.504 [pool-10-thread-5]  ClientConnectionManager.xmppStreamOpened()  FINER: DOEN 2
2014-03-11 11:15:35.504 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq to="sess-man@dv7" id="c2s--c2s22" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="set"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=420, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 11:15:35.505 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 11:15:35.505 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 11:15:35.505 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq to="sess-man@dv7" id="c2s--c2s22" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="set"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=420, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 11:15:35.506 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq to="sess-man@dv7" id="c2s--c2s22" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="set"><command xmlns="http://jabber.org/protocol/commands" node="STREAM_OPENED"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>CData size: 36</value></field><field var="hostname"><value>CData size: 8</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=420, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 11:15:35.507 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_OPENED command from: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.507 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINER: Adding resource connection for: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.508 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Setting hostname piruleta for connection: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, VHostItem: Domain: piruleta, enabled: true, anonym: true, register: true, maxusers: 0, tls: false, s2sSecret: null, domainFilter: ALL
2014-03-11 11:15:35.508 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Domain set for connectionId c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.509 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINEST: Setting session-id 30e3daab-1c2b-4b16-95ce-7a48f9ba0b2f for connection: user_jid=null, packets=0, connectioId=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 11:15:35.510 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<iq to="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" id="c2s--c2s22" from="sess-man@dv7" type="result"/>, SIZE=109, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 11:15:35.511 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.511 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, for map: {basic-conf@dv7=tigase.conf.Configurator@4672b784, amp@dv7=tigase.server.amp.AmpComponent@3a3e8692, vhost-man@dv7=tigase.vhosts.VHostManager@156e5f3e, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@4a70b657, bosh@dv7=tigase.server.bosh.BoshConnectionManager@5f064398, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@17aa994e, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@1f29f4e2, sess-man@dv7=tigase.server.xmppsession.SessionManager@11220055, stats@dv7=tigase.stats.StatisticsCollector@4fc5a2f9, monitor@dv7=tigase.server.monitor.MonitorComponent@23ec4d42}
2014-03-11 11:15:35.511 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.512 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, for map: {basic-conf@dv7=tigase.conf.Configurator@4672b784, amp@dv7=tigase.server.amp.AmpComponent@3a3e8692, vhost-man@dv7=tigase.vhosts.VHostManager@156e5f3e, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@4a70b657, bosh@dv7=tigase.server.bosh.BoshConnectionManager@5f064398, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@17aa994e, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@1f29f4e2, sess-man@dv7=tigase.server.xmppsession.SessionManager@11220055, stats@dv7=tigase.stats.StatisticsCollector@4fc5a2f9, monitor@dv7=tigase.server.monitor.MonitorComponent@23ec4d42}
2014-03-11 11:15:35.512 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<iq to="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" id="c2s--c2s22" from="sess-man@dv7" type="result"/>, SIZE=109, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 11:15:35.513 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq to="sess-man@dv7" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="get"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"/></iq>, SIZE=209, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 11:15:35.514 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 11:15:35.514 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 11:15:35.514 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq to="sess-man@dv7" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="get"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"/></iq>, SIZE=209, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 11:15:35.515 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq to="sess-man@dv7" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" type="get"><command xmlns="http://jabber.org/protocol/commands" node="GETFEATURES"/></iq>, SIZE=209, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 11:15:35.515 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.517 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<iq to="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="sess-man@dv7" type="result"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=640, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 11:15:35.518 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.518 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, for map: {basic-conf@dv7=tigase.conf.Configurator@4672b784, amp@dv7=tigase.server.amp.AmpComponent@3a3e8692, vhost-man@dv7=tigase.vhosts.VHostManager@156e5f3e, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@4a70b657, bosh@dv7=tigase.server.bosh.BoshConnectionManager@5f064398, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@17aa994e, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@1f29f4e2, sess-man@dv7=tigase.server.xmppsession.SessionManager@11220055, stats@dv7=tigase.stats.StatisticsCollector@4fc5a2f9, monitor@dv7=tigase.server.monitor.MonitorComponent@23ec4d42}
2014-03-11 11:15:35.519 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.519 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, for map: {basic-conf@dv7=tigase.conf.Configurator@4672b784, amp@dv7=tigase.server.amp.AmpComponent@3a3e8692, vhost-man@dv7=tigase.vhosts.VHostManager@156e5f3e, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@4a70b657, bosh@dv7=tigase.server.bosh.BoshConnectionManager@5f064398, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@17aa994e, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@1f29f4e2, sess-man@dv7=tigase.server.xmppsession.SessionManager@11220055, stats@dv7=tigase.stats.StatisticsCollector@4fc5a2f9, monitor@dv7=tigase.server.monitor.MonitorComponent@23ec4d42}
2014-03-11 11:15:35.519 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<iq to="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="sess-man@dv7" type="result"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=640, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 11:15:35.521 [in_5-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<iq to="c2s@dv7/10.205.238.159_5223_10.205.238.159_37644" id="cf1db32a-00ec-43a0-beb9-9518f5017a2d" from="sess-man@dv7" type="result"><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><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=640, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 11:15:35.521 [in_5-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, type: accept, Socket: TLS: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644 Socket[addr=/10.205.238.159,port=37644,localport=5223], jid: null, Writing packet: from=null, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, 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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=454, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 11:15:35.523 [pool-10-thread-8]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.523 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">AHRlc3QAdDNzdA==</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 11:15:35.523 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 11:15:35.524 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">AHRlc3QAdDNzdA==</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 11:15:35.524 [in_5-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 11:15:35.524 [in_5-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">CData size: 16</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=null, packets=0, connectioId=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 11:15:35.524 [in_5-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: SaslAuth (urn:ietf:params:xml:ns:xmpp-sasl)Request: from=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN" xmlns:ga="http://www.google.com/talk/protocol/auth" id="450568522655" ga:client-uses-full-bind-result="true">AHRlc3QAdDNzdA==</auth>, SIZE=197, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=null, packets=1, connectioId=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 11:15:35.524 [in_5-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [urn:ietf:params:xml:ns:xmpp-sasl]
2014-03-11 11:15:35.525 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 11:15:35.525 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/10.205.238.159_5223_10.205.238.159_37644
2014-03-11 11:15:35.525 [in_5-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, for map: {basic-conf@dv7=tigase.conf.Configurator@4672b784, amp@dv7=tigase.server.amp.AmpComponent@3a3e8692, vhost-man@dv7=tigase.vhosts.VHostManager@156e5f3e, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@4a70b657, bosh@dv7=tigase.server.bosh.BoshConnectionManager@5f064398, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@17aa994e, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@1f29f4e2, sess-man@dv7=tigase.server.xmppsession.SessionManager@11220055, stats@dv7=tigase.stats.StatisticsCollector@4fc5a2f9, monitor@dv7=tigase.server.monitor.MonitorComponent@23ec4d42}
2014-03-11 11:15:35.525 [in_5-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 11:15:35.526 [in_5-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl">CData size: 65</failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 11:15:35.526 [in_5-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, type: accept, Socket: TLS: c2s@dv7/10.205.238.159_5223_10.205.238.159_37644 Socket[addr=/10.205.238.159,port=37644,localport=5223], jid: null, Writing packet: from=sess-man@dv7, to=c2s@dv7/10.205.238.159_5223_10.205.238.159_37644, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null

Thanks for any help!

Added by Wojciech Kapcia TigaseTeam about 5 years ago

Could you provide whole freetalk output or better yet, use different xmpp client (Psi+ is a good choice for example)? You've said you used Pidgin and each time you end up with same console log including @xmlns:ga="http://www.google.com/talk/protocol/auth"@?!

Added by Diego Barrera about 5 years ago

Ok I changed to Psi+ and this is what's logged in tigase.log while I try to log in:

2014-03-11 16:39:51.356 [ConnectionOpenThread]  ConnectionManager.serviceStarted()  FINER: [[c2s]] Connection started: null, type: accept, Socket: nullSocket[addr=/192.168.1.132,port=50819,localport=5222], jid: null
2014-03-11 16:39:51.356 [pool-10-thread-2]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {to=piruleta, 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-03-11 16:39:51.356 [pool-10-thread-2]  ClientConnectionManager.xmppStreamOpened()  FINER: No Session ID, generating a new one: 0ff0db1e-23c3-4e62-8db2-7c9849d17864
2014-03-11 16:39:51.356 [pool-10-thread-2]  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='piruleta' id='0ff0db1e-23c3-4e62-8db2-7c9849d17864' version='1.0' xml:lang='en'>
2014-03-11 16:39:51.357 [pool-10-thread-2]  ClientConnectionManager.xmppStreamOpened()  FINER: DONE
2014-03-11 16:39:51.357 [pool-10-thread-2]  ClientConnectionManager.xmppStreamOpened()  FINER: Sending a system command to SM: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="c2s--c2s17"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>0ff0db1e-23c3-4e62-8db2-7c9849d17864</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:51.358 [pool-10-thread-2]  ClientConnectionManager.xmppStreamOpened()  FINER: DOEN 2
2014-03-11 16:39:51.358 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="c2s--c2s17"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>0ff0db1e-23c3-4e62-8db2-7c9849d17864</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:51.358 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:51.358 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:51.358 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="c2s--c2s17"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>0ff0db1e-23c3-4e62-8db2-7c9849d17864</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:51.359 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="c2s--c2s17"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>CData size: 36</value></field><field var="hostname"><value>CData size: 8</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:51.359 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_OPENED command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.359 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINER: Adding resource connection for: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.359 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Setting hostname piruleta for connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, VHostItem: Domain: piruleta, enabled: true, anonym: true, register: true, maxusers: 0, tls: false, s2sSecret: null, domainFilter: ALL
2014-03-11 16:39:51.359 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Domain set for connectionId c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.360 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINEST: Setting session-id 0ff0db1e-23c3-4e62-8db2-7c9849d17864 for connection: user_jid=null, packets=0, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:51.360 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="c2s--c2s17"/>, SIZE=107, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:51.360 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.361 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.361 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.361 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.361 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="c2s--c2s17"/>, SIZE=107, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:51.362 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:51.363 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:51.363 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:51.363 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:51.364 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:51.365 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.365 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:51.366 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.366 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.366 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.366 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.400 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:51.401 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="a26c0f0b-4dc6-4c03-94cc-7d996a6f7c36"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:51.401 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null, Writing packet: from=null, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, 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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=454, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:51.406 [pool-10-thread-9]  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@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.408 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, 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-03-11 16:39:51.408 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:51.409 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, 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-03-11 16:39:51.409 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, 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-03-11 16:39:51.409 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, 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@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:51.409 [in_9-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: StartTLS (starttls)Request: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, 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@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:51.409 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [starttls]
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig1"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:51.410 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig1"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:51.411 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig1"><command node="STARTTLS" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/></command></iq>, SIZE=271, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:51.411 [in_1-c2s]         ClientConnectionManager.processCommand()  FINER: Starting TLS for connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null
2014-03-11 16:39:51.416 [in_1-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]

At this point I get asked the following:

"The piruleta certificate failed the authenticity test. Certificate is self-signed". To which I choose "Connect Anyway" and then this happens:

2014-03-11 16:39:54.194 [pool-10-thread-8]  ClientConnectionManager.xmppStreamOpened()  FINER: Session ID is: 0ff0db1e-23c3-4e62-8db2-7c9849d17864
2014-03-11 16:39:54.201 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.202 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.202 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.202 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.202 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.203 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.204 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.204 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.204 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.204 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.205 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.205 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.209 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="dfc85b64-ae22-4b80-9e29-418262ab2089"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>CData size: 5</mechanism><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>CData size: 4</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=587, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.209 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null, Writing packet: from=null, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<stream:features><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=403, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.213 [pool-10-thread-8]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>CData size: 4</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.217 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>zlib</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.217 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.217 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>zlib</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.217 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>CData size: 4</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.217 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>CData size: 4</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=null, packets=1, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:54.218 [in_9-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: StartZLib (zlib)Request: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<compress xmlns="http://jabber.org/protocol/compress">
<method>zlib</method>
</compress>, SIZE=88, XMLNS=http://jabber.org/protocol/compress, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=null, packets=2, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:54.218 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [zlib]
2014-03-11 16:39:54.218 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig2"><command node="STARTZLIB" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><compressed xmlns="http://jabber.org/protocol/compress"/></command></iq>, SIZE=279, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:54.219 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.219 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.219 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.219 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.219 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig2"><command node="STARTZLIB" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><compressed xmlns="http://jabber.org/protocol/compress"/></command></iq>, SIZE=279, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:54.219 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=null, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="set" id="tig2"><command node="STARTZLIB" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"/><compressed xmlns="http://jabber.org/protocol/compress"/></command></iq>, SIZE=279, XMLNS=null, PRIORITY=NORMAL, PERMISSION=LOCAL, TYPE=set
2014-03-11 16:39:54.220 [in_1-c2s]         ClientConnectionManager.processCommand()  FINER: Starting zlib compression: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null
2014-03-11 16:39:54.223 [pool-10-thread-6]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {to=piruleta, 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-03-11 16:39:54.223 [pool-10-thread-6]  ClientConnectionManager.xmppStreamOpened()  FINER: Session ID is: 0ff0db1e-23c3-4e62-8db2-7c9849d17864
2014-03-11 16:39:54.224 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.226 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.226 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.226 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.227 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="get" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:54.227 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=495, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.229 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=495, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.233 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="83b24c6f-f2b3-48a8-88ba-8a4e4aefe91e"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>CData size: 5</mechanism><mechanism>CData size: 9</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=495, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.233 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: ZLIB: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null, Writing packet: from=null, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<stream:features><ver xmlns="urn:xmpp:features:rosterver"/><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><auth xmlns="http://jabber.org/features/iq-auth"/></stream:features>, SIZE=311, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.265 [pool-10-thread-7]  ClientConnectionManager.processSocketData()  FINEST: Processing socket data: from=null, to=null, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">CData size: 16</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null from connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.266 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AHRlc3QAdDNzdA==</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.266 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.266 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AHRlc3QAdDNzdA==</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.266 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Received packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">CData size: 16</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null
2014-03-11 16:39:54.266 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   processing packet: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">CData size: 16</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, connection: user_jid=null, packets=2, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:54.267 [in_9-sess-man]    SessionManager.walk()              FINEST:   XMPPProcessorIfc: SaslAuth (urn:ietf:params:xml:ns:xmpp-sasl)Request: from=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, to=sess-man@dv7, DATA=<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AHRlc3QAdDNzdA==</auth>, SIZE=88, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=null, conn: user_jid=null, packets=3, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:54.267 [in_9-sess-man]    SessionManager.processPacket()     FINEST:   Packet processed by: [urn:ietf:params:xml:ns:xmpp-sasl]
2014-03-11 16:39:54.268 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 16:39:54.268 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.268 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.269 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 16:39:54.269 [in_1-c2s]         ClientConnectionManager.processPacket()  FINEST: Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl">CData size: 65</failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 16:39:54.269 [in_1-c2s]         ConnectionManager.writePacketToSocket()  FINEST: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: ZLIB: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[addr=/192.168.1.132,port=50819,localport=5222], jid: null, Writing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<failure xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><not-authorized/><text xml:lang='en'>Password not verified</text></failure>, SIZE=125, XMLNS=urn:ietf:params:xml:ns:xmpp-sasl, PRIORITY=SYSTEM, PERMISSION=LOCAL, TYPE=null
2014-03-11 16:39:54.280 [socketReadThread-2]  ConnectionManager.serviceStopped()  FINER: [[c2s]] Connection stopped: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, type: accept, Socket: ZLIB: TLS: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819 Socket[unconnected], jid: null
2014-03-11 16:39:54.281 [socketReadThread-2]  ClientConnectionManager.xmppStreamClosed()  FINER: Stream closed: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.281 [socketReadThread-2]  ClientConnectionManager.xmppStreamClosed()  FINE: Service stopped, sending packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:54.281 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:54.281 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.281 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:54.282 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:54.282 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:54.282 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_CLOSED command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.282 [session-close Queue Worker 0]  SessionManager$SessionCloseProc.process()  FINEST: Executing connection close for: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" to="sess-man@dv7" type="set" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"><command node="STREAM_CLOSED" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=209, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:54.282 [session-close Queue Worker 0]  SessionManager.closeConnection()  FINER: Stream closed from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.283 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"/>, SIZE=133, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.283 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.284 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.284 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50819
2014-03-11 16:39:54.284 [in_1-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:54.284 [in_1-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50819, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50819" type="result" id="4ea6078a-711a-4354-85cc-c4ef7ef62ae6"/>, SIZE=133, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:54.284 [in_1-c2s]         ClientConnectionManager$StoppedHandler.responseReceived()  FINEST: Response for stop received...

At which point I get asked the password and then this happens:

2014-03-11 16:39:58.687 [ConnectionOpenThread]  ConnectionManager.serviceStarted()  FINER: [[c2s]] Connection started: null, type: accept, Socket: nullSocket[addr=/192.168.1.132,port=50820,localport=5222], jid: null
2014-03-11 16:39:58.688 [pool-10-thread-9]  ClientConnectionManager.xmppStreamOpened()  FINER: Stream opened: {to=piruleta, 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-03-11 16:39:58.688 [pool-10-thread-9]  ClientConnectionManager.xmppStreamOpened()  FINER: No Session ID, generating a new one: 413e6f38-7e02-403e-92d2-b950ad82b569
2014-03-11 16:39:58.688 [pool-10-thread-9]  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='piruleta' id='413e6f38-7e02-403e-92d2-b950ad82b569' version='1.0' xml:lang='en'>
2014-03-11 16:39:58.688 [pool-10-thread-9]  ClientConnectionManager.xmppStreamOpened()  FINER: DONE
2014-03-11 16:39:58.689 [pool-10-thread-9]  ClientConnectionManager.xmppStreamOpened()  FINER: Sending a system command to SM: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="set" id="c2s--c2s18"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>413e6f38-7e02-403e-92d2-b950ad82b569</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:58.689 [pool-10-thread-9]  ClientConnectionManager.xmppStreamOpened()  FINER: DOEN 2
2014-03-11 16:39:58.689 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="set" id="c2s--c2s18"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>413e6f38-7e02-403e-92d2-b950ad82b569</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:58.690 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:58.690 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:58.690 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="set" id="c2s--c2s18"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>413e6f38-7e02-403e-92d2-b950ad82b569</value></field><field var="hostname"><value>piruleta</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:58.690 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="set" id="c2s--c2s18"><command node="STREAM_OPENED" xmlns="http://jabber.org/protocol/commands"><x xmlns="jabber:x:data" type="submit"><field var="session-id"><value>CData size: 36</value></field><field var="hostname"><value>CData size: 8</value></field><field var="xml:lang"><value>en</value></field></x></command></iq>, SIZE=418, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=set
2014-03-11 16:39:58.690 [in_12-sess-man]   SessionManager.processCommand()    FINER:    STREAM_OPENED command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.691 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINER: Adding resource connection for: c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.691 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Setting hostname piruleta for connection: c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, VHostItem: Domain: piruleta, enabled: true, anonym: true, register: true, maxusers: 0, tls: false, s2sSecret: null, domainFilter: ALL
2014-03-11 16:39:58.692 [session-open Queue Worker 0]  SessionManager.createUserSession()  FINEST: Domain set for connectionId c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.692 [session-open Queue Worker 0]  SessionManager$SessionOpenProc.process()  FINEST: Setting session-id 413e6f38-7e02-403e-92d2-b950ad82b569 for connection: user_jid=null, packets=0, connectioId=c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, domain=piruleta, authState=NOT_AUTHORIZED, isAnon=false, isTmp=false
2014-03-11 16:39:58.692 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" type="result" id="c2s--c2s18"/>, SIZE=107, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:58.692 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.693 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:58.693 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.693 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7=tigase.server.xmppserver.S2SConnectionManager@5b895cb9, ws2s@dv7=tigase.server.websocket.WebSocketClientConnectionManager@545c1a99, sess-man@dv7=tigase.server.xmppsession.SessionManager@2de48d50, stats@dv7=tigase.stats.StatisticsCollector@5bbd46e4, monitor@dv7=tigase.server.monitor.MonitorComponent@4f744996}
2014-03-11 16:39:58.693 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: c2s@dv7, from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" type="result" id="c2s--c2s18"/>, SIZE=107, XMLNS=null, PRIORITY=SYSTEM, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:58.693 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="get" id="8e4d72dc-0c68-4cbe-b8f5-0361d19cbbd5"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:58.694 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:58.694 [in_4-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : sess-man@dv7
2014-03-11 16:39:58.694 [in_4-message-router]  MessageRouter.processPacket()  FINEST:   1. Packet will be processed by: sess-man@dv7, from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="get" id="8e4d72dc-0c68-4cbe-b8f5-0361d19cbbd5"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:58.694 [in_12-sess-man]   SessionManager.processPacket()     FINEST:   Received packet: from=null, to=null, DATA=<iq from="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" to="sess-man@dv7" type="get" id="8e4d72dc-0c68-4cbe-b8f5-0361d19cbbd5"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"/></iq>, SIZE=207, XMLNS=null, PRIORITY=HIGH, PERMISSION=NONE, TYPE=get
2014-03-11 16:39:58.694 [in_12-sess-man]   SessionManager.processCommand()    FINER:    GETFEATURES command from: c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.695 [in_7-message-router]  MessageRouter.processPacket()  FINEST:   Processing packet: from=sess-man@dv7, to=c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, DATA=<iq from="sess-man@dv7" to="c2s@dv7/192.168.1.132_5222_192.168.1.132_50820" type="result" id="8e4d72dc-0c68-4cbe-b8f5-0361d19cbbd5"><command node="GETFEATURES" xmlns="http://jabber.org/protocol/commands"><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><mechanism>ANONYMOUS</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/></command></iq>, SIZE=638, XMLNS=null, PRIORITY=NORMAL, PERMISSION=NONE, TYPE=result
2014-03-11 16:39:58.695 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: Called for : c2s@dv7/192.168.1.132_5222_192.168.1.132_50820
2014-03-11 16:39:58.695 [in_7-message-router]  MessageRouter.getLocalComponent()  FINEST: None compId matches (fast lookup): c2s@dv7/192.168.1.132_5222_192.168.1.132_50820, for map: {basic-conf@dv7=tigase.conf.Configurator@1d3cdb70, amp@dv7=tigase.server.amp.AmpComponent@1fd9e040, vhost-man@dv7=tigase.vhosts.VHostManager@66aa50f, c2s@dv7=tigase.server.xmppclient.ClientConnectionManager@54231c3, bosh@dv7=tigase.server.bosh.BoshConnectionManager@43748ba8, s2s@dv7

Added by Diego Barrera about 5 years ago

I decided to log from XMPPIOService as well and this popped up:

2014-03-11 17:13:58.970 [urn:ietf:params:xml:ns:xmpp-sasl Queue Worker 0] AuthRepositoryMDImpl.otherAuth() WARNING: Couldn't obtain user repository for domain: piruleta, not even default one!

What does this mean?

Avatar?id=6023&size=32x32

Added by Artur Hefczyc TigaseTeam about 5 years ago

This means Tigase misconfiguration or your database malfunction.

My suggestion is to stop Tigase, remove all log files, start Tigase and without even connecting with any client, look in the log files: logs/tigase-console.log. There should be some error messages about unsuccessful attempt to connect to DB.

    (1-9/9)