Not logged in. · Lost password · Registration disabled
Forum: MatriX and XmppDotNet RSS
General question - sending/receiving messages
Avatar
dtjoa 2012-09-15, 22:47 #1
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
Subject: General question - sending/receiving messages
I notice that my connection occasionally get terminated by server (receiving <stream></stream> from server).
Can client send multiple requests to server before receiving responses on previous request?
Sometimes, I have IQ on disco#item pending and I sends roster update, and once in awhile I see my connection got closed.
In general, should client serialize its request/response? Can client send multiple requests, or is there limit on pending requests?

I am using XMPP over BOSH type of connection.

Any help is greatly appreciated.
Avatar
Alex 2012-09-16, 01:55 #2
Member since Feb 2003 · 4449 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
no normally there is no limit. Of course a server can implement some limits.
A Xml log would help to see if the server closes the stream with a specific error. To get more logs from Bosh use OnReceiveBody and OnSendBody

Alex
Avatar
dtjoa 2012-09-18, 00:03 #3
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
Alex,

Here a case during start-up:

2012-09-17 14:14:24,172 [9] INFO  MyXmpp.XmppPresenter - SND: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="svr02001.uc.test.lab.com" version="1.0" >
2012-09-17 14:14:24,187 [9] INFO  MyXmpp.XmppPresenter - OnCreateBoshSession
2012-09-17 14:14:25,781 [9] INFO  MyXmpp.XmppPresenter - RCV: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="svr02001.uc.test.lab.com" version="1.0"

id="9bdcc6618a41d144ce4c70f3517f84433c44265e" >
2012-09-17 14:14:25,937 [9] INFO  MyXmpp.XmppPresenter - RCV: <stream:features xmlns:stream="http://etherx.jabber.org/streams">
  <mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
    <mechanism>PLAIN</mechanism>
  </mechanisms>
  <c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://www.process-one.net/en/ejabberd/" ver="yy7di5kE0syuCXOQTXNBTclpNTo=" />
  <register xmlns="http://jabber.org/features/iq-register" />
</stream:features>
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - SND: <auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl">XXX</auth>
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - RCV: <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl" />
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - OnLogin
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - SND: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="svr02001.uc.test.lab.com" version="1.0" >
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - RCV: <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="svr02001.uc.test.lab.com" version="1.0"

id="9bdcc6618a41d144ce4c70f3517f84433c44265e" >
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - RCV: <stream:features xmlns:stream="http://etherx.jabber.org/streams">
  <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind" />
  <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
  <c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://www.process-one.net/en/ejabberd/" ver="yy7di5kE0syuCXOQTXNBTclpNTo=" />
  <register xmlns="http://jabber.org/features/iq-register" />
</stream:features>
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_1" type="set" xmlns="jabber:client">
  <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
    <resource>bora-bora</resource>
  </bind>
</iq>
2012-09-17 14:14:30,609 [9] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" id="MX_1" type="result">
  <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
    <jid>test216@svr02001.uc.test.lab.com/bora-bora</jid>
  </bind>
</iq>
2012-09-17 14:14:30,625 [9] INFO  MyXmpp.XmppPresenter - OnBind(True)
2012-09-17 14:14:30,625 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_2" type="set" xmlns="jabber:client">
  <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
</iq>
2012-09-17 14:14:30,641 [9] INFO  MyXmpp.XmppPresenter - RCV: <iq type="result" xmlns="jabber:client" id="MX_2">
  <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
</iq>
2012-09-17 14:14:30,656 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_3" type="get" xmlns="jabber:client">
  <query xmlns="jabber:iq:roster" />
</iq>
2012-09-17 14:14:30,750 [9] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_3" type="result">
  <query xmlns="jabber:iq:roster">
    <item subscription="to" jid="test225@svr02001.uc.test.lab.com">
      <group>My Group 2</group>
      <group>My Contacts</group>
    </item>
    <item subscription="none" jid="test221@svr02001.uc.test.lab.com">
      <group>My Contacts</group>
      <group>My Group 3</group>
    </item>
    <item subscription="both" jid="test201@svr02001.uc.test.lab.com">
      <group>My Group 2</group>
      <group>My Group 1</group>
      <group>My Contacts</group>
    </item>
    <item subscription="none" jid="test216@svr02001.uc.test.lab.com">
      <group>My Contacts</group>
    </item>
    <item subscription="both" jid="test211@svr02001.uc.test.lab.com">
      <group>My Contacts</group>
    </item>
  </query>
</iq>
2012-09-17 14:14:30,781 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_4" type="get" xmlns="jabber:client">
  <vCard xmlns="vcard-temp" />
</iq>
2012-09-17 14:14:30,797 [9] INFO  MyXmpp.XmppPresenter - SND: <presence xmlns="jabber:client">
  <show>chat</show>
  <status></status>
  <priority>0</priority>
  <teststatus xmlns="test:extra:status">
    <location>In Office</location>
  </teststatus>
</presence>
2012-09-17 14:14:30,859 [9] INFO  MyXmpp.XmppPresenter - RCV: <presence xmlns="jabber:client" from="test225@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com" type="subscribe">
  <status>hii</status>
</presence>
2012-09-17 14:14:30,859 [9] INFO  MyXmpp.XmppPresenter - SND: <presence type="subscribed" to="test225@svr02001.uc.test.lab.com" xmlns="jabber:client" />
2012-09-17 14:14:31,047 [9] INFO  MyXmpp.XmppPresenter - RCV: <presence xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com/bora-bora" to="test216@svr02001.uc.test.lab.com/bora-bora">
  <show>chat</show>
  <status />
  <priority>0</priority>
  <teststatus xmlns="test:extra:status">
    <location>In Office</location>
  </teststatus>
</presence>
2012-09-17 14:14:31,734 [9] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_4" type="result" />
2012-09-17 14:14:31,828 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_5" type="get" to="svr02001.uc.test.lab.com" xmlns="jabber:client">
  <query xmlns="http://jabber.org/protocol/disco#items" />
</iq>
2012-09-17 14:14:31,828 [9] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="push877921331"

type="set">
  <query xmlns="jabber:iq:roster">
    <item subscription="both" jid="test225@svr02001.uc.test.lab.com">
      <group>My Group 2</group>
      <group>My Contacts</group>
    </item>
  </query>
</iq>
2012-09-17 14:14:31,844 [9] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_6" type="get" to="test225@svr02001.uc.test.lab.com" xmlns="jabber:client">
  <vCard xmlns="vcard-temp" />
</iq>
2012-09-17 14:14:31,844 [9] INFO  MyXmpp.XmppPresenter - SND: <iq type="result" id="push877921331" xmlns="jabber:client" />
2012-09-17 14:14:32,406 [9] INFO  MyXmpp.XmppPresenter - RCV: </stream:stream>
2012-09-17 14:14:32,406 [9] INFO  MyXmpp.XmppPresenter - SND: </stream:stream>
2012-09-17 14:14:32,406 [9] WARN  MyXmpp.XmppPresenter - xmppClient1_OnClose()
This post was edited on 2012-12-14, 12:09 by Alex.
Avatar
Alex 2012-09-18, 00:14 #4
Member since Feb 2003 · 4449 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
I need also the logs from OnReceiveBody and OnSendBody.
Are you using Openfire?

Alex
Avatar
dtjoa 2012-09-18, 20:27 #5
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
Alex,

We are using ejabberd.

I'll try to capture OnSendBody & OnReceiveBody, and post the log when I have it.
Avatar
dtjoa 2012-09-22, 17:03 #6
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
2012-09-19 08:47:38,906 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(B): <body xmlns="http://jabber.org/protocol/httpbind">
  <presence xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com/bora-bora" to="test216@svr02001.uc.test.lab.com/bora-bora">
    <show>chat</show>
    <status />
    <priority>0</priority>
    <teststatus xmlns="test:extra:status">
      <location>In Office</location>
    </teststatus>
  </presence>
  <presence xmlns="jabber:client" from="test211@svr02001.uc.test.lab.com/32990597181347973297737927" to="test216@svr02001.uc.test.lab.com/bora-bora">
    <show>available</show>
    <comment />
    <status />
    <teststatus xmlns="test:extra:status">
      <state />
      <location>in-office</location>
      <custom_msg />
    </status>
    <delay xmlns="urn:xmpp:delay" from="test211@svr02001.uc.test.lab.com/32990597181347973297737927" stamp="2012-09-18T13:01:40Z"></delay>
    <x xmlns="jabber:x:delay" stamp="20120918T13:01:40" />
  </presence>
</body>
2012-09-19 08:47:38,906 [10] INFO  MyXmpp.XmppPresenter - RCV: <presence xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com/bora-bora" to="test216@svr02001.uc.test.lab.com/bora-bora">
  <show>chat</show>
  <status />
  <priority>0</priority>
  <teststatus xmlns="test:extra:status">
    <location>In Office</location>
  </teststatus>
</presence>
2012-09-19 08:47:38,906 [10] INFO  MyXmpp.XmppPresenter - OnAvailablePresence() from test216@svr02001.uc.test.lab.com/bora-bora
2012-09-19 08:47:38,906 [10] INFO  MyXmpp.XmppPresenter - RCV: <presence xmlns="jabber:client" from="test211@svr02001.uc.test.lab.com/32990597181347973297737927" to="test216@svr02001.uc.test.lab.com/bora-bora">
  <show>available</show>
  <comment />
  <status />
  <teststatus xmlns="test:extra:status">
    <state />
    <location>in-office</location>
    <custom_msg />
  </status>
  <delay xmlns="urn:xmpp:delay" from="test211@svr02001.uc.test.lab.com/32990597181347973297737927" stamp="2012-09-18T13:01:40Z"></delay>
  <x xmlns="jabber:x:delay" stamp="20120918T13:01:40" />
</presence>
2012-09-19 08:47:38,906 [10] INFO  MyXmpp.XmppPresenter - OnAvailablePresence() from test211@svr02001.uc.test.lab.com/32990597181347973297737927
2012-09-19 08:47:38,921 [10] INFO  CmXmpp.CmContact - Delay Presence event: 09/18/2012 06:01:40
2012-09-19 08:47:38,921 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(A): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757689" key="8d447cb9a25f78fd708dadc99eec994a58c3a49c" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind" />
2012-09-19 08:47:38,921 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(B): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757690" key="726549f740a69d5b22b5e46ab0a4feb5543c7dee" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind">
  <iq id="MX_4" type="get" xmlns="jabber:client">
    <vCard xmlns="vcard-temp" />
  </iq>
</body>
2012-09-19 08:47:39,093 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(A): <body xmlns="http://jabber.org/protocol/httpbind">
  <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_4" type="result" />
</body>
2012-09-19 08:47:39,093 [10] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_4" type="result" />
2012-09-19 08:47:39,109 [10] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_6" type="get" to="svr02001.uc.test.lab.com" xmlns="jabber:client">
  <query xmlns="http://jabber.org/protocol/disco#items" />
</iq>
2012-09-19 08:47:39,109 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(A): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757691" key="4ed65ea0652dcd208ae0ff085380918ce386d0de" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind">
  <presence type="subscribed" to="test235@svr02001.uc.test.lab.com" xmlns="jabber:client" />
  <iq id="MX_5" type="set" xmlns="jabber:client">
    <query xmlns="jabber:iq:roster">
      <item jid="test235@svr02001.uc.test.lab.com" name="test235">
        <group>My Contacts</group>
      </item>
    </query>
  </iq>
</body>
2012-09-19 08:47:39,453 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(B): <body xmlns="http://jabber.org/protocol/httpbind">
  <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="push2219241179" type="set">
    <query xmlns="jabber:iq:roster">
      <item subscription="from" jid="test235@svr02001.uc.test.lab.com" />
    </query>
  </iq>
</body>
2012-09-19 08:47:39,453 [10] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="push2219241179" type="set">
  <query xmlns="jabber:iq:roster">
    <item subscription="from" jid="test235@svr02001.uc.test.lab.com" />
  </query>
</iq>
2012-09-19 08:47:39,453 [10] INFO  MyXmpp.XmppPresenter - SND: <iq id="MX_7" type="get" to="test235@svr02001.uc.test.lab.com" xmlns="jabber:client">
  <vCard xmlns="vcard-temp" />
</iq>
2012-09-19 08:47:39,453 [10] INFO  MyXmpp.XmppPresenter - SND: <iq type="result" id="push2219241179" xmlns="jabber:client" />
2012-09-19 08:47:39,453 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(B): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757692" key="5329d91c03286e7f27da396ead271fee73f3f744" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind">
  <iq id="MX_6" type="get" to="svr02001.uc.test.lab.com" xmlns="jabber:client">
    <query xmlns="http://jabber.org/protocol/disco#items" />
  </iq>
  <iq type="result" id="push2219241179" xmlns="jabber:client" />
</body>
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(A): <body xmlns="http://jabber.org/protocol/httpbind">
  <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="push2877602603" type="set">
    <query xmlns="jabber:iq:roster">
      <item subscription="from" name="test235" jid="test235@svr02001.uc.test.lab.com">
        <group>My Contacts</group>
      </item>
    </query>
  </iq>
  <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_5" type="result" />
</body>
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="push2877602603" type="set">
  <query xmlns="jabber:iq:roster">
    <item subscription="from" name="test235" jid="test235@svr02001.uc.test.lab.com">
      <group>My Contacts</group>
    </item>
  </query>
</iq>
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - SND: <iq type="result" id="push2877602603" xmlns="jabber:client" />
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - RCV: <iq xmlns="jabber:client" from="test216@svr02001.uc.test.lab.com" to="test216@svr02001.uc.test.lab.com/bora-bora" id="MX_5" type="result" />
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - SND: <presence type="subscribe" to="test235@svr02001.uc.test.lab.com" id="MX_8" xmlns="jabber:client" />
2012-09-19 08:47:39,562 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(A): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757693" key="214dada3cca0da03e36823bc8e25e937a1a51a64" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind">
  <iq id="MX_7" type="get" to="test235@svr02001.uc.test.lab.com" xmlns="jabber:client">
    <vCard xmlns="vcard-temp" />
  </iq>
  <iq type="result" id="push2877602603" xmlns="jabber:client" />
</body>
2012-09-19 08:47:40,000 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(A): <body xmlns="http://jabber.org/protocol/httpbind" />
2012-09-19 08:47:40,015 [10] INFO  MyXmpp.XmppPresenter - BOSHSND(A): <body xmlns:xmpp="urn:xmpp:xbosh" xmlns:stream="http://etherx.jabber.org/streams" rid="863757694" key="656aab2ea90f42da6ff17ff5a65f431e7cebd049" sid="b1f06ebe2730d23696f080f57c3d37c787fdf8a7" to="svr02001.uc.test.lab.com" xmlns="http://jabber.org/protocol/httpbind">
  <presence type="subscribe" to="test235@svr02001.uc.test.lab.com" id="MX_8" xmlns="jabber:client" />
</body>
2012-09-19 08:47:40,468 [10] INFO  MyXmpp.XmppPresenter - BOSHRCV(A): <body xmlns="http://jabber.org/protocol/httpbind" type="terminate" condition="item-not-found" />
2012-09-19 08:47:40,468 [10] INFO  MyXmpp.XmppPresenter - RCV: </stream:stream>
2012-09-19 08:47:40,468 [10] INFO  MyXmpp.XmppPresenter - SND: </stream:stream>
2012-09-19 08:47:40,484 [10] WARN  MyXmpp.XmppPresenter - OnError(Matrix.Net.BoshException: BoshException ---> System.Net.WebException: The request was aborted: The request was canceled.
   at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
   at #=q2ldGcaI9pae07bHCg0OBhGV7$Vlz95NjBxg653Dm35c=.#=q6oiYWzjF8b0s6ZrtM4b_Ug==(IAsyncResult #=qh2ld98f$4NLGS2T67VxDJg==)
   --- End of inner exception stack trace ---)
Avatar
Alex 2012-09-22, 17:38 #7
Member since Feb 2003 · 4449 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
Your server terminates the session with an item not found error.
I see no errors from Matrix in your logs. The sid is also correct, so no idea what's going wrong on your server.

Alex
Avatar
Alex 2012-09-22, 17:45 #8
Member since Feb 2003 · 4449 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
You can check your ejabberd logs for more info.

Alex
Avatar
dtjoa 2012-09-22, 19:20 #9
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
Thanks.
Avatar
Alex 2012-09-22, 19:32 #10
Member since Feb 2003 · 4449 posts · Location: Germany
Group memberships: Administrators, Members
Show profile · Link to this post
a quick Google search on this topic finds many people having similar problems.
See also: https://support.process-one.net/browse/EJAB-1568

Alex
Avatar
dtjoa 2012-09-26, 05:51 #11
Member since Jul 2012 · 39 posts
Group memberships: Members
Show profile · Link to this post
Alex,

Thank for the information.
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 and XmppDotNet RSS