search

eusoulevi / emite

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

Invalid SID (404) stops emiteui and reconect fails #6

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
Debug follows:

[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns='http://jabber.org/protocol/httpbind'><message
to="admin@emitetest.ourproject.org/emiteui-1208863321484" type="chat"
id="iChat_4AAA588A" from="danigb@gmail.com/emite6B1819EA"> [DEBUG]
<body>tenemos un issue ;)</body> [DEBUG] <x xmlns="jabber:x:event"> [DEBUG]
<composing/> [DEBUG] </x> [DEBUG] <active
xmlns="http://jabber.org/protocol/chatstates"/><nos:x
xmlns:nos="google:nosave" value="disabled"></nos:x><arc:record
xmlns:arc="http://jabber.org/protocol/archive"
otr="false"></arc:record></message></body>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@a6176BEB8C62D9AEF6D...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@a7176BEB8C62D9AEF6D...
(line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] DELAY: 0176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body
xmlns="http://jabber.org/protocol/httpbind" rid="725522" sid="9ccf22ec"
/>176BEB8C62D9AEF6D... (line 24)
POST http://emite.ourproject.org/proxy404 (1968ms)176BEB8C62D9AEF6D...
(line 1584)
[DEBUG] GWT CONNECTOR RECEIVED: <html> [DEBUG] <head> [DEBUG] <meta
http-equiv="Content-Type" content="text/html; charset=ISO-8859-1"/> [DEBUG]
<title>Error 404 </title> [DEBUG] </head> [DEBUG] <body><h2>HTTP ERROR:
404</h2><pre>Invalid SID.</pre> [DEBUG]
<p>RequestURI=/http-bind/</p><p><i><small><a
href="http://jetty.mortbay.org/">Powered by
Jetty://</a></small></i></p><br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/>
[DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/>
[DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/>
[DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/>
[DEBUG] <br/> [DEBUG] [DEBUG] </body> [DEBUG] </html> [DEBUG]
176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching: <event xmlns="emite:event" type="connection:on:error"
cause="response-status" info="404" />176BEB8C62D9AEF6D... (line 24)
[INFO] STATE CHANGED: error - old: connected176BEB8C62D9AEF6D... (line 24)
[INFO] STATE CHANGED: disconnected - old: error176BEB8C62D9AEF6D... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHING176BEB8C62D9AEF6D... (line 24)
[INFO] STATE CHANGED: connecting - old: disconnected176BEB8C62D9AEF6D...
(line 24)
[DEBUG] dispatching: <event xmlns="emite:event" type="session:do:login"
uri="admin@emitetest.ourproject.org/emiteui-1208867515841"
password="easyeasy" />176BEB8C62D9AEF6D... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHING176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching: <event xmlns="emite:event" type="connection:do:start"
domain="emitetest.ourproject.org" />176BEB8C62D9AEF6D... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] DELAY: 0176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body
xmlns="http://jabber.org/protocol/httpbind" rid="371528" content="text/xml;
charset=utf-8" to="emitetest.ourproject.org" secure="true" ver="1.6"
wait="60" ack="1" hold="1" xml:lang="en" />176BEB8C62D9AEF6D... (line 24)
POST http://emite.ourproject.org/proxy (2085ms)176BEB8C62D9AEF6D... (line 1584)
[DEBUG] dispatching: <event xmlns="emite:event"
type="connection:do:send"><presence
xmlns="jabber:client"><show>available</show></presence></event>176BEB8C62D9AEF6D
...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>176BEB8C62D9AEF6D... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] DELAY: 0176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body
xmlns="http://jabber.org/protocol/httpbind" rid="371529"><presence
xmlns="jabber:client"><show>available</show></presence></body>176BEB8C62D9AEF6D.
..
(line 24)
POST http://emite.ourproject.org/proxy (2208ms)176BEB8C62D9AEF6D... (line 1584)
[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns="http://jabber.org/protocol/httpbind"
xmlns:stream="http://etherx.jabber.org/streams" authid="944d2d58"
sid="944d2d58" secure="true" requests="2" inactivity="30" polling="5"
wait="60" ver="1.6"><stream:features><mechanisms
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mecha
nism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism><mechanism>CRAM-MD5</mecha
nism></mechanisms><compression
xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><
bind
xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session
xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features></body>176BEB8C62
D9AEF6D...
(line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@a8176BEB8C62D9AEF6D...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@a9176BEB8C62D9AEF6D...
(line 24)
[DEBUG] dispatching: <event xmlns="emite:event"
type="session:do:authization" />176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching: <event xmlns="emite:event"
type="connection:do:send"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">YWRtaW5AZW1pdGV0ZXN0Lm91cnByb2plY3Qub3JnAGFkbWluAGVhc3llYXN5</
auth></event>176BEB8C62D9AEF6D...
(line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] DELAY: 0176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body
xmlns="http://jabber.org/protocol/httpbind" rid="371530"
sid="944d2d58"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">YWRtaW5AZW1pdGV0ZXN0Lm91cnByb2plY3Qub3JnAGFkbWluAGVhc3llYXN5</
auth></body>176BEB8C62D9AEF6D...
(line 24)
POST http://emite.ourproject.org/proxy (5937ms)176BEB8C62D9AEF6D... (line 1584)
[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns="http://jabber.org/protocol/httpbind"
xmlns:stream="http://etherx.jabber.org/streams" authid="19f88264"
sid="19f88264" secure="true" requests="2" inactivity="30" polling="5"
wait="60"><stream:features><mechanisms
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mecha
nism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism><mechanism>CRAM-MD5</mecha
nism></mechanisms><compression
xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><
bind
xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session
xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features></body>176BEB8C62
D9AEF6D...
(line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@aa176BEB8C62D9AEF6D...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@ab176BEB8C62D9AEF6D...
(line 24)
[DEBUG] dispatching: <event xmlns="emite:event"
type="session:do:authization" />176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching: <event xmlns="emite:event"
type="connection:do:send"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">YWRtaW5AZW1pdGV0ZXN0Lm91cnByb2plY3Qub3JnAGFkbWluAGVhc3llYXN5</
auth></event>176BEB8C62D9AEF6D...
(line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] DELAY: 0176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body
xmlns="http://jabber.org/protocol/httpbind" rid="371531"
sid="944d2d58"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">YWRtaW5AZW1pdGV0ZXN0Lm91cnByb2plY3Qub3JnAGFkbWluAGVhc3llYXN5</
auth></body>176BEB8C62D9AEF6D...
(line 24)
POST http://emite.ourproject.org/proxy (5578ms)176BEB8C62D9AEF6D... (line 1584)
[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns="http://jabber.org/protocol/httpbind" type="terminal"
condition="item-not-found"></body>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@ac176BEB8C62D9AEF6D...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>176BEB8C62D9AEF6D... (line 24)
[DEBUG] dispatching: <event xmlns="emite:event" type="connection:on:error"
cause="terminal" info="item-not-found" />176BEB8C62D9AEF6D... (line 24)
[INFO] STATE CHANGED: error - old: connecting176BEB8C62D9AEF6D... (line 24)
[INFO] STATE CHANGED: disconnected - old: error176BEB8C62D9AEF6D... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS176BEB8C62D9AEF6D... (line 24)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHING176BEB8C62D9AEF6D... (line 24)
[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns="http://jabber.org/protocol/httpbind"></body>

Original issue reported on code.google.com by vruiz.ju...@gmail.com on 22 Apr 2008 at 1:20

GoogleCodeExporter commented 9 years ago

Original comment by danigb on 22 Apr 2008 at 3:42

GoogleCodeExporter commented 9 years ago 

A client (in the same browser) try to connect
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="32523" sid="bb7178e7"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">dGVzdDFAZW1pdGVkZW1vLm91cnByb2plY3Qub3JnAHRlc3QxAHRlc3Qx</auth
></body>

The other client throw a Invalid sid:
D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="629781" sid="70f8185d" />

And in the server:
2008.04.29 00:01:11 Client provided invalid session: 70f8185d. [82.144.4.28]
2008.04.29 00:01:13 Request 32524 > 32523, ending session.
~                                                                    

2008.04.29 00:01:13
[org.jivesoftware.openfire.net.VirtualConnection.close(VirtualConnection.java:16
0)]
Could not close socket
org.jivesoftware.openfire.http.HttpSession$HttpVirtualConnection@16a16ae
java.lang.NullPointerException
        at
org.jivesoftware.openfire.http.HttpSession$Deliverable.getPackets(HttpSession.ja
va:809)
        at org.jivesoftware.openfire.http.HttpSession.failDelivery(HttpSession.java:682)
        at
org.jivesoftware.openfire.http.HttpSession.closeConnection(HttpSession.java:671)
        at org.jivesoftware.openfire.http.HttpSession.access$200(HttpSession.java:52)
        at
org.jivesoftware.openfire.http.HttpSession$HttpVirtualConnection.closeVirtualCon
nection(HttpSession.java:740)
        at
org.jivesoftware.openfire.net.VirtualConnection.close(VirtualConnection.java:156
)
        at org.jivesoftware.openfire.http.HttpSession.close(HttpSession.java:161)
        at
org.jivesoftware.openfire.http.HttpBindServlet.sendError(HttpBindServlet.java:18
8)
        at
org.jivesoftware.openfire.http.HttpBindServlet.handleSessionRequest(HttpBindServ
let.java:225)
        at
org.jivesoftware.openfire.http.HttpBindServlet.parseDocument(HttpBindServlet.jav
a:150)
        at
org.jivesoftware.openfire.http.HttpBindServlet.doPost(HttpBindServlet.java:120)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:362)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:726)
        at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollecti
on.java:206)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
        at org.mortbay.jetty.Server.handle(Server.java:324)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:505)
        at
org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:842)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:648)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:205)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:380)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:395)
        at
org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:450)

Original comment by vruiz.ju...@gmail.com on 28 Apr 2008 at 10:08

GoogleCodeExporter commented 9 years ago 
Second client trying to connect (item-not-found) the servert throw the logs of
previous message

[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:do:start"
domain="emitedemo.ourproject.org" />D47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending: Poll overhead: -39, connections: 0D47C63EDEF975513F... (line 
24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="32521" content="text/xml; charset=utf-8" to="emitedemo.ourproject.org"
secure="true" ver="1.6" wait="60" ack="1" hold="1" xml:lang="en"
/>D47C63EDEF975513F... (line 24)
POST http://emite.ourproject.org/proxy (12272ms)D47C63EDEF975513F... (line 1816)
[DEBUG] Dispatching: <event xmlns="emite:event" 
type="connection:do:send"><presence
xmlns="jabber:client"><show>available</show></presence></event>D47C63EDEF975513F
...
(line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending not empty. Conn: 1D47C63EDEF975513F... (line 24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="32522"><presence
xmlns="jabber:client"><show>available</show></presence></body>D47C63EDEF975513F.
..
(line 24)
POST http://emite.ourproject.org/proxy (13005ms)D47C63EDEF975513F... (line 1816)
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns="http://jabber.org/protocol/httpbind"
xmlns:stream="http://etherx.jabber.org/streams" authid="bb7178e7" sid="bb7178e7"
secure="true" requests="2" inactivity="30" polling="5" wait="60"
ver="1.6"><stream:features><mechanisms
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mecha
nism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism><mechanism>CRAM-MD5</mecha
nism></mechanisms><compression
xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><
bind
xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session
xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features></body>D47C63EDEF
975513F...
(line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@49D47C63EDEF975513F... (line 
24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@4aD47C63EDEF975513F... (line 
24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="session:do:authorization"
/>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:do:send"><auth
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">dGVzdDFAZW1pdGVkZW1vLm91cnByb2plY3Qub3JnAHRlc3QxAHRlc3Qx</auth
></event>D47C63EDEF975513F...
(line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending not empty. Conn: 1D47C63EDEF975513F... (line 24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="32523" sid="bb7178e7"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">dGVzdDFAZW1pdGVkZW1vLm91cnByb2plY3Qub3JnAHRlc3QxAHRlc3Qx</auth
></body>D47C63EDEF975513F...
(line 24)
POST http://emite.ourproject.org/proxy (61371ms)D47C63EDEF975513F... (line 1816)
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns="http://jabber.org/protocol/httpbind"
xmlns:stream="http://etherx.jabber.org/streams" authid="29ab46d4" sid="29ab46d4"
secure="true" requests="2" inactivity="30" polling="5"
wait="60"><stream:features><mechanisms
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>DIGEST-MD5</mechanism><mecha
nism>PLAIN</mechanism><mechanism>ANONYMOUS</mechanism><mechanism>CRAM-MD5</mecha
nism></mechanisms><compression
xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><
bind
xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session
xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features></body>D47C63EDEF
975513F...
(line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@4bD47C63EDEF975513F... (line 
24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@4cD47C63EDEF975513F... (line 
24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="session:do:authorization"
/>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:do:send"><auth
xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">dGVzdDFAZW1pdGVkZW1vLm91cnByb2plY3Qub3JnAHRlc3QxAHRlc3Qx</auth
></event>D47C63EDEF975513F...
(line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending not empty. Conn: 1D47C63EDEF975513F... (line 24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="32524" sid="bb7178e7"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl"
mechanism="PLAIN">dGVzdDFAZW1pdGVkZW1vLm91cnByb2plY3Qub3JnAHRlc3QxAHRlc3Qx</auth
></body>D47C63EDEF975513F...
(line 24)
POST http://emite.ourproject.org/proxy (13341ms)D47C63EDEF975513F... (line 1816)
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns="http://jabber.org/protocol/httpbind"
type="terminal" condition="item-not-found"></body>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@4dD47C63EDEF975513F... (line 
24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:on:error"
cause="terminal" info="item-not-found" />D47C63EDEF975513F... (line 24)
[INFO] STATE CHANGED: error - old: connectingD47C63EDEF975513F... (line 24)
[INFO] STATE CHANGED: disconnected - old: errorD47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHINGD47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns="http://jabber.org/protocol/httpbind"
type="terminal" condition="item-not-found"></body>

Original comment by vruiz.ju...@gmail.com on 28 Apr 2008 at 10:18

GoogleCodeExporter commented 9 years ago 
1st. client withou activity after a lot of test, stops with a invalid sid when 
the
other client try to login:

vestibulum viverra. Vivamus id augue. Cum sociis natoque penatibus et magnis dis
parturient montes, nascetur ridiculus mus. Morbi sit amet turpis eu pede 
adipiscing
aliquet. Donec lacinia est. Morbi eleifend neque quis risus. Etiam 
pellentesque. Sed
massa ipsum, dictum non, ornare sodales, pretium sit amet, tellus. Fusce mattis
mauris. Donec nec nisl. Morbi ut turpis non pede sagittis laoreet. Morbi egestas
massa sit amet sem. Duis vehicula purus ornare justo blandit vehicula. Sed mi. 
Proin
quam arcu, interdum at, feugiat vel, bibendum in, mauris. In hac habitasse 
platea
dictumst.<br/></span></body></html></message></body>D47C63EDEF975513F... (line 
24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b1D47C63EDEF975513F... (line 
24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b2D47C63EDEF975513F... (line 
24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] DELAY: 2900D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:do:pull"
/>D47C63EDEF975513F... (line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending: Poll overhead: -519, connections: 0D47C63EDEF975513F... (line 
24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="629780" sid="70f8185d" />D47C63EDEF975513F... (line 24)
POST http://emite.ourproject.org/proxy (5275ms)D47C63EDEF975513F... (line 1816)
[DEBUG] GWT CONNECTOR RECEIVED: <body
xmlns='http://jabber.org/protocol/httpbind'><message type="chat" 
id="purple6217944a"
to="test100@emitedemo.ourproject.org/emiteui-1209419337174"
from="admin@emitedemo.ourproject.org/sanuk"><x
xmlns="jabber:x:event"><composing/></x><body>1</body><html
xmlns="http://jabber.org/protocol/xhtml-im"><body
xmlns="http://www.w3.org/1999/xhtml"><span style="font-weight:
bold;">1</span></body></html></message><message type="chat" id="purple6217944b"
to="test100@emitedemo.ourproject.org/emiteui-1209419337174"
from="admin@emitedemo.ourproject.org/sanuk"><x
xmlns="jabber:x:event"><composing/></x><body>2</body><html
xmlns="http://jabber.org/protocol/xhtml-im"><body
xmlns="http://www.w3.org/1999/xhtml"><span style="font-weight:
bold;">2</span></body></html></message><message type="chat" id="purple6217944c"
to="test100@emitedemo.ourproject.org/emiteui-1209419337174"
from="admin@emitedemo.ourproject.org/sanuk"><x
xmlns="jabber:x:event"><composing/></x><body>3</body><html
xmlns="http://jabber.org/protocol/xhtml-im"><body
xmlns="http://www.w3.org/1999/xhtml"><span style="font-weight:
bold;">3</span></body></html></message></body>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b3D47C63EDEF975513F... (line 
24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b4D47C63EDEF975513F... (line 
24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b5D47C63EDEF975513F... (line 
24)
[DEBUG] Dispatching:
com.calclab.emite.client.core.packet.gwt.GWTPacket@b6D47C63EDEF975513F... (line 
24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] DELAY: 1262D47C63EDEF975513F... (line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:do:pull"
/>D47C63EDEF975513F... (line 24)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>D47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] Sending: Poll overhead: -95, connections: 0D47C63EDEF975513F... (line 
24)
[DEBUG] DELAY: 0D47C63EDEF975513F... (line 24)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind"
rid="629781" sid="70f8185d" />D47C63EDEF975513F... (line 24)
POST http://emite.ourproject.org/proxy404 (48325ms)D47C63EDEF975513F... (line 
1816)
[DEBUG] GWT CONNECTOR RECEIVED: <html> [DEBUG] <head> [DEBUG] <meta
http-equiv="Content-Type" content="text/html; charset=ISO-8859-1"/> [DEBUG]
<title>Error 404 Invalid SID.</title> [DEBUG] </head> [DEBUG] <body><h2>HTTP 
ERROR:
404</h2><pre>Invalid SID.</pre> [DEBUG] 
<p>RequestURI=/http-bind/</p><p><i><small><a
href="http://jetty.mortbay.org/">Powered by Jetty://</a></small></i></p><br/> 
[DEBUG]
<br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> 
[DEBUG]
<br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> 
[DEBUG]
<br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> [DEBUG] <br/> 
[DEBUG]
<br/> [DEBUG] [DEBUG] </body> [DEBUG] </html> [DEBUG] D47C63EDEF975513F... 
(line 24)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:on:error"
cause="response-status" info="404" />D47C63EDEF975513F... (line 24)
[INFO] STATE CHANGED: error - old: connectedD47C63EDEF975513F... (line 24)
[INFO] STATE CHANGED: disconnected - old: errorD47C63EDEF975513F... (line 24)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSD47C63EDEF975513F... (line 24)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHING

Original comment by vruiz.ju...@gmail.com on 28 Apr 2008 at 10:21

GoogleCodeExporter commented 9 years ago 
Seems a 3.5.1 issue http://www.igniterealtime.org/community/message/169420

Original comment by vruiz.ju...@gmail.com on 28 Apr 2008 at 10:29

GoogleCodeExporter commented 9 years ago 
Interesting:
http://www.igniterealtime.org/builds/openfire/docs/latest/documentation/javadoc/
org/jivesoftware/openfire/http/BoshBindingError.html

Original comment by vruiz.ju...@gmail.com on 30 Apr 2008 at 1:51

GoogleCodeExporter commented 9 years ago 
More server logs:

2008.05.25 14:46:00 Client provided invalid session: 6daba21d. [127.0.0.1]
2008.05.25 15:50:57 Client provided invalid session: e25f513b. [127.0.0.1]
2008.05.25 15:55:55 Request 241173 > 241172, ending session.
2008.05.25 16:06:44 Client provided invalid session: 64b98525. [127.0.0.1]
2008.05.25 16:39:52 Request 90745 > 90744, ending session.
2008.05.25 16:51:28 Client provided invalid session: e729d612. [127.0.0.1]
2008.05.25 16:52:24 Request 150811 > 150810, ending session.

The main problem is than you cannot reconnect after this error and you have to 
reload
the page (very awkward if you use emiteui with other applications).

Original comment by vruiz.ju...@gmail.com on 25 May 2008 at 4:37

GoogleCodeExporter commented 9 years ago 
I am running into a very similar problem running with ejabberd 2.0.1 running as 
the 
server

Once this occurs I can't log back in until I do a refresh of the page

The debug is below:

[DEBUG] Signal ONSTATECHANGED: connectingF1C0B283E2195183E... (line 159)
[DEBUG] CREATE ALL in context class 
com.calclab.emite.client.xmpp.session.SessionF1C0B283E2195183E... (line 159)
[DEBUG] Signal ONLOGIN: 
com.calclab.emite.client.xmpp.sasl.AuthorizationTicket@2cF1C0B283E2195183E... 
(line 
159)
[DEBUG] Dispatching: <event xmlns="emite:event" type="bosh-manager:do:start" 
domain="vypedev1.com" />F1C0B283E2195183E... (line 159)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>F1C0B283E2195183E... (line 159)
[DEBUG] START IN BOSH MANAGER!!!F1C0B283E2195183E... (line 159)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSF1C0B283E2195183E... (line 159)
[DEBUG] STATE - SEND: Empty request, not connections (0) and delay ok: 11 with 
poll: 
1F1C0B283E2195183E... (line 159)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind" 
rid="784993" content="text/xml; charset=utf-8" to="vypedev1.com" secure="true" 
wait="60" ack="1" hold="1" xml:lang="en" xmpp:version="1.0" 
xmlns:xmpp="urn:xmpp:xbosh" />F1C0B283E2195183E... (line 159)
POST http://vypedev1.com:4444/com.calclab.emiteui.EmiteUI/proxy 
(1236ms)F1C0B283E2195183E... (line 16707)
ParamsHeadersPostResponse
Response Headers
viaJTTP JTTP
Content-Length  597
Content-Type    text/xml; charset=utf-8
Connection  close
Server  Jetty(6.1.5)
Request Headers
Host    vypedev1.com:4444
User-Agent  Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.14) Gecko/20080404 
Firefox/2.0.0.14
Accept  text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/
plain;q=0.8,image/png,*/*;q=0.5
Accept-Language en-us,en;q=0.5
Accept-Encoding gzip,deflate
Accept-Charset  ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive  300
Connection  keep-alive
Content-Type    text/plain; charset=utf-8
Referer http://vypedev1.com:4444/gwt/com.calclab.emiteui.EmiteUI/
F1C0B283E2195183E2438A6F4EA1E6C9.cache.html
Content-Length  219
Pragma  no-cache
Cache-Control   no-cache

<body xmlns="http://jabber.org/protocol/httpbind" rid="784993" 
content="text/xml; 
charset=utf-8" to="vypedev1

.com" secure="true" wait="60" ack="1" hold="1" xml:lang="en" xmpp:version="1.0" 
xmlns:xmpp="urn:xmpp

:xbosh" />

<body xmlns='http://jabber.org/protocol/httpbind' 
sid='bc03cfaca281a86e13dbcff2a2a549ee94bc6696' wait

='60' requests='2' inactivity='30' maxpause='120' polling='2' ver='1.6' 
from='vypedev1.com' secure='true'

 authid='4013027725' xmlns:xmpp='urn:xmpp:xbosh' xmlns:stream='http://
etherx.jabber.org/streams' xmpp

:version='1.0'><stream:features xmlns:stream='http://etherx.jabber.org/
streams'><mechanisms xmlns='urn

:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN
</
mechanism></mechanisms

><register 
xmlns='http://jabber.org/features/iq-register'/></stream:features></body>

[DEBUG] Getting dependency: class 
com.calclab.emite.client.im.presence.PresenceManagerF1C0B283E2195183E... (line 
159)
[DEBUG] Dispatching: <event xmlns="emite:event" 
type="connection:do:send"><presence 
from="apars@vypedev1.com/emiteui-1212530061907-r639-7" /></
event>F1C0B283E2195183E... (line 159)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>F1C0B283E2195183E... (line 159)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSF1C0B283E2195183E... (line 159)
[DEBUG] STATE - SEND: Not empty request and current connections ok 
(1)F1C0B283E2195183E... (line 159)
[DEBUG] GWT CONNECTOR SEND: <body xmlns="http://jabber.org/protocol/httpbind" 
rid="784994"><presence from="apars@vypedev1.com/emiteui-1212530061907-r639-7" 
/></
body>F1C0B283E2195183E... (line 159)
POST http://vypedev1.com:4444/com.calclab.emiteui.EmiteUI/proxy 
(1057ms)F1C0B283E2195183E... (line 16707)
[DEBUG] Signal ONOWNPRESENCECHANGED: <presence from="apars@vypedev1.com/emiteui-
1212530061907-r639-7" />F1C0B283E2195183E... (line 159)
[DEBUG] GWT CONNECTOR RECEIVED: <body type='terminate' condition='improper-
addressing' xmlns='http://jabber.org/protocol/httpbind'/>F1C0B283E2195183E... 
(line 
159)
[DEBUG] Dispatching: <event xmlns="emite:event" type="connection:on:error" 
cause="terminal" info="improper-addressing" />F1C0B283E2195183E... (line 159)
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>F1C0B283E2195183E... (line 159)
[DEBUG] Signal ONSTATECHANGED: errorF1C0B283E2195183E... (line 159)
[DEBUG] Signal ONSTATECHANGED: disconnectedF1C0B283E2195183E... (line 159)
[DEBUG] <<<<<<<<<<<< DISPATCH ENDSF1C0B283E2195183E... (line 159)
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHINGF1C0B283E2195183E... (line 159)
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns='http://jabber.org/protocol/httpbind' 
sid='bc03cfaca281a86e13dbcff2a2a549ee94bc6696' wait='60' requests='2' 
inactivity='30' maxpause='120' polling='2' ver='1.6' from='vypedev1.com' 
secure='true' authid='4013027725' xmlns:xmpp='urn:xmpp:xbosh' 
xmlns:stream='http://
etherx.jabber.org/streams' xmpp:version='1.0'><stream:features 
xmlns:stream='http://
etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-
sasl'><mechanism>DIGEST-MD5</mechanism><mechanism>PLAIN</mechanism></
mechanisms><register xmlns='http://jabber.org/features/iq-register'/></
stream:features></body>

Original comment by amir...@gmail.com on 3 Jun 2008 at 10:14

GoogleCodeExporter commented 9 years ago 
More logs of this situation:
- sending a message (without problems) to a buddy
- wait for some time
- send again another message in the same conversation (getting a 404) ... It 
seems
that the bosh connection is not present after some time without activity. If 
you do
test without debug using firebug, you see that after same time the bosh POST is 
not
open... then you get the Invalid SID/404 if you try to do anything.

(using ejabberd)

[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns='http://jabber.org/protocol/httpbind'/>
[DEBUG] Signal onChatCreated: chat: vjrj@localhost-301543.2227249343
[DEBUG] Adding chat state to chat: chat: vjrj@localhost-301543.2227249343
[DEBUG] Signal onUnHighLight:
com.calclab.emiteuimodule.client.chat.ChatUIPresenter@9161eb
[DEBUG] Signal onActivate: 
com.calclab.emiteuimodule.client.chat.ChatUIPresenter@9161eb
[DEBUG] Signal onStateChanged: ready
[DEBUG] Signal onCurrentUserSend: sdasa
[DEBUG] Dispatching: <event type="connection:do:send" 
xmlns="emite:event"><message
to="vjrj@localhost" type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>sdasa</body><thread>30
1543.2227249343</thread><active
xmlns="http://jabber.org/protocol/chatstates" /></message></event>
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS
[DEBUG] STATE - SEND: Not empty request and current connections ok (1)
[DEBUG] GWT CONNECTOR SEND: <body sid="6ccc15cac89b3a21cb45803c20ad027a7f142932"
xmlns="http://jabber.org/protocol/httpbind" rid="869239"><message 
to="vjrj@localhost"
type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>sdasa</body><thread>30
1543.2227249343</thread><active
xmlns="http://jabber.org/protocol/chatstates" /></message></body>
[DEBUG] Signal onMessageSent: <message to="vjrj@localhost" type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>sdasa</body><thread>30
1543.2227249343</thread><active
xmlns="http://jabber.org/protocol/chatstates" /></message>
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns='http://jabber.org/protocol/httpbind'/>
[DEBUG] GWT CONNECTOR RECEIVED: <body 
xmlns='http://jabber.org/protocol/httpbind'/>
[DEBUG] Signal onCurrentUserSend: llllll
[DEBUG] Dispatching: <event type="connection:do:send" 
xmlns="emite:event"><message
to="vjrj@localhost" type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>llllll</body><thread>3
01543.2227249343</thread></message></event>
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS
[DEBUG] STATE - SEND: Not empty request and current connections ok (0)
[DEBUG] GWT CONNECTOR SEND: <body sid="6ccc15cac89b3a21cb45803c20ad027a7f142932"
xmlns="http://jabber.org/protocol/httpbind" rid="869240"><message 
to="vjrj@localhost"
type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>llllll</body><thread>3
01543.2227249343</thread></message></body>
[DEBUG] Signal onMessageSent: <message to="vjrj@localhost" type="chat"
from="admin@localhost/emiteui-1212581305192-r639-7"><body>llllll</body><thread>3
01543.2227249343</thread></message>
[DEBUG] GWT CONNECTOR RECEIVED: 
[DEBUG] Dispatching: <event info="404" type="connection:on:error" 
xmlns="emite:event"
cause="response-status" />
[DEBUG] DISPATCH BEGINS >>>>>>>>>>>
[DEBUG] Signal onStateChanged: error
[DEBUG] Signal onStateChanged: disconnected
[DEBUG] <<<<<<<<<<<< DISPATCH ENDS
[DEBUG] BOSH IS STOP. NO NEED TO SEND ANYTHING

Original comment by vruiz.ju...@gmail.com on 4 Jun 2008 at 12:23

GoogleCodeExporter commented 9 years ago 
Also with SwingClient. Steps to reproduce:
- I opened a room.
- I let the client unattended for some minutes.

Traces:

CONN START: 20
CONN OUT: <body xmlns="http://jabber.org/protocol/httpbind" rid="603708"
sid="9e5acd9e"><message type="groupchat"
from="dani@emitedemo.ourproject.org/emite-swing"
to="testroom1@rooms.emitedemo.ourproject.org"><body>aq</body></message></body>
CONN # 20-ERROR: bad status
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: Dispatching: <event info="bad http status 404" 
type="connection:on:error"
xmlns="emite:event" cause="connector-error" />
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: DISPATCH BEGINS >>>>>>>>>>>
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: Signal onStateChanged: error
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 info
INFORMACIàN: STATE: error
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: Signal onStateChanged: disconnected
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 info
INFORMACIàN: STATE: disconnected
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: <<<<<<<<<<<< DISPATCH ENDS
06-jun-2008 6:48:44 com.allen_sauer.gwt.log.server.ServerLogImplJDK14 debug
PRECISO: BOSH IS STOP. NO NEED TO SEND ANYTHING

Original comment by vruiz.ju...@gmail.com on 6 Jun 2008 at 11:32

GoogleCodeExporter commented 9 years ago 
Dani just committed few hours ago a possible fix...

Original comment by vruiz.ju...@gmail.com on 10 Jun 2008 at 11:05

GoogleCodeExporter commented 9 years ago 
Less frecuent, but still happens... after some time of inactivity (sometimes) 
the
BOSH connection is not created again.

Original comment by vruiz.ju...@gmail.com on 11 Jun 2008 at 9:14

GoogleCodeExporter commented 9 years ago

Original comment by danigb on 27 Jun 2008 at 7:37