No one? I'm stucked with this

Tomcat — Thu, 17 Nov 2011 11:18:32 +0000

No one? I'm stucked with this one.

I did some research with

Tomcat — Mon, 07 Nov 2011 10:32:55 +0000

I did some research with tcpdump on the server where ejabberd is running. The problem has something to do with an ACK that is send with delay.

Here is the dump corresponding to the sequence above (I can reproduce this any time):

The messages were send from the ejabberd to the client1 and then the <close> is delivered:

09:28:45.387026 IP 192.168.50.51.xmpp-client > 192.168.2.54.26390: Flags [P.], seq 97096:97255, ack 2378, win 262, length 159
E.....@.@.i...23...6.fg....;....P....s..<iq from='test@localhost/GU-PC' to='jadmin@localhost/PROTEL-JANTH' type='set' id='527d7c07'><close xmlns='http://jabber.org/protocol/ibb' sid='7ac8897f'/></iq>

Then the ACKs for the messages from client1 comes in:

09:28:45.387110 IP 192.168.2.54.26390 > 192.168.50.51.xmpp-client: Flags [.], ack 92338, win 16425, length 0
E..(..@...8q...6..23g..f........P.@).4........
09:28:45.387267 IP 192.168.2.54.26390 > 192.168.50.51.xmpp-client: Flags [.], ack 95131, win 16425, length 0
E..(..@...8p...6..23g..f........P.@).K........
09:28:45.387678 IP 192.168.2.54.26390 > 192.168.50.51.xmpp-client: Flags [.], ack 97096, win 16425, length 0
E..(..@...8o...6..23g..f.......;P.@)..........

Now the receipt on the <close> is send from the client1 to the ejabberd combined with the ACK for the <close>

09:28:45.391483 IP 192.168.2.54.26390 > 192.168.50.51.xmpp-client: Flags [P.], seq 2378:2484, ack 97255, win 16385, length 106
E.....@...7....6..23g..f........P.@..}..<iq type="result" id="527d7c07" to="test@localhost/GU-PC" from="jadmin@localhost/PROTEL-JANTH" xmlns="" />

The ejabberd sends the receipt to the client2. Everything fine, but ...

09:28:45.391820 IP 192.168.50.51.xmpp-client > 192.168.0.125.48403: Flags [P.], seq 2541:2637, ack 96625, win 1678, length 96
E...rc@.@.....23...}.f...       ....G.P....{..<iq from='jadmin@localhost/PROTEL-JANTH' to='test@localhost/GU-PC' type='result' id='527d7c07'/>

.. the ACK for the receipt is send with delay to the client1.

09:28:45.424646 IP 192.168.50.51.xmpp-client > 192.168.2.54.26390: Flags [.], ack 2484, win 262, length 0
E..(..@.@.j...23...6.fg.........P.......

Any idea what happens this 32 MilliSeconds? If you need anything more to help me with this, please let me know.

I suspected the shaper to be the reason, but the problem still exists after disabling the shapers completly.

Kind regards

PS: Here is the ejabberd-log from this message. I can't see anything suspicous here. I think the next message from client1 is send with delay because of the delayed ACK.

=INFO REPORT==== 2011-11-07 09:28:45.412 ===
D(<0.387.0>:ejabberd_receiver:320) : Received XML on stream = "<iq type=\"result\" id=\"527d7c07\" to=\"test@localhost/GU-PC\" from=\"jadmin@localhost/PROTEL-JANTH\" xmlns=\"\" />"
=INFO REPORT==== 2011-11-07 09:28:45.412 ===
D(<0.388.0>:ejabberd_router:313) : route
        from {jid,"jadmin","localhost","PROTEL-JANTH","jadmin","localhost",
                  "PROTEL-JANTH"}
        to {jid,"test","localhost","GU-PC","test","localhost","GU-PC"}
        packet {xmlelement,"iq",
                           [{"type","result"},
                            {"id","527d7c07"},
                            {"to","test@localhost/GU-PC"},
                            {"from","jadmin@localhost/PROTEL-JANTH"}],
                           []}
=INFO REPORT==== 2011-11-07 09:28:45.413 ===
D(<0.388.0>:ejabberd_local:300) : local route
        from {jid,"jadmin","localhost","PROTEL-JANTH","jadmin","localhost",
                  "PROTEL-JANTH"}
        to {jid,"test","localhost","GU-PC","test","localhost","GU-PC"}
        packet {xmlelement,"iq",
                           [{"type","result"},{"id",[...]},{[...],...},{...}],
                           []}
=INFO REPORT==== 2011-11-07 09:28:45.413 ===
D(<0.388.0>:ejabberd_sm:411) : session manager
        from {jid,"jadmin","localhost","PROTEL-JANTH","jadmin","localhost",
                  "PROTEL-JANTH"}
        to {jid,"test","localhost","GU-PC","test","localhost","GU-PC"}
        packet {xmlelement,"iq",
                           [{"type","result"},{"id",[...]},{[...],...},{...}],
                           []}
=INFO REPORT==== 2011-11-07 09:28:45.414 ===
D(<0.388.0>:ejabberd_sm:510) : sending to process <0.391.0>
=INFO REPORT==== 2011-11-07 09:28:45.414 ===
D(<0.391.0>:ejabberd_c2s:1558) : Send XML on stream = <<"<iq from='jadmin@localhost/PROTEL-JANTH' to='test@localhost/GU-PC' type='result' id='527d7c07'/>">>
=INFO REPORT==== 2011-11-07 09:28:45.425 ===
D(<0.387.0>:ejabberd_receiver:320) : Received XML on stream = "<message to=\"test@localhost\" id=\"9\"><body>10000</body></message>"

ejabberd - Comments for "4 times slower performance when sending receipt for close in IBB"

No one? I'm stucked with this

I did some research with