Smack 4.3.0 Join server chat room receive <presence/> NoResponseException even the response is received

[cmeng]

Followings describe the whole observation while joining a chat room previously created on server by admin. Please refer to the log and the Threads captured for details:

1. Two accounts: babai@example.ru as user and admin@example.ru as contact
2. Chat room on server is puhlya@conference.example.ru
3. User babai initialize the joining of a server chatroom to puhlya@conference.example.ru
4. Server detected the user join chatroom request i.e.<presence> and response correctly; see id=‘gGiY9-106’
5. Server sends occupant update for admin
6. aTalk receives admin <presence> and display “admin: has joined puhlya@conference.example.ru” in chat window.
7. The process seems OK till this far.
8. However 15-Second later, smack throws NoResponseException for id=‘gGiY9-106’

Other info:
a. Occupant.getJid() returns null
b. RoomInfo.getContactJids() throws NPE

Previously aTalk also experienced similar NoResponseException due to incorrectly handling of “vcard-temp:x:update” extension element. This problem has since been corrected. I have even disable the “vcard-temp:x:update” option during this test, but the NoResponseException remains unchanged.

I also setup the same test on jitsi, there is no problem with babai joining the chatroom and muc setup is OK.

I preformed a similar test on my home server for atalk.org service. The NoResponseException does not occur. The problem seems to be server or chatroom on server related. However I am unable to find the cause; any advice on what can be the possible cause or way to find the cause.

============== aTalk log on joining chat room on server ==============
08-30 11:46:33.632 9451-10343/org.atalk.android D/SMACK: SENT (0): <iq to='conference.example.ru' id='gGiY9-107' type='get'><query xmlns='http://jabber.org/protocol/disco#info'></query></iq>
08-30 11:46:33.985 9451-10343/org.atalk.android D/SMACK: SENT (0): <iq to='example.ru' id='gGiY9-108' type='get'><query xmlns='http://jabber.org/protocol/disco#info'></query></iq>
08-30 11:46:34.161 9451-10344/org.atalk.android D/SMACK: RECV (0): <iq type="result" id="gGiY9-107" from="conference.example.ru" to="babai@example.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="conference" name="Публичные чат комнаты" type="text"/><identity category="directory" name="Public Chatroom Search" type="chatroom"/><feature var="http://jabber.org/protocol/muc"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="jabber:iq:search"/><feature var="http://jabber.org/protocol/rsm"/></query></iq>

08-30 11:46:34.165 9451-10343/org.atalk.android D/SMACK: SENT (0): <presence to='puhlya@conference.example.ru/babai' id='gGiY9-106'><x xmlns='http://jabber.org/protocol/muc'></x><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://android.atalk.org' ver='SPANeHrMhKxipyDRRXFZu1T21So='/></presence>
<r xmlns='urn:xmpp:sm:3'/>
08-30 11:46:34.669 9451-10344/org.atalk.android D/SMACK: RECV (0): <r xmlns='urn:xmpp:sm:3' />
08-30 11:46:34.670 9451-10343/org.atalk.android D/SMACK: SENT (0): <a xmlns='urn:xmpp:sm:3' h='33'/>

08-30 11:46:35.084 9451-10344/org.atalk.android D/SMACK: RECV (0): <iq type="result" id="gGiY9-108" from="example.ru" to="babai@example.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="account" type="registered"/><identity category="pubsub" type="pep"/><feature var="http://jabber.org/protocol/pubsub#retrieve-default"/><feature var="http://jabber.org/protocol/pubsub#purge-nodes"/><feature var="vcard-temp"/><feature var="http://jabber.org/protocol/pubsub#subscribe"/><feature var="http://jabber.org/protocol/pubsub#subscription-options"/><feature var="http://jabber.org/protocol/pubsub#create-nodes"/><feature var="http://jabber.org/protocol/pubsub#outcast-affiliation"/><feature var="msgoffline"/><feature var="http://jabber.org/protocol/pubsub#get-pending"/><feature var="http://jabber.org/protocol/pubsub#multi-subscribe"/><feature var="http://jabber.org/protocol/pubsub#presence-notifications"/><feature var="urn:xmpp:ping"/><feature var="jabber:iq:register"/><feature var="http://jabber.org/protocol/pubsub#delete-nodes"/><feature var="http://jabber.org/protocol/pubsub#config-node"/><feature var="http://jabber.org/protocol/pubsub#retrieve-items"/><feature var="http://jabber.org/protocol/pubsub#auto-create"/><feature var="http://jabber.org/protocol/disco#items"/><feature var="http://jabber.org/protocol/pubsub#item-ids"/><feature var="http://jabber.org/protocol/pubsub#meta-data"/><feature var="jabber:iq:roster"/><feature var="http://jabber.org/protocol/pubsub#instant-nodes"/><feature var="http://jabber.org/protocol/pubsub#modify-affiliations"/><feature var="http://jabber.org/protocol/pubsub#persistent-items"/><feature var="http://jabber.org/protocol/pubsub#create-and-configure"/><feature var="http://jabber.org/protocol/pubsub"/><feature var="http://jabber.org/protocol/pubsub#publisher-affiliation"/><feature var="http://jabber.org/protocol/pubsub#access-open"/><feature var="http://jabber.org/protocol/pubsub#retrieve-affiliations"/><feature var="jabber:iq:version"/><feature var="http://jabber.org/protocol/pubsub#retract-items"/><feature var="urn:xmpp:time"/><feature var="http://jabber.org/protocol/pubsub#manage-subscriptions"/><feature var="jabber:iq:privacy"/><feature var="jabber:iq:last"/><feature var="http://jabber.org/protocol/commands"/><feature var="http://jabber.org/protocol/offline"/><feature var="urn:xmpp:carbons:2"/><feature var="http://jabber.org/protocol/address"/><feature var="http://jabber.org/protocol/pubsub#publish"/><feature var="http://jabber.org/protocol/pubsub#collections"/><feature var="http://jabber.org/protocol/pubsub#retrieve-subscriptions"/><feature var="http://jabber.org/protocol/disco#info"/><feature var="jabber:iq:private"/><feature var="http://jabber.org/protocol/rsm"/></query></iq>
08-30 11:46:35.109 9451-10343/org.atalk.android D/SMACK: SENT (0): <iq to='puhlya@conference.example.ru' id='gGiY9-111' type='get'><query xmlns='http://jabber.org/protocol/disco#info'></query></iq>

08-30 11:46:35.493 9451-10344/org.atalk.android D/SMACK: RECV (0): <presence to="babai@example.ru/atalk" from="puhlya@conference.example.ru/admin"><c xmlns="http://jabber.org/protocol/caps" ver="xOD7qc/AVy8G6jenMz3NmW5+rWI=" node="http://conversations.im" hash="sha-1"/><x xmlns="http://jabber.org/protocol/muc#user"><item affiliation="owner" role="moderator"/></x></presence>
08-30 11:46:35.507 9451-10344/org.atalk.android D/SMACK: RECV (0): <presence to="babai@example.ru/atalk" id="gGiY9-106" from="puhlya@conference.example.ru/babai"><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://android.atalk.org" ver="SPANeHrMhKxipyDRRXFZu1T21So="/><x xmlns="http://jabber.org/protocol/muc#user"><item jid="babai@example.ru/atalk" affiliation="none" role="participant"/></x></presence>

08-30 11:46:35.521 9451-10344/org.atalk.android D/SMACK: RECV (0): <a xmlns='urn:xmpp:sm:3' h='35' />

08-30 11:46:36.006 9451-10344/org.atalk.android D/SMACK: RECV (0): <iq type="result" id="gGiY9-111" from="puhlya@conference.example.ru" to="babai@example.ru/atalk"><query xmlns="http://jabber.org/protocol/disco#info"><identity category="conference" name="puhlya" type="text"/><feature var="http://jabber.org/protocol/muc"/><feature var="muc_public"/><feature var="muc_open"/><feature var="muc_unmoderated"/><feature var="muc_semianonymous"/><feature var="muc_unsecured"/><feature var="muc_persistent"/><feature var="http://jabber.org/protocol/disco#info"/><x xmlns="jabber:x:data" type="result"><field var="FORM_TYPE" type="hidden"><value>http://jabber.org/protocol/muc#roominfo</value></field><field var="muc#roominfo_description" label="Описание"><value>example.ru</value></field><field var="muc#roominfo_subject" label="Тема"><value></value></field><field var="muc#roominfo_occupants" label="Количество участников"><value>3</value></field><field var="x-muc#roominfo_creationdate" label="Дата Создания"><value>2017-11-29T19:08:09.419Z</value></field></x></query></iq>

08-30 11:46:49.200 9451-11658/org.atalk.android E/aTalk: [516] impl.protocol.jabber.ChatRoomJabberImpl.joinAs().669 Failed to join room puhlya@conference.example.ru with nickname: babai.
    org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 15000ms (~15s). Waited for response using: AndFilter: (StanzaTypeFilter: Presence, OrFilter: (AndFilter: (FromMatchesFilter (ignoreResourcepart): puhlya@conference.example.ru, MUCUserStatusCodeFilter: status=110), AndFilter: (FromMatchesFilter (full): puhlya@conference.example.ru/babai, StanzaIdFilter: id=gGiY9-106, PresenceTypeFilter: type=error))).
        at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:265)
        at org.jivesoftware.smackx.muc.MultiUserChat.enter(MultiUserChat.java:376)
        at org.jivesoftware.smackx.muc.MultiUserChat.join(MultiUserChat.java:740)
        at org.jivesoftware.smackx.muc.MultiUserChat.join(MultiUserChat.java:631)
        at net.java.sip.communicator.impl.protocol.jabber.ChatRoomJabberImpl.joinAs(ChatRoomJabberImpl.java:624)
        at net.java.sip.communicator.impl.protocol.jabber.ChatRoomJabberImpl.joinAs(ChatRoomJabberImpl.java:595)
        at net.java.sip.communicator.impl.muc.MUCServiceImpl$JoinChatRoomTask.run(MUCServiceImpl.java:517)

[Flow]

Compare

@cmeng

08-30 11:46:35.507 9451-10344/org.atalk.android D/SMACK: RECV (0):

<presence to="babai@example.ru/atalk" id="gGiY9-106" from="puhlya@conference.example.ru/babai">
  <c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://android.atalk.org" ver="SPANeHrMhKxipyDRRXFZu1T21So="/>
  <x xmlns="http://jabber.org/protocol/muc#user"><item jid="babai@example.ru/atalk" affiliation="none" role="participant"/>
  </x>
</presence>

with

@cmeng

08-30 11:46:49.200 9451-11658/org.atalk.android E/aTalk: [516] impl.protocol.jabber.ChatRoomJabberImpl.joinAs().669 Failed to join room puhlya@conference.example.ru with nickname: babai. org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 15000ms (~15s). Waited for response using: AndFilter: (StanzaTypeFilter: Presence, OrFilter: (AndFilter: (FromMatchesFilter (ignoreResourcepart): puhlya@conference.example.ru, MUCUserStatusCodeFilter: status=110), AndFilter: (FromMatchesFilter (full): puhlya@conference.example.ru/babai, StanzaIdFilter: id=gGiY9-106, PresenceTypeFilter: type=error))).

and observe that the returned presence by the service does not contain the 110 status code that the filter expects (among other things). The MUC service implementation is not following specification found in XEP-0045 (like older Openfire versions did).

[cmeng]

Yes, the user server is using openfire. Look like it is the cause of the problem. Thanks for the quick reply.

By the way would smack looking at throwing an exception on malformed stanza instead of NoResponseException, so it provides some flexibility to the app implementation…

[cmeng]

User has just upgraded his openfire service to the latest version 4.2.3. Look the reported problem still exists in the latest revision.

Openfire v4.2.3 does not compliant to XEP-0045: Multi-User Chat - Presence Broadcast standard

Test environment: XMPP client aTalk with smack 4.4.0 with an account registered on example.ru service which runs on openfire v4.2.3: Please refer also to: It is found that openfire v4.2.3 does not compliant to the following standard: XEP-0045: Multi-User Chat - Presence Broadcast specifications (self presence) <presence from='coven@chat.shakespeare.lit/thirdwitch' id='026B3509-2CCE-4D69-96D6-25F41FFDC408' to='hag66@shakespeare.lit/pda'> <x xmlns='http://jabber.org/protocol/…