False warning logged by Roster while disconnecting

Smack Smack Dev
1

While tearing down a connection, Smack sometimes logs:

Roster not loaded while processing

This is triggered by the PresencePacketListener in the Roster class. When logging out, setOfflinePresencesAndResetLoaded resets the rosterState field, making isLoaded() return false.

private class PresencePacketListener implements StanzaListener {

    @Override
    public void processStanza(Stanza packet) throws NotConnectedException, InterruptedException {
        // Try to ensure that the roster is loaded when processing presence stanzas. While the
        // presence listener is synchronous, the roster result listener is not, which means that
        // the presence listener may be invoked with a not yet loaded roster.
        if (rosterState == RosterState.loading) {
            try {
                waitUntilLoaded();
            }
            catch (InterruptedException e) {
                LOGGER.log(Level.INFO, "Presence listener was interrupted", e);

            }
        }
        if (!isLoaded() && rosterLoadedAtLogin) {
            LOGGER.warning("Roster not loaded while processing " + packet);
        }

There is no functional impact, but having a warning logged does not seem approriate in this case.

2

The presence stanza that was triggering this problem for me is the initial presence sent by org.jivesoftware.smack.AbstractXMPPConnection#afterSuccessfulLogin

// Set presence to online. It is important that this is done after
// callConnectionAuthenticatedListener(), as this call will also
// eventually load the roster. And we should load the roster before we
// send the initial presence.
if (config.isSendPresence() && !resumed) {
    Presence availablePresence = getStanzaFactory()
                    .buildPresenceStanza()
                    .ofType(Presence.Type.available)
                    .build();
    sendStanza(availablePresence);
}

If a Smack connection is shut down quickly enough (for example, when performing a test), then the echo from that initial presence causes the warning to be logged.

Note that the code above does not wait for the initial presence to be echo’d back. I have confirmed that by doing so (using the snippet below), the warning no longer gets logged:

// Set presence to online. It is important that this is done after
// callConnectionAuthenticatedListener(), as this call will also
// eventually load the roster. And we should load the roster before we
// send the initial presence.
if (config.isSendPresence() && !resumed) {
    Presence availablePresence = getStanzaFactory()
                    .buildPresenceStanza()
                    .ofType(Presence.Type.available)
                    .build();
    StanzaCollector packetCollector = createStanzaCollectorAndSend(new StanzaIdFilter(availablePresence), availablePresence);
    packetCollector.nextResult();
    sendStanza(availablePresence);
}

I’m not to sure if I like this approach. It feels needlessly delaying to synchronously wait for the initial presence to be echo’d back.

3

Thanks for the detailed report. Created SMACK-941 and

as proposed fix.

1 Like