AnsweredAssumed Answered

ReconnectionManager sends duplicate login requests while reconnecting

Question asked by Amitoj on Jun 20, 2016
Latest reply on Jun 21, 2016 by Flow

I'm creating an android Xmpp client using Smack(4.1.7). While implementing the automatic re-connection feature using ReconnectionManager, I find that the library sends duplicate login requests. Because of that the second Reconnection is rejected by server with error - `Client is already logged in`.

 

Here is the XML dump from Smack:

 

    06-20 15:42:37.704 26369-26612/in.gappi.gappichat D/SMACK: XMPPConnection closed due to an exception (0)

    06-20 15:42:37.714 26369-26612/in.gappi.gappichat W/System.err: java.net.SocketException: recvfrom failed: ETIMEDOUT (Connection timed out)

    06-20 15:42:37.714 26369-26612/in.gappi.gappichat W/System.err:     at libcore.io.IoBridge.maybeThrowAfterRecvfrom(IoBridge.java:592)

    06-20 15:42:37.714 26369-26612/in.gappi.gappichat W/System.err:     at libcore.io.IoBridge.recvfrom(IoBridge.java:556)

    .....

    .....

    06-20 15:42:38.714 26369-26829/in.gappi.gappichat D/GappiXmpp: Reconnecting 10

    06-20 15:42:38.714 26369-26829/in.gappi.gappichat D/SMACK: XMPPConnection (0) will reconnect in 10

    .....

    06-20 15:42:48.724 26369-26829/in.gappi.gappichat D/GappiXmpp: Reconnecting 0

    06-20 15:42:48.724 26369-26829/in.gappi.gappichat D/SMACK: XMPPConnection (0) will reconnect in 0

    06-20 15:42:48.894 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <stream:stream xmlns='jabber:client' to='gappi.in' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='9739937980@gappi.in' xml:lang='en'>

    06-20 15:42:48.984 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='11040239326876846172' from='gappi.in' version='1.0' xml:lang='en'>

    06-20 15:42:48.984 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='PXc8x7mNN6cEIZgjsEishHW4d3E='/><register xmlns='http://jabber.org/features/iq-register'/><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism><mech anism>SCRAM-SHA-1</mechanism><mechanism>PLAIN</mechanism><mechanism>X-OAUTH2</me chanism></mechanisms></stream:features>

    06-20 15:42:48.994 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='SCRAM-SHA-1'>biwsbj05NzM5OTM3OTgwLHI9QncuaHNmXV8lOGAyInQzTEJacnpkXmB PVCR3Rl90J0M=</auth>

    06-20 15:42:49.094 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cj1Cdy5oc2ZdXyU4YDIidDNMQlpyemReYE9UJH dGX3QnQ0RsUkhLTTRJU2V5ZG1LNGtSRThva3c9PSxzPUpJemJtbXAxaExzRFNZV042M1EyK0E9PSxpPT QwOTY=</challenge>

    06-20 15:42:49.264 26369-26388/in.gappi.gappichat I/art: Background partial concurrent mark sweep GC freed 90062(4MB) AllocSpace objects, 20(540KB) LOS objects, 32% free, 33MB/49MB, paused 1.826ms total 137.089ms

    06-20 15:42:49.564 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>Yz1iaXdzLHI9QncuaHNmXV8lOGAyInQzTEJacn pkXmBPVCR3Rl90J0NEbFJIS000SVNleWRtSzRrUkU4b2t3PT0scD16UXpxR2xVeDArTnF1M1lERkxhN2 lubXphNnc9</response>

    06-20 15:42:49.654 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dj1vdHAxTGtUVVZMZW1GdEVLOXdmZWlqQTdWK1 E9</success>

    06-20 15:42:49.654 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <stream:stream xmlns='jabber:client' to='gappi.in' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='9739937980@gappi.in' id='11040239326876846172' xml:lang='en'>

    06-20 15:42:49.654 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <resume xmlns='urn:xmpp:sm:3' h='2' previd='g2gCbQAAAAVTbWFja2gDYgAABbpiAAbIgmIAAAIt'/>

    06-20 15:42:49.734 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <?xml version='1.0'?><stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' id='5567512457513756075' from='gappi.in' version='1.0' xml:lang='en'>

    06-20 15:42:49.734 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <stream:features><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='PXc8x7mNN6cEIZgjsEishHW4d3E='/><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'/><session xmlns='urn:ietf:params:xml:ns:xmpp-session'><optional/></session><sm xmlns='urn:xmpp:sm:2'/><sm xmlns='urn:xmpp:sm:3'/><csi xmlns='urn:xmpp:csi:0'/></stream:features>

    06-20 15:42:49.814 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <resumed xmlns='urn:xmpp:sm:3' h='2' previd='g2gCbQAAAAVTbWFja2gDYgAABbpiAAbIgmIAAAIt'/>

    06-20 15:42:49.814 26369-26829/in.gappi.gappichat D/SMACK: User logged (0): 9739937980@gappi.in:5222/Smack

    06-20 15:42:49.814 26369-27616/in.gappi.gappichat D/SMACK: RECV (0): <r xmlns='urn:xmpp:sm:3'/>

    06-20 15:42:49.814 26369-26829/in.gappi.gappichat D/SMACK: XMPPConnection authenticated (0) and resumed

    06-20 15:42:49.814 26369-27615/in.gappi.gappichat D/SMACK: SENT (0): <a xmlns='urn:xmpp:sm:3' h='2'/>

    06-20 15:42:49.824 26369-26829/in.gappi.gappichat D/SMACK: XMPPConnection connected (0)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat D/GappiXmpp: ReconnectionFailed!

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err: org.jivesoftware.smack.SmackException$AlreadyLoggedInException: Client is already logged in

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.tcp.XMPPTCPConnection.throwAlreadyLoggedInExceptionIfApp ropriate(XMPPTCPConnection.java:358)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.AbstractXMPPConnection.login(AbstractXMPPConnection.java :452)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.AbstractXMPPConnection.login(AbstractXMPPConnection.java :414)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectInternal(XMPPTCPConnection. java:863)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.AbstractXMPPConnection.connect(AbstractXMPPConnection.ja va:364)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at org.jivesoftware.smack.ReconnectionManager$2.run(ReconnectionManager.java:241)

    06-20 15:42:49.834 26369-26829/in.gappi.gappichat W/System.err:     at java.lang.Thread.run(Thread.java:818)

 

At times `06-20 15:42:48.894` and `06-20 15:42:49.654` two different `<stream/>` stanzas are sent, which ultimately cause the exception later on. Is there any reason for such behavior? My client side xmpp code looks like this:

 

      XMPPTCPConnectionConfiguration connConfig = XMPPTCPConnectionConfiguration.builder().setHost(serverAddress)
                .setPort(5222).setDebuggerEnabled(true).setSecurityMode(ConnectionConfiguration.SecurityMode.disabled)
                .setUsernameAndPassword(loginUser, passwordUser).setServiceName(serverAddress).build();
        XMPPTCPConnection.setUseStreamManagementDefault(true);
        XMPPTCPConnection.setUseStreamManagementResumptionDefault(true);
        connection = new XMPPTCPConnection(connConfig);
        connection.setUseStreamManagement(true);
        connection.setUseStreamManagementResumption(true);

        XMPPConnectionListener connectionListener = new XMPPConnectionListener();
        connection.addConnectionListener(connectionListener);
        connection.setPacketReplyTimeout(10000);
        connection.addStanzaAcknowledgedListener(new StanzaListener() {
            @Override
            public void processPacket(Stanza packet) throws SmackException.NotConnectedException {
                String id = packet.getStanzaId();
                if (StringUtils.isNullOrEmpty(id)) {
                    return;
                }
                stanzaAcknowledged(id);
            }
        });

        ReconnectionManager reconnectionManager = ReconnectionManager.getInstanceFor(connection);
        reconnectionManager.setEnabledPerDefault(true);
        reconnectionManager.enableAutomaticReconnection();

Outcomes