Strophe + BOSH + Openfire server

We are trying to get Strophe, BOSH with openfire to work. We get anonymous authentication and session but username authentication fails everytime.

We have researched all the post on the forums before posting this issue. Please respond ASAP.

Here is the log for sucessful anonymous authentication -

Strophe is connecting.

LOG: _throttledRequestHandler called with 1 requests

LOG: request id 3.0 posting

LOG: request id 3.0 state changed to 1

LOG: request id 3.0 state changed to 2

SENT:

LOG: request id 3.1 state changed to 2

LOG: request id 3.1 state changed to 3

LOG: request id 3.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 3 should now be removed

LOG: request id 3.1 got 200

LOG: _connect_cb was called

RECV: stream:featuresDIGEST-MD5PLAINANONYMOUSCRAM-MD5</mech anism>zlib</stream:features>

Strophe is authentication

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 4.0 posting

LOG: request id 4.0 state changed to 1

LOG: request id 4.0 state changed to 2

SENT:

LOG: request id 4.1 state changed to 3

LOG: request id 4.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 4 should now be removed

LOG: request id 4.1 got 200

RECV:

LOG: SASL authentication succeeded.

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 5.0 posting

LOG: request id 5.0 state changed to 1

LOG: request id 5.0 state changed to 2

SENT:

LOG: request id 5.1 state changed to 3

LOG: request id 5.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 5 should now be removed

LOG: request id 5.1 got 200

RECV: stream:featureszlib</stream:features>

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 6.0 posting

LOG: request id 6.0 state changed to 1

LOG: request id 6.0 state changed to 2

SENT:

LOG: request id 6.1 state changed to 3

LOG: request id 6.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 6 should now be removed

LOG: request id 6.1 got 200

RECV: c80ab5a0@cloud11/c80ab5a0</ bind>

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 7.0 posting

LOG: request id 7.0 state changed to 1

LOG: request id 7.0 state changed to 2

SENT:

LOG: request id 7.1 state changed to 3

LOG: request id 7.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 7 should now be removed

LOG: request id 7.1 got 200

RECV:

Strophe is connected.

Strophe is disconnecting.

LOG: Disconnect was called because: undefined

LOG: _sendTerminate was called

LOG: _throttledRequestHandler called with 1 requests

LOG: request id 8.0 posting

LOG: request id 8.0 state changed to 1

LOG: request id 8.0 state changed to 2

SENT:

LOG: request id 8.1 state changed to 3

LOG: request id 8.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 8 should now be removed

LOG: request id 8.1 got 200

RECV: <body xmlns='http://jabber.org/protocol/httpbind’/>

LOG: _doDisconnect was called

Strophe is disconnected.

Here is the log for failed non-anonymous authentication (we disabled anonymous auth on server to reproduce the issue) -

Strophe is connecting.

LOG: _throttledRequestHandler called with 1 requests

LOG: request id 1.0 posting

LOG: request id 1.0 state changed to 1

LOG: request id 1.0 state changed to 2

SENT:

LOG: request id 1.1 state changed to 2

LOG: request id 1.1 state changed to 3

LOG: request id 1.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 1 should now be removed

LOG: request id 1.1 got 200

LOG: _connect_cb was called

RECV: stream:featuresDIGEST-MD5PLAINANONYMOUSCRAM-MD5</mech anism>zlib</stream:features>

Strophe is authentication

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 2.0 posting

LOG: request id 2.0 state changed to 1

Strophe failed to connect.

LOG: _onDisconnectTimeout was called

LOG: _doDisconnect was called

Strophe is disconnected.

Strophe failed to connect.

LOG: _onDisconnectTimeout was called

LOG: _doDisconnect was called

SENT:

Further help will be highly appreciated

After doing some further analysis it seems client is using digest-md5 where as server is not configured for the same. So we disabled digest-md5 on server and now it supports only plain mechanism but still it stops after the initial session creation here are the new logs -

Strophe is connecting.LOG: _throttledRequestHandler called with 1 requestsLOG: request id 1.0 postingLOG: request id 1.0 state changed to 1LOG: request id 1.0 state changed to 2SEND: LOG: request id 1.1 state changed to 2LOG: request id 1.1 state changed to 3LOG: request id 1.1 state changed to 4LOG: removing requestLOG: _throttledRequestHandler called with 0 requestsLOG: request id 1 should now be removedLOG: request id 1.1 got 200LOG: _connect_cb was calledRECV: stream:featuresPLAIN</mechanis ms>zlib</stream:features>Strophe failed to connect.LOG: _onDisconnectTimeout was calledLOG: _doDisconnect was calledStrophe is disconnected.

I have enabled logging of http packets on the openfire server. Its a strange behaviour after the client receives the session, it just sits there doing nothing -

Strophe is connecting.LOG: _throttledRequestHandler called with 1 requestsLOG: request id 1.0 postingLOG: request id 1.0 state changed to 1SEND: LOG: request id 1.1 state changed to 2LOG: request id 1.1 state changed to 3LOG: request id 1.1 state changed to 4LOG: removing requestLOG: _throttledRequestHandler called with 0 requestsLOG: request id 1 should now be removedLOG: request id 1.1 got 200

LOG: _connect_cb was called

RECV: stream:featuresPLAIN</mechanis ms>zlib</stream:features>

I have used the source from the Strophe website itself, can’t seem to figure why would it just halt when client sees plain as the authentication mechanism?

Well it seems the client just stalls when it seems plain as authentication mechanism and NOT using SSL.

There was a similiar issue earlier with digest-md5. Not sure if this is openfire or strophe issue.

Here is the summary till now -

BTW - Knock, Knock, anyone there on the forum?

Hello -

After having researched all the forums, I have still not been able to get Plain SASL authentication to work with BOSH + Strophe + Openfire 3.7.

If I enter a garbled username i.e. user name without the @domain, the client quickly chooses anonymous auth and gives anonymous session. But if I enter right username@domain, it stalls after receiving the session from the server and mechanism as PLAIN (disabled all other mechanism on the server). If I enable all mechanism on the server, it uses MD5 and it again fails because passwords are plain text.

Here are the relevant client logs

Strophe is connecting.LOG: _throttledRequestHandler called with 1 requestsLOG: request id 1.0 postingLOG: request id 1.0 state changed to 1SEND: LOG: request id 1.1 state changed to 2LOG: request id 1.1 state changed to 3LOG: request id 1.1 state changed to 4LOG: removing requestLOG: _throttledRequestHandler called with 0 requestsLOG: request id 1 should now be removedLOG: request id 1.1 got 200

LOG: _connect_cb was called

RECV: stream:featuresPLAIN</mechanis ms>zlib</stream:features>

Server logs -

Thu Mar 17 12:43:16 EDT 2011: HTTP RECV(d20af63d):

Thu Mar 17 12:43:16 EDT 2011: HTTP SENT(d20af63d): stream:featuresPLAIN</mechanis ms>zlib</stream:features>

It is very strange that if server advertises only Plain as auth mechanism, the client just halts and does not send the auth request on session provided by the server.

Any ideas.

Thanks,

Himanshu

Further troubleshooting shows that after the client receives authchallenge or auth mechanism, it just throws error and disconnects -

Strophe is connecting.LOG: _throttledRequestHandler called with1 requestsLOG: request id 1.0 postingLOG: request id 1.0 state changedto 1LOG: request id 1.0 state changed to 2SEND: <bodyrid=‘3343970908’ xmlns=‘http://jabber.org/protocol/httpbind’to='ec2-50-16-41-243.compute-1.amazonaws.com’ xml:lang=‘en’ wait='60’hold=‘1’ content=‘text/xml; charset=utf-8’ ver=‘1.6’ xmpp:version='1.0’xmlns:xmpp=‘urn:xmpp:xbosh’/>LOG: request id 1.1 state changed to2LOG: request id 1.1 state changed to 3LOG: request id 1.1 statechanged to 4LOG: removing requestLOG: _throttledRequestHandler calledwith 0 requestsLOG: request id 1 should now be removedLOG: request id1.1 got 200LOG: _connect_cb was calledRECV: <bodyxmlns=‘http://jabber.org/protocol/httpbind’xmlns:stream='http://etherx.jabber.org/strea ms’ authid='eaf22fe5’sid=‘eaf22fe5’ secure=‘true’ requests=‘2’ inactivity=‘30’ polling='5’wait=‘60’ hold=‘1’ ack=‘3343970908’ maxpause='300’ver=‘1.6’>stream:features<mechanismsxmlns=‘urn:ietf:params:xml: ns:xmpp-sasl’>DIGEST-MD5PLAINANONYMOUSCRAM-MD5zlib<bindxmlns=‘urn:ietf:params:xml:ns:xmpp-bin d’/><sessionxmlns=‘urn:ietf:params:xml:ns:xmpp-session’/></stream:features></bod y>LOG:_throttledRequestHandler called with 0 requestsLOG: request id 2.0postingLOG: request id 2.0 state changed to 1LOG: request id 2.0 statechanged to 2SEND: <body rid='3343970909’xmlns=‘http://jabber.org/protocol/httpbind’ sid=‘eaf22fe5’><authxmlns='urn:ietf:params:xml:ns:xmpp-sasl’mechanism=‘DIGEST-M D5’/>LOG: request id 2.1 statechanged to 3LOG: request id 2.1 state changed to 4LOG: removingrequestLOG: _throttledRequestHandler called with 0 requestsLOG: requestid 2 should now be removedLOG: request id 2.1 got 200RECV: <bodyxmlns=‘http://jabber.org/protocol/httpbind’><challengexmlns=‘urn:ietf:params:xml:ns:xmpp-sasl’>cmVhbG09ImVjMi01MC0xNi00MS0 yNDMuY29tcHV0ZS0xLmFtYXpvbmF3cy5jb20iLG5vbmNlPSJjZEJET1ByWUJEYlBHNWRXUmdPZzZRdHk rRi82NjhvVis3Vm1QRU9tIixxb3A9ImF1dGgiLGNoYXJzZXQ9dXRmLTgsYWxnb3JpdGhtPW1kNS1zZXN zLOG:error: function () { [native code] }Strophe failed to connect.LOG:_onDisconnectTimeout was calledLOG: _doDisconnect was calledStrophe isdisconnec

Further research shows that the strophe is stuck on authenticating after it receives mechanism to authenticate or MD5 challenge and just sits there and a disconnect is called. Any clues? -

Strophe is connecting.

LOG: _throttledRequestHandler called with 1 requests

LOG: request id 1.0 posting

LOG: request id 1.0 state changed to 1

LOG: request id 1.0 state changed to 2

SEND:

LOG: request id 1.1 state changed to 2

LOG: request id 1.1 state changed to 3

LOG: request id 1.1 state changed to 4

LOG: removing request

LOG: _throttledRequestHandler called with 0 requests

LOG: request id 1 should now be removed

LOG: request id 1.1 got 200

LOG: _connect_cb was called

RECV: stream:featuresPLAIN</mechanis ms>zlib</stream:features>

Strophe is Authenticating.

Strophe failed to connect.

LOG: _onDisconnectTimeout was called

LOG: _doDisconnect was called

Strophe is disconnected.

I hope this helps someone. The issue was very very silly. The examples provided did not have 2 js includes i.e. md5js include and base64 js. Once these were included in the html files, the issues were resolved,

Thanks,

Himanshu