Dealing with HTTP Error 400 with punjab

35 views
Skip to first unread message

Daryl Herzmann

unread,
Jun 6, 2013, 9:38:44 PM6/6/13
to str...@googlegroups.com
Hi,

I continue to plod along attempting to make a robust strophe
connection to openfire via punjab. The current issue a small
percentage of my users are seeing is an error 400 that I can't resolve
where it is coming from. Here's a sample of the debug log from my
client.

7:47:06 AM :: request id 218.0 posting
7:47:06 AM :: request id 218.0 state changed to 1
7:47:06 AM :: request id 218.0 state changed to 1
7:47:06 AM :: SENT: <body rid='3340377560'
xmlns='http://jabber.org/protocol/httpbind'
sid='b97de6e9f5b2bcefd1a8bd0355870dc80d67761e'/>
7:47:16 AM :: request id 218.1 state changed to 2
7:47:16 AM :: request id 218.1 state changed to 3
7:47:16 AM :: request id 218.1 state changed to 4
7:47:16 AM :: removing request
7:47:16 AM :: _throttledRequestHandler called with 0 requests
7:47:16 AM :: request id 218 should now be removed
7:47:16 AM :: request id 218.1 got 200
7:47:16 AM :: RECV: <body
xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' to='user'
from='luser'><show>away</show><status>I'm not here right
now</status><c xmlns='http://jabber.org/protocol/caps'
node='http://pidgin.im/' ver='I22W7CegORwdbnu0ZiQwGpxr0Go='
hash='sha-1'/><x
xmlns='vcard-temp:x:update'><photo>90352fbb3cbddee510a310ff22a8b5b223bfe290</photo></x></presence></body>
7:47:16 AM :: no requests during idle cycle, sending blank request
7:47:16 AM :: request id 219.0 posting
7:47:16 AM :: request id 219.0 state changed to 1
7:47:16 AM :: request id 219.0 state changed to 1
7:47:16 AM :: SENT: <body rid='3340377561'
xmlns='http://jabber.org/protocol/httpbind'
sid='b97de6e9f5b2bcefd1a8bd0355870dc80d67761e'/>
7:47:26 AM :: request id 219.1 state changed to 2
7:47:26 AM :: request id 219.1 state changed to 3
7:47:26 AM :: request id 219.1 state changed to 4
7:47:26 AM :: removing request
7:47:26 AM :: _throttledRequestHandler called with 0 requests
7:47:26 AM :: request id 219 should now be removed
7:47:26 AM :: request id 219.1 error 400 happened
7:47:26 AM :: request errored, status: 400, number of errors: 1
7:47:26 AM :: Strophe.Status.DISCONNECTING...
7:47:26 AM :: _doDisconnect was called
7:47:26 AM :: Strophe.Status.DISCONNECTED...

So looking at the punjab source, error 400 means one of the following (I think)

1. Bad stanza that isn't <body>
2. Some Xml Parse error occurs
3. Some other error occurs
4. Some initial session establishment issue that I should be well past
at this time

Each those situations should log something, but the punjab logs are
clean at the time. So I wonder if the apache proxy is erroring out?
Unfortunately, getting the apache logs at this time is problematic :(
(i don't have sysadmin access to the production systems).

From what I can tell, this error does not invalidate the session on
punjab's side, but strophe appears to initiate the disconnect
procedure. This causes a problem as my client creates a new session
and now there's two active on the server :(

Any suggestions on what I should do? Perhaps some kind soul has a
'robustness' plugin that I could add on? :) I also wish I could
figure out how to log any payloads that come with http errors.

PS. Openfire's recent releases have added significant BOSH
improvements, so I will try my client for a while going direct to
openfire via apache/proxy for a while and see how it goes.

thanks,
daryl

Jack Moffitt

unread,
Jun 8, 2013, 12:34:45 AM6/8/13
to strophe
> So looking at the punjab source, error 400 means one of the following (I think)
>
> 1. Bad stanza that isn't <body>
> 2. Some Xml Parse error occurs
> 3. Some other error occurs
> 4. Some initial session establishment issue that I should be well past
> at this time
>
> Each those situations should log something, but the punjab logs are
> clean at the time. So I wonder if the apache proxy is erroring out?
> Unfortunately, getting the apache logs at this time is problematic :(
> (i don't have sysadmin access to the production systems).

Does punjab log other things? Perhaps logging is turned off? :)

Generally proxy errors will result in a 5xx, not a 4xx.

Another way to see if the code is triggering or not is to put a raise
in those places and see if punjab crashes like you expect.

> From what I can tell, this error does not invalidate the session on
> punjab's side, but strophe appears to initiate the disconnect
> procedure. This causes a problem as my client creates a new session
> and now there's two active on the server :(

If the session is not invalidated then this is probably not a punjab
issue. I believe punjab still uses legacy BOSH, which defines 4xx
errors as terminal. This would point to Apache, but why it would
return 400 error I don't know. Perhaps the request is actually
invalid?

jack.

Daryl Herzmann

unread,
Jun 15, 2013, 5:45:03 PM6/15/13
to str...@googlegroups.com
On Fri, 7 Jun 2013, Jack Moffitt wrote:

> > So looking at the punjab source, error 400 means one of the following (I
> > think)
> >
> > 1. Bad stanza that isn't <body>
> > 2. Some Xml Parse error occurs
> > 3. Some other error occurs
> > 4. Some initial session establishment issue that I should be well past
> > at this time
> >
> > Each those situations should log something, but the punjab logs are
> > clean at the time. So I wonder if the apache proxy is erroring out?
> > Unfortunately, getting the apache logs at this time is problematic :(
> > (i don't have sysadmin access to the production systems).
>
> Does punjab log other things? Perhaps logging is turned off? :)

Yeah, I am getting other tracebacks from punjab for other issues.

> Generally proxy errors will result in a 5xx, not a 4xx.

Thanks, that is good to know.

> Another way to see if the code is triggering or not is to put a raise in
> those places and see if punjab crashes like you expect.

Thanks, of course, I can't reproduce this fun in development :)

> > From what I can tell, this error does not invalidate the session on
> > punjab's side, but strophe appears to initiate the disconnect
> > procedure. This causes a problem as my client creates a new session
> > and now there's two active on the server :(
>
> If the session is not invalidated then this is probably not a punjab
> issue. I believe punjab still uses legacy BOSH, which defines 4xx errors
> as terminal. This would point to Apache, but why it would return 400 error
> I don't know. Perhaps the request is actually invalid?

Hmm, from what I can tell, the 400 error emitted by punjab does not
invalidate the session on punjab's side. My hack attempt at the moment is
to disconnect once I get the disconnecting status

else if (status == Strophe.Status.DISCONNECTING) {
App.log('Strophe.Status.DISCONNECTING...');
App.XMPPConn.flush();
App.XMPPConn.disconnect();
}

This change will go to production in a month or so, so we'll see how that
goes :)

thanks for your help,
daryl
Reply all
Reply to author
Forward
0 new messages