Not logged in. · Lost password · Register
Forum: MatriX RSS
Avatar
matianyi #1
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
Subject: BOSH:login process is blocked for 1 minute sometimes
Matrix v1.5.0.0

We use bosh for connection. normally the login process ends in few second, but at rarely times it takes more than 1 minute for login process to end.

log on client like this

2013-02-15 16:15:59,241 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138210, 
2013-02-15 16:15:59,368 [1] [INFO ] XmppClientFactory BOSH_RECV:ACK:1187138210,features
2013-02-15 16:15:59,404 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138211, auth
2013-02-15 16:15:59,405 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138212, 
2013-02-15 16:15:59,543 [1] [INFO ] XmppClientFactory BOSH_RECV:ACK:0,success
2013-02-15 16:16:59,572 [1] [INFO ] XmppClientFactory BOSH_RECV:ACK:0,
2013-02-15 16:16:59,601 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138213, 
2013-02-15 16:16:59,697 [1] [INFO ] XmppClientFactory BOSH_RECV:ACK:0,features
2013-02-15 16:16:59,726 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138214, iq
2013-02-15 16:16:59,727 [1] [INFO ] XmppClientFactory BOSH_SEND:RID:1187138215, 
2013-02-15 16:16:59,851 [1] [INFO ] XmppClientFactory BOSH_RECV:ACK:0,iq

when there is no ack in response body, ACK:0 displayed.

log on server like this:
[2013-02-15 16:15:59.310] request: <body xmlns:ns1="urn:xmpp:xbosh" xmlns="http://jabber.org/protocol/httpbind" to="example.com" rid="1187138210" hold="1" secure="true" newkey="cab9725478b741073216c5648e90bb4610c795bd" wait="300" ns1:version="1.0" ver="1.6" polling="0"></body>
[2013-02-15 16:15:59.311] response: <body xmlns="http://jabber.org/protocol/httpbind" wait="60" inactivity="60" polling="15" requests="2" hold="1" sid="33fe22f24ed94a4b81a06a5d61aecb7c" ver="1.6" from="example.com" secure="true" maxpause="120" ack="1187138210"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"></register></stream:features></body>
[2013-02-15 16:15:59.497] request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="33fe22f24ed94a4b81a06a5d61aecb7c" rid="1187138211" key="400919ec1c2080533a955087c9eb4b4e24198733"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AHVzZXIxADAwMDAwMA==</auth></body>
[2013-02-15 16:15:59.500] request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="33fe22f24ed94a4b81a06a5d61aecb7c" rid="1187138212" key="d96c34944195c743b4a5c8b9cf6c17bc91750c49"></body>
[2013-02-15 16:15:59.501] response: <body xmlns="http://jabber.org/protocol/httpbind"><success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"></success></body>
[2013-02-15 16:16:59.536] response: <body xmlns="http://jabber.org/protocol/httpbind"></body>
[2013-02-15 16:16:59.664] request: <body xmlns:ns1="urn:xmpp:xbosh" xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="33fe22f24ed94a4b81a06a5d61aecb7c" rid="1187138213" key="5e9da4e276a2251e34e1aebc69ea6084387c4a98" ns1:restart="true"></body>
[2013-02-15 16:16:59.664] response: <body xmlns="http://jabber.org/protocol/httpbind"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><required></required></bind><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><required></required></session><ver xmlns="urn:xmpp:features:rosterver"></ver></stream:features></body>

we can see that it take about 1 minute for the "restart request(1187138213)" waiting response of the "empty request(1187138212)" to come back. why does matrix wait that empty request?

I found that normally there is no empty request in login process but at rarely times there is.
Avatar
Alex #2
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
Quote by matianyi:
Matrix v1.5.0.0

We use bosh for connection. normally the login process ends in few second, but at rarely times it takes more than 1 minute for login process to end.

this build is very old. Please update to the latest build first. We have made lots of BOSH improvements in newer builds.
If you still have problems then also post the log from the events OnSendBody and OnReceiveBody with timestamps.

Alex
Avatar
matianyi #3
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
hi, Alex

I upgrade matrix to 1.5.2.8 but got the same problem.

the log of client like this:
2013-02-18 18:00:07,613 [1] XmppClientFactory BOSH_SEND:RID:214745296, 
2013-02-18 18:00:07,699 [1] XmppClientFactory BOSH_RECV:ACK:214745296,features
2013-02-18 18:00:07,724 [1] XmppClientFactory BOSH_SEND:RID:214745297, auth
2013-02-18 18:00:07,724 [1] XmppClientFactory BOSH_SEND:RID:214745298, 
[b]2013-02-18 18:00:07,806 [1] XmppClientFactory BOSH_RECV:ACK:0,success[/b]
[b]2013-02-18 18:01:08,705 [1] XmppClientFactory BOSH_RECV:ACK:0, [/b]
[b]2013-02-18 18:01:08,730 [1] XmppClientFactory BOSH_SEND:RID:214745299,[/b] 
2013-02-18 18:01:08,827 [1] XmppClientFactory BOSH_RECV:ACK:0,features
2013-02-18 18:01:08,852 [1] XmppClientFactory BOSH_SEND:RID:214745300, iq
2013-02-18 18:01:08,853 [1] XmppClientFactory BOSH_SEND:RID:214745301, 
2013-02-18 18:01:08,977 [1] XmppClientFactory BOSH_RECV:ACK:0,iq
2013-02-18 18:01:08,980 [1] XmppClientFactory BOSH_RECV:ACK:214745301,
2013-02-18 18:01:09,004 [1] XmppClientFactory BOSH_SEND:RID:214745302, iq
2013-02-18 18:01:09,008 [1] XmppClientFactory BOSH_SEND:RID:214745303, 
2013-02-18 18:01:09,124 [1] XmppClientFactory BOSH_RECV:ACK:0,iq
2013-02-18 18:01:09,141 [1] XmppClientFactory BOSH_RECV:ACK:0,iq

the log of server like this:

[2013-02-18 18:00:07.692] BOSH decoding request: <body xmlns:ns1="urn:xmpp:xbosh" xmlns="http://jabber.org/protocol/httpbind" to="example.com" rid="214745296" hold="1" secure="true" newkey="b98acb812d4f4f2edd7f5cdc95981204db2fc32f" wait="300" ns1:version="1.0" ver="1.6" polling="0"></body>
[2013-02-18 18:00:07.693] session state changed to = ENCRYPTED
[2013-02-18 18:00:07.694] BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind" wait="60" inactivity="60" polling="15" requests="2" hold="1" sid="ef9a1fc08394439183200a450c978f98" ver="1.6" from="example.com" secure="true" maxpause="120" ack="214745296"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"></register></stream:features></body>
[2013-02-18 18:00:07.800]  BOSH decoding request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="ef9a1fc08394439183200a450c978f98" rid="214745297" key="75f213d3ccac02b909a2c5d8e260a497b66c7ac2"><auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">AHVzZXIxADAwMDAwMA==</auth></body>
[2013-02-18 18:00:07.802] BOSH decoding request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="ef9a1fc08394439183200a450c978f98" rid="214745298" key="2b43fc987d3e1d82501bda4cd186901c0b0203b1"></body>
[2013-02-18 18:00:07.804]  session state changed to = AUTHENTICATED

[2013-02-18 18:00:07.804]  BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind"><success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"></success></body>
[2013-02-18 18:01:08.702]  BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind"></body>
[2013-02-18 18:01:08.822] BOSH decoding request: <body xmlns:ns1="urn:xmpp:xbosh" xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="ef9a1fc08394439183200a450c978f98" rid="214745299" key="f0239cff755503f931f1aaa20ed5d477d493af0a" ns1:restart="true"></body>

[2013-02-18 18:01:08.822] BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind"><stream:features xmlns:stream="http://etherx.jabber.org/streams"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><required></required></bind><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><required></required></session><ver xmlns="urn:xmpp:features:rosterver"></ver></stream:features></body>
[2013-02-18 18:01:08.967]  BOSH decoding request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="ef9a1fc08394439183200a450c978f98" rid="214745301" key="51afca3acbdeb786e28cdf5bff3f44ee6667596d"></body>
[2013-02-18 18:01:08.968]  BOSH decoding request: <body xmlns="http://jabber.org/protocol/httpbind" to="example.com" sid="ef9a1fc08394439183200a450c978f98" rid="214745300" key="f67be1180515a1dc24cc8789110133f89a91dd88"><iq xmlns="jabber:client" id="MX_8" type="set"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>lim-pc|2.1.0(8035)|Windows 7  6.1.7601.65536 32Bits|172.16.11.219,192.168.11.4</resource></bind></iq></body>
[2013-02-18 18:01:08.969]  BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind" ack="214745301"></body>
[2013-02-18 18:01:08.972]  BOSH writing response: <body xmlns="http://jabber.org/protocol/httpbind"><iq xmlns="jabber:client" type="result" id="MX_8"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>user1@example.com/4524cea99f6840cfb6cc9d6af5595f1d</jid></bind></iq></body>

and it not always happend around the auth stanza but also somewhere else.
Avatar
Alex #4
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
you have not posted the logs from OnSendBody and OnReceiveBody with timestamp as I requested. The server side log does not help right now. Loggin the OnCreateWebRequest with timestamp would be also useful for me.

Which server software are you using?
Do you have some HTTP proxies between the client and the server?

Is it possible that you hit the 2 concurrent request limit of windows and windows waits until it executes the next webrequest?
See: ServicePointManager.DefaultPersistentConnectionLimit

Alex
Avatar
matianyi #5
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
hi, Alex

This is the logs from OnSendBody and OnReceiveBody and OnCreateWebRequest.
The problem happend at 2013-02-19 19:20:51,612 , OnCreateWebRequest was called but unit 2013-02-19 19:21:48,322 it send the request.
It seems that the http connection is reused so the response of preview XmppClient (which is already closed) is received by the second XmppClient.

2013-02-19 19:20:50,612 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:20:50,635 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="1692658631" key="dfb6df94f590c4bd6cdddf484a8b540b228f6908" sid="6c37dc4854da476581a459b8ba935651" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  <iq id="MX_230" type="get" xmlns="jabber:client">
    <query xmlns="http://xmpp.legendapl.com/protocol/offlinemsg#summary" />
  </iq>
  <iq id="MX_231" from="user0@example.com/abca9c966a084ac28f2e04d1bb1d206a" type="set" xmlns="jabber:client">
    <query xmlns="http://xmpp.legendapl.com/protocol/status">
      <show>NONE</show>
      <status>Online</status>
    </query>
  </iq>
</body>
2013-02-19 19:20:50,726 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind">
  <iq xmlns="jabber:client" to="user0@example.com/abca9c966a084ac28f2e04d1bb1d206a" type="result" id="MX_231">
    <query xmlns="http://xmpp.legendapl.com/protocol/status"></query>
  </iq>
</body>
2013-02-19 19:20:51,112 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:20:51,135 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="1692658632" key="0d51e536a90e152f4c508a39a998321e634c4d25" sid="6c37dc4854da476581a459b8ba935651" to="example.com" xmlns="http://jabber.org/protocol/httpbind" />

logout by user here

2013-02-19 19:20:51,612 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:48,300 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind"></body>
2013-02-19 19:21:48,322 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="1692658633" key="2a5ba7049fe3c5052b29eaedd950afcd118e6474" sid="6c37dc4854da476581a459b8ba935651" to="example.com" type="terminate" xmlns="http://jabber.org/protocol/httpbind">
  <presence type="unavailable" xmlns="jabber:client">
    <status>?????</status>
  </presence>
</body>
2013-02-19 19:21:48,417 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind" ack="1692658633"></body>
2013-02-19 19:21:48,421 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind" type="terminate"></body>
2013-02-19 19:21:48,506 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:48,529 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="1208419071" key="e598044260ce854f6778cc051f3d9492af500cd8" sid="08dde86f9f524dcdabe1413a50f27658" to="example.com" xmlns="http://jabber.org/protocol/httpbind" />
2013-02-19 19:21:48,580 [1] OnCreateWebRequest
2013-02-19 19:21:48,602 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" ver="1.6" xmpp:version="1.0" hold="1" wait="300" rid="752422455" polling="0" to="example.com" secure="true" newkey="29215f3d4756483eecc36b1999de68ffee1180c0" xmlns="http://jabber.org/protocol/httpbind" />
2013-02-19 19:21:48,693 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind" wait="60" inactivity="60" polling="15" requests="2" hold="1" sid="9c727a3b58574fd7985854afc87de446" ver="1.6" from="example.com" secure="true" maxpause="120" ack="752422455">
  <stream:features xmlns:stream="http://etherx.jabber.org/streams">
    <mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
      <mechanism>PLAIN</mechanism>
    </mechanisms>
    <register xmlns="http://jabber.org/features/iq-register"></register>
  </stream:features>
</body>
2013-02-19 19:21:49,081 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:49,103 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="752422456" key="5430da4f98e4c6b3636d9ef611dbb436197d1e99" sid="9c727a3b58574fd7985854afc87de446" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  <auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl">AHVzZXIwADAwMDAwMA==</auth>
</body>
2013-02-19 19:21:49,191 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind">
  <iq xmlns="jabber:client" from="user0@example.com" to="user0@example.com/f958b88d88114c84b9bc7b4e60f26137" type="set" id="1361269309220">
    <command xmlns="http://jabber.org/protocol/commands" action="execute" node="logout"></command>
  </iq>
</body>
2013-02-19 19:21:49,192 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind">
  <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"></success>
</body>
2013-02-19 19:21:49,507 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:49,530 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="1208419072" key="e3dc5b7c20b368eaafcfb0abecb499f7429aff7c" sid="08dde86f9f524dcdabe1413a50f27658" to="example.com" xmlns="http://jabber.org/protocol/httpbind" />
2013-02-19 19:21:49,588 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:49,612 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="752422457" key="a85a85b5b968684b4ba8e0f6f62ea039a50a7c2f" sid="9c727a3b58574fd7985854afc87de446" to="example.com" xmpp:restart="true" xmlns="http://jabber.org/protocol/httpbind" />
2013-02-19 19:21:49,703 [1] OnReceiveBody:<body xmlns="http://jabber.org/protocol/httpbind">
  <stream:features xmlns:stream="http://etherx.jabber.org/streams">
    <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
      <required></required>
    </bind>
    <session xmlns="urn:ietf:params:xml:ns:xmpp-session">
      <required></required>
    </session>
    <ver xmlns="urn:xmpp:features:rosterver"></ver>
  </stream:features>
</body>
2013-02-19 19:21:50,089 [BOSH sender thread] OnCreateWebRequest
2013-02-19 19:21:50,112 [1] OnSendBody:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="752422458" key="648bb9456e1722345f25acd91161829b181fdbe5" sid="9c727a3b58574fd7985854afc87de446" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  <iq id="MX_232" type="set" xmlns="jabber:client">
    <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
      <resource>lim-pc|2.1.0(6502)|Windows 7  6.1.7601.65536 32Bits|172.16.11.219,192.168.11.2</resource>
    </bind>
  </iq>
</body>
Avatar
Alex #6
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
In reply to post #1
You logout and immediate login explains the problem.
Bosh is always working with 2 WebRequests than implement the long polling pattern, otherwise you would not be able to receive data in realtime.

To me it looks like you open a new session before the previous was closed successfully.

When you close a session then MatriX Aborts existing WebRequests, but it can take some milliseconds until the server releases them. So don't reconnect in the OnClose event. But a small sleep in your code before you reconnect.

Alex
Avatar
matianyi #7
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
Alex
Thanks for your reply.

Is there any way to wait until the session closed except Thread.Sleep() ?
Actually, i have opened another thread about this. (http://forum.ag-software.net/thread/1459-BOSH-can-i-wait-u…)
Avatar
Alex #8
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
Quote by matianyi:
Is there any way to wait until the session closed except Thread.Sleep() ?

currently not. You can watch the sender thread and check when it ends.
When you use Thread.Sleep then make sure that you don't block the sender thread with it.
I put this on our TODO list, maybe we find a good solution for one of the next updates.

Quote by matianyi:
Actually, i have opened another thread about this. (http://forum.ag-software.net/thread/1459-BOSH-can-i-wait-u…)
I have replied there and waiting for your logs. Or is this solved now?

Alex
Avatar
matianyi #9
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
Quote by Alex on 2013-02-25, 12:05:
Quote by matianyi:
Actually, i have opened another thread about this. (http://forum.ag-software.net/thread/1459-BOSH-can-i-wait-u…)
I have replied there and waiting for your logs. Or is this solved now?

Alex

sorry for reply so late. we haven't solved that issue and I just post logs to the thread.
Avatar
matianyi #10
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
hello, Alex

I have not resolve the problem yet.
I am using Matrix 1.5.2.8 and let the GUI wait unit session is closed.
Now the login process does very well without any delay.
But sometimes the logout process take 1 minute before send the unavailable presence.
I set ServicePointManager.DefaultConnectionLimit = 3.

This is my client log.

  1. 2013-03-15 10:33:19,169 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" ver="1.6" xmpp:version="1.0" hold="1" wait="300" rid="2048806084" polling="0" to="example.com" secure="true" newkey="975e99db647790d4925d59a4899621e3a9de97d6" xmlns="http://jabber.org/protocol/httpbind" />
  2. 2013-03-15 10:33:19,240 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind" wait="60" inactivity="60" polling="15" requests="2" hold="1" sid="3b42d4055fda463788766d5c26725851" ver="1.6" from="example.com" secure="true" maxpause="120" ack="2048806084">
  3.  <stream:features xmlns:stream="http://etherx.jabber.org/streams">
  4.     <mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
  5.       <mechanism>PLAIN</mechanism>
  6.     </mechanisms>
  7.     <register xmlns="http://jabber.org/features/iq-register"></register>
  8.  </stream:features>
  9. </body>
  10. 2013-03-15 10:33:19,669 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806085" key="d0cfb9115eb101f9b8a1ea654c9596e4d53643e0" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  11.  <auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl">AGRtLWthbmVrby15dQAwMDAwMDA=</auth>
  12. </body>
  13. 2013-03-15 10:33:19,740 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  14.  <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"></success>
  15. </body>
  16. 2013-03-15 10:33:20,170 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806086" key="2b15d48d00adb056fb6974a3168549d9f707f277" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmpp:restart="true" xmlns="http://jabber.org/protocol/httpbind" />
  17. 2013-03-15 10:33:20,242 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  18.  <stream:features xmlns:stream="http://etherx.jabber.org/streams">
  19.     <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
  20.       <required></required>
  21.     </bind>
  22.     <session xmlns="urn:ietf:params:xml:ns:xmpp-session">
  23.       <required></required>
  24.     </session>
  25.     <ver xmlns="urn:xmpp:features:rosterver"></ver>
  26.  </stream:features>
  27. </body>
  28. 2013-03-15 10:33:20,672 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806087" key="e79997c3f4e66c0543a17042a37e54898189724a" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  29.  <iq id="MX_517" type="set" xmlns="jabber:client">
  30.     <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
  31.       <resource>lim-pc|2.1.0(8035)|Windows 7  6.1.7601.65536 32Bits|172.16.11.219,192.168.11.3</resource>
  32.     </bind>
  33.  </iq>
  34. </body>
  35. 2013-03-15 10:33:20,749 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  36.  <iq xmlns="jabber:client" type="result" id="MX_517">
  37.     <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
  38.       <jid>dm-kaneko-yu@example.com/b279afcf102140ab8bdaf201059bf2d8</jid>
  39.     </bind>
  40.  </iq>
  41. </body>
  42. 2013-03-15 10:33:21,174 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806088" key="2cbf752ed2903575b3d309742a4a7d6c99f86ce2" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  43.  <iq id="MX_518" type="set" xmlns="jabber:client">
  44.     <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
  45.  </iq>
  46.  <iq id="MX_519" type="get" xmlns="jabber:client">
  47.     <query xmlns="http://xmpp.legendapl.com/protocol/auth" />
  48.  </iq>
  49. </body>
  50. 2013-03-15 10:33:21,254 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  51.  <iq xmlns="jabber:client" type="result" id="MX_518" from="example.com"></iq>
  52. </body>
  53. 2013-03-15 10:33:21,674 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806089" key="19d275849f9bb6f37ca1f241706f9cf989bb6f9d" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind" />
  54. 2013-03-15 10:33:21,752 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  55.  <iq xmlns="jabber:client" type="result" id="MX_519">
  56.     <query xmlns="http://xmpp.legendapl.com/protocol/auth">
  57.       <authToken>0lDPppuhpajIW7daLneDZdLAoM8rglEXK9DPKAOM_FVMy5Djt0-UgQ8DTImBCHWj0QRfghxpwyUPvJRD82O0Zw</authToken>
  58.     </query>
  59.  </iq>
  60. </body>
  61. 2013-03-15 10:33:22,174 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806090" key="deda2b28ee7c7c5832173d3fff5f79ac863da916" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  62.  <iq id="MX_520" type="get" xmlns="jabber:client">
  63.     <query ver="0" xmlns="http://xmpp.legendapl.com/protocol/contact" />
  64.  </iq>
  65. </body>
  66. 2013-03-15 10:33:22,253 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  67.  <iq xmlns="jabber:client" type="result" id="MX_520">
  68.     <query xmlns="http://xmpp.legendapl.com/protocol/contact" ver="0"></query>
  69.  </iq>
  70. </body>
  71. 2013-03-15 10:33:22,674 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806091" key="19b5268ba8ebc149d7758a48796f78ab3f183d45" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  72.  <iq id="MX_521" type="get" xmlns="jabber:client">
  73.     <query xmlns="http://xmpp.legendapl.com/protocol/status" />
  74.  </iq>
  75. </body>
  76. 2013-03-15 10:33:22,752 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  77.  <iq xmlns="jabber:client" type="result" id="MX_521">
  78.     <query xmlns="http://xmpp.legendapl.com/protocol/status"></query>
  79.  </iq>
  80. </body>
  81. 2013-03-15 10:33:23,171 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806092" key="922a6899967ec88a8b11ac81145e5612875b17f2" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind">
  82.  <iq id="MX_522" from="dm-kaneko-yu@example.com/b279afcf102140ab8bdaf201059bf2d8" type="set" xmlns="jabber:client">
  83.     <query xmlns="http://xmpp.legendapl.com/protocol/status">
  84.       <show>NONE</show>
  85.       <status>Online</status>
  86.     </query>
  87.  </iq>
  88. </body>
  89. 2013-03-15 10:33:23,245 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind">
  90.  <iq xmlns="jabber:client" to="dm-kaneko-yu@example.com/b279afcf102140ab8bdaf201059bf2d8" type="result" id="MX_522">
  91.     <query xmlns="http://xmpp.legendapl.com/protocol/status"></query>
  92.  </iq>
  93. </body>
  94. 2013-03-15 10:33:23,672 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806093" key="a363daf133bd975926326937b4ad06f37cfaf11e" sid="3b42d4055fda463788766d5c26725851" to="example.com" xmlns="http://jabber.org/protocol/httpbind" />

The user click logout. but it takes 1 minute to send the unavailable presence.
At this time, the server have only 1 http connection, so it must hold it for 1 minute or until the client send another request.
but it seems that the client is waiting server to release the only 1 connection to send a another request.

  1. 2013-03-15 10:34:24,729 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind"></body>
  2. 2013-03-15 10:34:24,752 [1] [DEBUG]  BOSH_SEND:<body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="2048806094" key="35b93d58e2ad078f4bf59e9d214aaaf187da4ae5" sid="3b42d4055fda463788766d5c26725851" to="example.com" type="terminate" xmlns="http://jabber.org/protocol/httpbind">
  3.  <presence type="unavailable" xmlns="jabber:client">
  4.     <status>?????</status>
  5.  </presence>
  6. </body>
  7. 2013-03-15 10:34:24,852 [1] [DEBUG]  BOSH_RECV:<body xmlns="http://jabber.org/protocol/httpbind" type="terminate"></body>
Avatar
Alex #11
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
Please contact us directly by email to get this resolved.

Alex
Avatar
matianyi #12
Member since Mar 2012 · 19 posts · Location: Japan
Group memberships: Members
Show profile · Link to this post
hi, alex
which email address should i send to?
Avatar
Alex #13
Member since Feb 2003 · 4295 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
The one you got with your license.
Close Smaller – Larger + Reply to this post:
Verification code: VeriCode Please enter the word from the image into the text field below. (Type the letters only, lower case is okay.)
Smileys: :-) ;-) :-D :-p :blush: :cool: :rolleyes: :huh: :-/ <_< :-( :'( :#: :scared: 8-( :nuts: :-O
Special characters:
Forum: MatriX RSS