Below described the process on aTalk test observation, and finally find a solution to fix both the problems.
Basically there are two major problems observed on aTalk, and need to be fixed.
1a. aTalk set smack relay timer cannot be guaranteed when the function is being executed in Async.go()
1b. aTalk is having problem with NoResponseException, and endless loop in executing
PepEventListener pepOmemoDeviceListEventListener
and eventually crashes smack with InvalidXmlException.
Finally aTalk decided to make local changes, replacing the 2 files in smack-omemo library i.e.
2a. OmemoManager.java and
2b. OmemoService.java classes
// ===== OmemoManager.java changes are shown here ==========
public static final int SMACK_REPLY_OMEMO_PUBLISH = 15000;
private Set<Integer> publishedDeviceList;
/**
* Initializes the OmemoManager. This method must be called before the manager can be used.
*
* @throws CorruptedOmemoKeyException if the OMEMO key is corrupted.
* @throws InterruptedException if the calling thread was interrupted.
* @throws SmackException.NoResponseException if there was no response from the remote entity.
* @throws SmackException.NotConnectedException if the XMPP connection is not connected.
* @throws XMPPException.XMPPErrorException if there was an XMPP error returned.
* @throws SmackException.NotLoggedInException if the XMPP connection is not authenticated.
* @throws PubSubException.NotALeafNodeException if a PubSub leaf node operation was attempted on a non-leaf node.
* @throws IOException if an I/O error occurred.
*/
public synchronized void initialize()
throws SmackException.NotLoggedInException, CorruptedOmemoKeyException, InterruptedException,
SmackException.NoResponseException, SmackException.NotConnectedException, XMPPException.XMPPErrorException,
PubSubException.NotALeafNodeException, IOException {
if (!connection().isAuthenticated()) {
throw new SmackException.NotLoggedInException();
}
if (getTrustCallback() == null) {
throw new IllegalStateException("No TrustCallback set.");
}
LOGGER.log(Level.INFO, "Start OmemoManager.initialize()");
getConnection().setReplyTimeout(SMACK_REPLY_OMEMO_PUBLISH);
getOmemoService().init(new LoggedInOmemoManager(this));
}
/**
* Initialize the manager without blocking. Once the manager is successfully initialized, the finishedCallback will
* be notified. It will also get notified, if an error occurs.
*
* @param finishedCallback callback that gets called once the manager is initialized.
*/
public void initializeAsync(final InitializationFinishedCallback finishedCallback) {
Async.go(new Runnable() {
@Override
public void run() {
try {
initialize();
finishedCallback.initializationFinished(OmemoManager.this);
} catch (Exception e) {
finishedCallback.initializationFailed(e);
}
getConnection().setReplyTimeout(SmackConfiguration.getDefaultReplyTimeout());
}
});
}
@SuppressWarnings("UnnecessaryLambda")
private final PepEventListener<OmemoDeviceListElement> pepOmemoDeviceListEventListener =
(from, receivedDeviceList, id, message) -> {
// Device List <list>
OmemoCachedDeviceList deviceList;
try {
getOmemoService().getOmemoStoreBackend().mergeCachedDeviceList(getOwnDevice(), from,
receivedDeviceList);
if (!from.asBareJid().equals(getOwnJid())) {
return;
}
deviceList = getOmemoService().cleanUpDeviceList(getOwnDevice());
} catch (IOException e) {
LOGGER.log(Level.SEVERE,
"IOException while processing OMEMO PEP device updates. Message: " + message,
e);
return;
}
final OmemoDeviceListElement_VAxolotl newDeviceList = new OmemoDeviceListElement_VAxolotl(deviceList);
if (!newDeviceList.copyDeviceIds().equals(receivedDeviceList.copyDeviceIds())
&& !newDeviceList.copyDeviceIds().equals(publishedDeviceList)) {
LOGGER.log(Level.FINE, "Republish deviceList due to changes:" +
" Received: " + Arrays.toString(receivedDeviceList.copyDeviceIds().toArray()) +
" Published: " + Arrays.toString(newDeviceList.copyDeviceIds().toArray()));
Async.go(new Runnable() {
@Override
public void run() {
try {
LOGGER.log(Level.INFO, "received (new) DeviceList: " + receivedDeviceList.getDeviceIds()
+ " (" + newDeviceList.getDeviceIds() + ")");
getConnection().setReplyTimeout(SMACK_REPLY_OMEMO_PUBLISH);
OmemoService.publishDeviceList(connection(), newDeviceList);
publishedDeviceList = newDeviceList.copyDeviceIds();
} catch (InterruptedException | XMPPException.XMPPErrorException |
SmackException.NotConnectedException | SmackException.NoResponseException | PubSubException.NotALeafNodeException e) {
LOGGER.log(Level.WARNING, "Could not publish our deviceList upon an received update.", e);
}
getConnection().setReplyTimeout(SmackConfiguration.getDefaultReplyTimeout());
}
});
}
};
Originally, aTalk first attempt is to change only one class file i.e. OmemoManager.java.
#1b. Stop further process of pubsub#event send from server, once it was handled successfully.
This was resolved with the introduction of publishedDeviceList. From test result, xmpp server sends a total of 15 x pubsub#event, upon aTalk successfully process the event after the third event, all the subsequent events are ignored. This fixes the #1b issue.
#1a. Move the setReplyTimeout just before calling, however was found not working.
getOmemoService().init(new LoggedInOmemoManager(this));
The set value can still be reset to 5s by other aTalk stanza processes;
there is about 2.9s between setReplyTimeout() and the actually stanza data being sent.
Eventually the setReplyTimeout() has to be moved to OmemoService.java class to get it to work properly.
See below source and test results.
May be the smack team would consider to implement the same or equivalant in the smack standard library.
==== TEST RESULT ====
// =============== OmemoManager#initialize ======================
11:25:34.588 I [2153] org.jivesoftware.smackx.omemo.OmemoManager.initialize() Start OmemoManager.initialize()
11:25:37.399 I [2171] org.jivesoftware.smackx.omemo.OmemoService.publishBundle() Start OmemoService.publishBundle()
11:25:37.778 D SENT (0):
<iq id='G5WU2-18' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item>
<bundle xmlns='eu.siacs.conversations.axolotl'>
<signedPreKeyPublic signedPreKeyId='91'>
BQKKWZbgrtIegXEYQ2V+nkxk4ArSPZ0vemsuydBZ7IJM
</signedPreKeyPublic>
<signedPreKeySignature>
v8SmtxT3bq2f6oZYpz3tIoZ5n2Z4SsKANoOnJhPOyKr3WLZMZold3451xlwos9nuF8UUokDyz0GyYEPQBlhRhA==
</signedPreKeySignature>
<identityKey>
BX5UMfOGUCKZEn41j44IIPDNag53yAk58fnbP7obdehB
</identityKey>
.....
<preKeyPublic preKeyId='133'>
BX9ydZfIYpR8Cxq9BXKPyeRl402eyeoFp9Pq/p9GC0Mh
</preKeyPublic>
</prekeys>
</bundle>
</item>
</publish>
</pubsub>
</iq>
11:25:42.642 W OmemoManager init failed: No response received within reply timeout. Timeout was 5000ms (~5s). StanzaCollector has been cancelled. Waited for response using: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=G5WU2-18)), : fromFilter (OrFilter: (FromMatchesFilter (full): null, FromMatchesFilter (ignoreResourcepart): swordfish@atalk.sytes.net, FromMatchesFilter (full): atalk.sytes.net)).
11:25:44.719 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='G5WU2-18'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item id='6ACB5EB795147'/>
</publish>
</pubsub>
</iq>
// =============== aTalk home server send pubsub#event a total of 15x of the stanza below. The new fix limits the response to only 3.======================
11:25:36.864 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5A651CD16'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
11:25:37.331 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5A651CD16'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk-amb0rd' type='replyto'/>
</addresses>
</message>
11:25:37.483 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5A651CD16'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
11:25:42.796 I [2166] org.jivesoftware.smackx.omemo.OmemoManager.run() received (new) DeviceList: [327058251] ([327058251, 646419288])
11:25:42.818 I [2167] org.jivesoftware.smackx.omemo.OmemoManager.run() received (new) DeviceList: [327058251] ([327058251, 646419288])
11:25:42.890 D SENT (0):
<iq id='G5WU2-23' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</publish>
</pubsub>
</iq>
<iq id='G5WU2-24' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</publish>
</pubsub>
</iq>
11:25:42.946 I [2168] org.jivesoftware.smackx.omemo.OmemoManager.run() received (new) DeviceList: [327058251] ([327058251, 646419288])
11:25:42.964 D SENT (0):
<iq id='G5WU2-26' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</publish>
</pubsub>
</iq>
11:25:46.057 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='G5WU2-23'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB8F08D0'/>
</publish>
</pubsub>
</iq>
11:25:46.086 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB8F08D0'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
11:25:46.125 D RECV (0):
<message to='swordfish@atalk.sytes.net' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB920AD'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
11:25:46.148 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='G5WU2-24'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB920AD'/>
</publish>
</pubsub>
</iq>
11:25:46.166 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB920AD'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
11:25:46.323 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='G5WU2-26'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB992F0'/>
</publish>
</pubsub>
</iq>
11:25:46.368 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB992F0'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
<device id='646419288'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk' type='replyto'/>
</addresses>
</message>
// Ignore by aTalk new fix for #4 to #15
#4 11:25:46.418 D RECV (0):
<message to='swordfish@atalk.sytes.net' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB9234D0'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk-amb0rd' type='replyto'/>
</addresses>
</message>
#15 11:25:46.705 D RECV (0):
<message to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='headline'>
<event xmlns='http://jabber.org/protocol/pubsub#event'>
<items node='eu.siacs.conversations.axolotl.devicelist'>
<item id='6ACB5EB961D89'>
<list xmlns='eu.siacs.conversations.axolotl'>
<device id='327058251'/>
</list>
</item>
</items>
</event>
<addresses xmlns='http://jabber.org/protocol/address'>
<address jid='swordfish@atalk.sytes.net/atalk-amb0rd' type='replyto'/>
</addresses>
</message>
// =========== Move setReplyTimeout() to OmemService =================
static void publishBundle(XMPPConnection connection, OmemoDevice userDevice, OmemoBundleElement bundle)
throws XMPPException.XMPPErrorException, SmackException.NotConnectedException, InterruptedException,
SmackException.NoResponseException, NotALeafNodeException {
PepManager pm = PepManager.getInstanceFor(connection);
LOGGER.log(Level.INFO, "Start OmemoService.publishBundle()");
connection.setReplyTimeout(OmemoManager.SMACK_REPLY_OMEMO_PUBLISH);
pm.publish(userDevice.getBundleNodeName(), new PayloadItem<>(bundle));
}
### Test #1
12:44:42.626 I [2173] org.jivesoftware.smackx.omemo.OmemoManager.initialize() Start OmemoManager.initialize()
12:44:45.535 I [2173] org.jivesoftware.smackx.omemo.OmemoService.publishBundle() Start OmemoService.publishBundle()
12:44:45.713 D SENT (0):
<iq id='IW8UA-20' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item>
<bundle xmlns='eu.siacs.conversations.axolotl'>
<signedPreKeyPublic signedPreKeyId='91'>
BQKKWZbgrtIegXEYQ2V+nkxk4ArSPZ0vemsuydBZ7IJM
</signedPreKeyPublic>
.....
<preKeyPublic preKeyId='133'>
BX9ydZfIYpR8Cxq9BXKPyeRl402eyeoFp9Pq/p9GC0Mh
</preKeyPublic>
</prekeys>
</bundle>
</item>
</publish>
</pubsub>
</iq>
12:44:54.019 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='IW8UA-20'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item id='6ACB71455FF8'/>
</publish>
</pubsub>
</iq>
### Test #2
12:48:29.647 I [2168] org.jivesoftware.smackx.omemo.OmemoManager.initialize() Start OmemoManager.initialize()
12:48:32.961 I [2168] org.jivesoftware.smackx.omemo.OmemoService.publishBundle() Start OmemoService.publishBundle()
12:48:33.094 D SENT (0):
<iq id='DQ2X3-24' type='set'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item>
<bundle xmlns='eu.siacs.conversations.axolotl'>
<signedPreKeyPublic signedPreKeyId='91'>
BQKKWZbgrtIegXEYQ2V+nkxk4ArSPZ0vemsuydBZ7IJM
</signedPreKeyPublic>
....
<preKeyPublic preKeyId='133'>
BX9ydZfIYpR8Cxq9BXKPyeRl402eyeoFp9Pq/p9GC0Mh
</preKeyPublic>
</prekeys>
</bundle>
</item>
</publish>
</pubsub>
</iq>
12:48:41.552 D RECV (0):
<iq xml:lang='en' to='swordfish@atalk.sytes.net/atalk' from='swordfish@atalk.sytes.net' type='result' id='DQ2X3-24'>
<pubsub xmlns='http://jabber.org/protocol/pubsub'>
<publish node='eu.siacs.conversations.axolotl.bundles:646419288'>
<item id='6ACB7228659F8'/>
</publish>
</pubsub>
</iq>