Re: Strophe with Ejabberd http-bind gets 404 on sending messages too quickly without waiting

1,249 views
Skip to first unread message

Jack Moffitt

unread,
Nov 9, 2012, 2:34:26 PM11/9/12
to strophe
> After some research I figured out that this is due to invalid rid issue and
> it is happening because ideally client-side js should wait for server
> response before pushing a new stanza while it does not in some cases.

How did you determine this? Are you sure you aren't hitting ejabberd's
rate limits on message sends?

> From my point of view this should be ensured by Strophe.js at low level
> rather than the application programmer. Please tell me how should I proceed
> to fix this problem? I could not find solution to this problem on Google.

Strophe has code to throttle requests so there is never more than one
outbound. Do you have logs that show multiple requests in flight?

It's really hard to say what is happening without access to the wire
logs and/or the debugging logs for the session that experienced the
problem.

jack.

Saurabh Kumar

unread,
Nov 9, 2012, 2:41:55 PM11/9/12
to str...@googlegroups.com, ja...@metajack.im
Thanks for prompt reply!

Could you quickly give me a reference about how to configure ejabberd rate limits, before I provide you with the other logs. Problem could be with ejabberd config.
If I run a loop which send messages once per second things go well. On the other hand, sending messages twice a second leads to 404.

Jack Moffitt

unread,
Nov 9, 2012, 3:13:23 PM11/9/12
to strophe
> Could you quickly give me a reference about how to configure ejabberd rate
> limits, before I provide you with the other logs. Problem could be with
> ejabberd config.

http://www.ejabberd.im/files/doc/guide.html#htoc16

I'm not sure what the default maxreate is, but I believe there his a
top level c2s shaper configured with some maxrate.

jack.

Saurabh Kumar

unread,
Nov 9, 2012, 11:12:26 PM11/9/12
to str...@googlegroups.com
Here is what I saw in ejabberd logs,

All requests use same session id and are arranged chronologically.

RID: 2407827990 processesd.
RID: 2407827992 buffered.
RID: 2407827993 buffered. Session terminated.
RID: 2407827991 bad request 404. no session. bad key.

Can you think of any plausible reason?



jack.

--
You received this message because you are subscribed to the Google Groups "Strophe" group.
To post to this group, send email to str...@googlegroups.com.
To unsubscribe from this group, send email to strophe+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/strophe?hl=en.


Jack Moffitt

unread,
Nov 20, 2012, 6:41:17 PM11/20/12
to strophe
Yes, you can see that it's sent 93 before 91. This is outside the RID
window, and so the server terminates the connection.

The server expects to get 91 next, and will allow for 92 to come in
early. But 93 is too far ahead. The server never got 91 at all it
appears. Did strophe send it? What do Strophe's logs say when this
happens?

jack.

Christian Gribneau

unread,
Jan 28, 2013, 3:22:13 PM1/28/13
to str...@googlegroups.com, ja...@metajack.im
Ejabberd uses the http 404 code in a handful of cases. You can find them in the source, and the comments are reasonably exaplanatory:

emancipator:xmpp-server grib$ grep -3 -in 404 src/web/ejabberd_http_bind.erl 


228-        {size_limit, Sid} ->
229-        case mnesia:dirty_read({http_bind, Sid}) of
230-            [] ->
231:                {404, ?HEADER, ""};
232-            [#http_bind{pid = FsmRef}] ->
233-                gen_fsm:sync_send_all_state_event(FsmRef, {stop, close}),
234-                {200, ?HEADER, "<body type='terminate' "
--
780-    case http_put(Sid, Rid, Attrs, Payload, PayloadSize, StreamStart, IP) of
781-        {error, not_exists} ->
782-            ?DEBUG("no session associated with sid: ~p", [Sid]),
783:            {404, ?HEADER, ""};
784-        {{error, Reason}, Sess} ->
785-            ?DEBUG("Error on HTTP put. Reason: ~p", [Reason]),
786-            handle_http_put_error(Reason, Sess);
--
853-    case Reason of
854-        not_exists -> %% bad rid
855-        ?DEBUG("Closing HTTP bind session (Bad rid).", []),
856:            {404, ?HEADER, ""};
857-        bad_key ->
858-        ?DEBUG("Closing HTTP bind session (Bad key).", []),
859:            {404, ?HEADER, ""};
860-        polling_too_frequently ->
861-        ?DEBUG("Closing HTTP bind session (User polling too frequently).", []),
862-            {403, ?HEADER, ""}



On Jan 28, 2013, at 10:49 AM, Bill Hubbard wrote:

I'm having the same issue, but using JSJaC, not Strophe.  In my case, as in the example provided by Saurabh, I would get a 404 on the request that was attempting to send rid 91. What I don't understand is why the request shows up in the ejabberd log. How does a request get through to the log if it got a 404 response? I thought 404 meant the server could not be reached.


--
You received this message because you are subscribed to the Google Groups "Strophe" group.
To post to this group, send email to str...@googlegroups.com.
To unsubscribe from this group, send email to strophe+u...@googlegroups.com.

Bill Hubbard

unread,
Jan 28, 2013, 4:42:29 PM1/28/13
to str...@googlegroups.com, ja...@metajack.im
I'm in Windows and I don't know ERLANG, so how do I determine from the HTTP response which condition generated the 404? It's sporadic, and my chat client retries the connection after getting a terminate response from ejabberd, so the same series of messages repeats. The process will continue 2 to 5 times, in the exact same sequence, before it succeeds, so I'm trying desperately to determine what is different when it succeeds from when it fails, because the content of the requests is identical in each iteration.

The 404 conditions you pointed out appear to include a body tag with type='terminate', but I don't get a terminate response until two requests after the 404 condition. This is all I see in the 404 response:

HTTP/1.1 404 Not Found
Content-Length: 0
Content-Type: text/xml; charset=utf-8
Access-Control-Allow-Origin: *
Access-Control-Allow-Headers: Content-Type

Two requests later, when I do get a terminate, I get:

HTTP/1.1 200 OK
Content-Length: 95
Content-Type: text/xml; charset=utf-8
Access-Control-Allow-Origin: *
Access-Control-Allow-Headers: Content-Type

Ejabberd log reports bad_key. I posted an entry on the ejabberd forum a few days ago: http://www.ejabberd.im/node/9552

I don't have much to go on, so am reaching out wherever I can, as I have lost many days trying to resolve this.  Thanks for any help.

<body xmlns='http://jabber.org/protocol/httpbind' type='terminate' condition='item-not-found'/>

Bill Hubbard

unread,
Jan 28, 2013, 4:44:37 PM1/28/13
to str...@googlegroups.com, ja...@metajack.im
Apparently I cannot edit a post here. My previous message got a bit out of sequence. The terminate response is actually:


HTTP/1.1 200 OK
Content-Length: 95
Content-Type: text/xml; charset=utf-8
Access-Control-Allow-Origin: *
Access-Control-Allow-Headers: Content-Type

Christian Gribneau

unread,
Jan 28, 2013, 5:48:55 PM1/28/13
to str...@googlegroups.com, ja...@metajack.im
The condition you've described sounds like RIDs getting out of sequence. Walking through the sids, rids, and responses will provide more context.

I haven't ever used JSJaC. Does it have the ability to log the XML in and out of the client? In a pinch, firebug will show you what has been sent and received.



Things to look for:

Is the RID incrementing by more than 1?

Is the client maintaining two (or more) bosh connections (comprised of as many as two simultaneous HTTP connections each)?
(This condition can arise if attempting to reconnect repeatedly with some libraries. I am unfamiliar with JSJaC.)

-C

Christian Gribneau

unread,
Jan 31, 2013, 11:56:05 AM1/31/13
to str...@googlegroups.com, ja...@metajack.im
In the event that the root of this issue turns out to be multiple concurrent attempts to reconnect triggered by various events on the client, I've put out a mutex plugin for jQuery that might be useful:


You can also find it on the jQuery site:



Cheers
-C



On Jan 28, 2013, at 10:49 AM, Bill Hubbard wrote:

I'm having the same issue, but using JSJaC, not Strophe.  In my case, as in the example provided by Saurabh, I would get a 404 on the request that was attempting to send rid 91. What I don't understand is why the request shows up in the ejabberd log. How does a request get through to the log if it got a 404 response? I thought 404 meant the server could not be reached.

--
You received this message because you are subscribed to the Google Groups "Strophe" group.
To post to this group, send email to str...@googlegroups.com.
To unsubscribe from this group, send email to strophe+u...@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages