I have an Android application where I’m connecting to an XMPP server using BOSH. I created a bound and started service that runs in its own thread and does all connection, disconnection etc.
Here’s the skeleton for the service:
public class XMPPConnectionService extends Service {
@Override
public void onCreate() {
super.onCreate();
...
}
public class XMPPConnectionServiceBinder extends Binder {
...
}
@Override
public int onStartCommand(Intent intent, int flags, int startId) {
...
return START_STICKY;
}
private void initializeXMPPConnection() {
if (xmppConnection != null && isConnected && isAuthenticated)
return;
if(xmppConnection == null) {
System.out.println(TAG + " First time connnection to xmpp ");
try {
configurationBuilder = BOSHConfiguration.builder()
.setUsernameAndPassword(jabberId, proxyToken)
.setCustomSSLContext(getCustomSSLContext())
.setXmppDomain("mydomain")
.setFile("/http-bind/")
.setHost(Utility.getHostForChat())
.setPort(ServerConstants.PORT_FOR_CHAT)
.setResource("Smack")
.setSecurityMode(ConnectionConfiguration.SecurityMode.disabled)
.setUseHttps(true)
.setSendPresence(true)
.build();
} catch (XmppStringprepException xse) {
xse.printStackTrace();
Logger.logException(xse.getMessage(), xse);
}
xmppConnection = new XMPPBOSHConnection(configurationBuilder);
}
try {
System.out.println(TAG + " connecting to XMPP");
xmppConnection.connect();
xmppConnection.login();
} catch (SmackException | IOException | XMPPException | InterruptedException sixi) {
sixi.printStackTrace();
Logger.logException(sixi.getMessage(), sixi);
}
if(reconnectionManager== null)
reconnectionManager = ReconnectionManager.getInstanceFor(xmppConnection);
reconnectionManager.enableAutomaticReconnection();
if(offlineMessageManager == null)
offlineMessageManager = new OfflineMessageManager(xmppConnection);
isConnected = true;
isAuthenticated = true;
}
@Override
public void onDestroy() {
super.onDestroy();
Logger.logDebug(TAG, "Closing and destroying XMPP connection");
System.out.println("Closing xmpp connection.");
if(xmppConnection!=null){
reconnectionManager.disableAutomaticReconnection();
xmppConnection.disconnect();
isConnected = false;
isAuthenticated = false;
}
}
}
The service is started via a call to startService and ended on activity’s logout via a call to stopService. Everything works perfectly when I log into the application the first time. I’m able to chat, check offline messages etc. I then proceed to logging out from the application and that too works as expected. The logout code calls stopService as below:
protected void logout() {
Intent stopXMPPConnectionService = new Intent(MyApplication.getAppContext(), XMPPConnectionService.class);
stopXMPPConnectionService.setAction(XMPPConnectionService.ACTION_XMPP_DISCONNECT);
stopService(stopXMPPConnectionService);
...
}
This works fine too. I can see from the logs the onDestroy method of the service being invoked and a XMPP message being sent to the server to set the status as unavailable. I can see the following trace messages in logcat when the user logs out from the application:
10-27 13:07:21.772 6922-6922/io.xxxxx.user I/System.out: Closing xmpp connection.
10-27 13:07:21.773 6922-6922/io.xxxxx.user D/SMACK: XMPPConnection closed (XMPPBOSHConnection[alphauser1\40xxxxx.io@inuka/Smack] (0))
10-27 13:07:21.951 6922-7269/io.inuka.user W/Roster: Roster not loaded while processing Presence Stanza [to=alphauser1\40xxxxx.io@inuka/Smack,from=alphauser1\40xxxxx.io@xxxxx/Smack,id=9V2W6-8,type=unavailable,]
The problem comes when I try to log into the application again. When the XMPP service is started again via a call to the startService method, I see the following error in logcat:
10-27 13:10:54.881 6922-7349/io.xxxx.user I/System.out: io.xxxx.user.service.XMPPConnectionService First time connnection to xmpp
10-27 13:10:54.884 6922-7349/io.xxxx.user I/System.out: io.xxxx.user.service.XMPPConnectionService connecting to XMPP
10-27 13:10:54.887 6922-7349/io.xxxx.user I/BOSHClient: Starting with 1 request processors
10-27 13:10:55.555 6922-7352/io.xxxx.user D/SMACK: RECV (1): <body xmlns="http://jabber.org/protocol/httpbind" xmlns:stream="http://etherx.jabber.org/streams" from="xxxx" authid="5fpgkrm94h" sid="5fpgkrm94h" secure="true" requests="200" inactivity="600" polling="300" wait="60" hold="1" ack="4678127962453164" maxpause="300" ver="1.6"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism><mechanism>EXTERNAL</mechanism></mechanisms><register xmlns="http://jabber.org/features/iq-register"/><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session></stream:features></body>
10-27 13:10:56.357 6922-7352/io.xxxx.user D/SMACK: RECV (1): <body xmlns='http://jabber.org/protocol/httpbind' ack='4678127962453165'><success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/></body>
10-27 13:10:56.526 6922-7352/io.xxxx.user D/SMACK: RECV (1): <body xmlns="http://jabber.org/protocol/httpbind" xmlns:stream="http://etherx.jabber.org/streams"><stream:features><register xmlns="http://jabber.org/features/iq-register"/><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"><optional/></session></stream:features></body>
10-27 13:10:57.049 6922-7349/io.xxxx.user D/SMACK: User logged (1): alphauser1\40xxxx.io@xxxx:0/Smack
10-27 13:10:57.049 6922-7352/io.xxxx.user D/SMACK: RECV (1): <body xmlns='http://jabber.org/protocol/httpbind' ack='4678127962453167'><iq type="result" id="9V2W6-12" to="xxxx/5fpgkrm94h" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>alphauser1\40xxxx.io@xxxx/Smack</jid></bind></iq></body>
10-27 13:10:57.050 6922-7349/io.xxxx.user D/SMACK: XMPPConnection authenticated (XMPPBOSHConnection[alphauser1\40xxxx.io@xxxx/Smack] (1))
10-27 13:10:57.225 6922-7352/io.xxxx.user D/SMACK: RECV (1): <body xmlns='http://jabber.org/protocol/httpbind' ack='4678127962453168'><iq type="result" id="9V2W6-14" to="alphauser1\40xxxx.io@xxxx/Smack" xmlns="jabber:client"><query xmlns="jabber:iq:roster"/></iq></body>
10-27 13:10:57.326 6922-7076/io.xxxx.user W/AbstractXMPPConnection: Connection XMPPBOSHConnection[alphauser1\40xxxx.io@xxxx/Smack] (0) closed with error
org.igniterealtime.jbosh.BOSHException: Could not parse body:
<html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 </title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /http-bind/. Reason:
<pre> Invalid SID value.</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
</body>
</html>
at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:132)
at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114)
at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:241)
at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:187)
at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1114)
at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:990)
at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100)
at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1719)
at java.lang.Thread.run(Thread.java:818)
Caused by: java.lang.IllegalStateException: Root element was not 'body' in the 'http://jabber.org/protocol/httpbind' namespace. (Was 'html' in '')
at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:98)
at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114)
at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:241)
at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:187)
at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1114)
at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:990)
at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100)
at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1719)
at java.lang.Thread.run(Thread.java:818)
10-27 13:10:57.326 6922-7076/io.xxxx.user D/SMACK: XMPPConnection closed due to an exception (XMPPBOSHConnection[alphauser1\40xxxx.io@xxxx/Smack] (0))
org.igniterealtime.jbosh.BOSHException: Could not parse body:
<html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 </title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /http-bind/. Reason:
<pre> Invalid SID value.</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
</body>
</html>
at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:132)
at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114)
at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:241)
at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:187)
at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1114)
at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:990)
at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100)
at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1719)
at java.lang.Thread.run(Thread.java:818)
Caused by: java.lang.IllegalStateException: Root element was not 'body' in the 'http://jabber.org/protocol/httpbind' namespace. (Was 'html' in '')
at org.igniterealtime.jbosh.BodyParserXmlPull.parse(BodyParserXmlPull.java:98)
at org.igniterealtime.jbosh.StaticBody.fromString(StaticBody.java:114)
at org.igniterealtime.jbosh.ApacheHTTPResponse.awaitResponse(ApacheHTTPResponse.java:241)
at org.igniterealtime.jbosh.ApacheHTTPResponse.getBody(ApacheHTTPResponse.java:187)
at org.igniterealtime.jbosh.BOSHClient.processExchange(BOSHClient.java:1114)
at org.igniterealtime.jbosh.BOSHClient.processMessages(BOSHClient.java:990)
at org.igniterealtime.jbosh.BOSHClient.access$300(BOSHClient.java:100)
at org.igniterealtime.jbosh.BOSHClient$RequestProcessor.run(BOSHClient.java:1719)
at java.lang.Thread.run(Thread.java:818)
10-27 13:10:57.389 6922-7206/io.xxxx.user W/art: No such thread id for suspend: 231
10-27 13:10:57.418 6922-7245/io.xxxx.user W/art: No such thread id for suspend: 264
10-27 13:10:59.225 1259-1326/? D/hwcomposer: hw_composer sent 555 syncs in 60s
Once the error is thrown the connection is automatically established but it causes a delay in app initialization. The code works fine on the very first connection i.e. when the app is launched the very first time or I kill the app using “fore stop” from android system settings. But when I logout and login again, I get the above error.
I have a suspicion that somehow the connection is not being closed cleanly - not sure how to do it properly.
Any helps, tips, pointers will be greatly appreciated.