AnsweredAssumed Answered

Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121

Question asked by cmeng on May 21, 2017
Latest reply on Jun 16, 2017 by cmeng

Like • Show 0 Likes0
Comment • 8

While testing aTalk, trying to remove a roster entry using the method below:

roster.removeEntry(entry);

Note: the entry is still pending subscription authorization from the contact.

Smack 4.2.0 sends an <query xmlns='jabber:iq:roster'> with 'ask' attribute in <item/> which is not allow as per RFC6121 document

================ RFC6121 section 2.1.2.2 extraction =================

2.1.2.2. Ask Attribute

The 'ask' attribute of the <item/> element with a value of

"subscribe" is used to signal various subscription sub-states that

include a "Pending Out" aspect as described under Section 3.1.2.

A server SHOULD include the 'ask' attribute to inform the client of

"Pending Out" sub-states. A client MUST NOT include the 'ask'

attribute in the roster sets it sends to the server, but instead MUST

use presence stanzas of type "subscribe" and "unsubscribe" to manage

such sub-states as described under Section 3.1.2.

========= SMACK Error Log ======================

05-21 16:59:33.441 D/SMACK: SENT (1): <iq id='w2HYF-301' type='set'><query xmlns='jabber:iq:roster'><item jid='abc123@atalk.org' name='abc123.atalk' subscription='remove' ask='subscribe'><group>atalk member</group></item></query></iq>

05-21 16:59:33.851 D/SMACK: RECV (1): <iq xml:lang='en' to='abc123@jabbim.com/atalk' from='abc123@jabbim.com' type='error' id='w2HYF-301'><query xmlns='jabber:iq:roster'><item ask='subscribe' subscription='remove' name='abc123.atalk' jid='abc123@atalk.org'><group>atalk member</group></item></query><error code='400' type='modify'><bad-request xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/><text xml:lang='en' xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'>Possessing 'ask' attribute is not allowed by RFC6121</text></error></iq>

No one else has this question

Outcomes

8 Replies

Flow May 22, 2017 2:01 AM
Mark Correct
Correct Answer
Excellent bug report. Created [SMACK-766] Smack possibly includes 'ask' attribute in roster items when sending requests - IgniteRealtime JIRA.
Will be fixed in Smack 4.2.1.
Like • Show 0 Likes0
Actions
Flow May 22, 2017 7:25 AM
Mark Correct
Correct Answer
Should be fixed with Don't send 'ask' roster item attribute · Flowdalic/Smack@847890b · GitHub
Like • Show 0 Likes0
Actions
- cmeng @ Flow on Jun 8, 2017 9:30 PM
  Mark Correct
  Correct Answer
  I have just tested the latest SNAPSHOT released on Jun 5, 2017. Although the problem on the 'ask' attribute has been corrected, the capture log still shows response timeout?
  
  I have checked the log on the server, there is no related error reported, and the contact that has been removed is also properly deleted from its database. However this problem does not happen when performed on an earlier registered account. Strange? Look like I really need to get to the root cause of the response timeout on other scenarios.
  
  Any ideas?
  
  ================== aTalk - Contact (waiting for authorization) removal log ======================
  06-09 11:01:09.816 D/SMACK: SENT (0): <iq id='4MH5l-82' type='set'><query xmlns='jabber:iq:roster'><item jid='abc123@atalk.org' name='abc123@atalk.org' subscription='remove'><group>friends</group></item></query></iq>
  06-09 11:01:09.936 D/SMACK: RECV (0): <iq to='newx@atalk.org/atalk' from='newx@atalk.org' type='set' id='push13559684941514785749'><query ver='f64161520b7c9c038747ee5e36769fcbd52aca29' xmlns='jabber:iq:roster'><item subscription='remove' jid='abc123@atalk.org'/></query></iq>
  06-09 11:01:09.936 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='4MH5l-82'/>
  06-09 11:01:14.816 W/System.err: org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 5000ms (~5s). Waited for response using: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=4MH5l-82)), : fromFilter (OrFilter: (FromMatchesFilter (full): null, FromMatchesFilter (ignoreResourcepart): newx@atalk.org, FromMatchesFilter (full): atalk.org)).
  06-09 11:01:14.836 W/System.err:     at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:2 53)
  06-09 11:01:14.836 W/System.err:     at org.jivesoftware.smack.StanzaCollector.nextResultOrThrow(StanzaCollector.java:2 08)
  06-09 11:01:14.836 W/System.err:     at org.jivesoftware.smack.roster.Roster.removeEntry(Roster.java:752)
  06-09 11:01:14.836 W/System.err:     at net.java.sip.communicator.impl.protocol.jabber.ServerStoredContactListJabberImp l.removeContact(ServerStoredContactListJabberImpl.java:751)
  06-09 11:01:14.836 W/System.err:     at net.java.sip.communicator.impl.protocol.jabber.OperationSetPersistentPresenceJa bberImpl.unsubscribe(OperationSetPersistentPresenceJabberImpl.java:799)
  06-09 11:01:14.836 W/System.err:     at net.java.sip.communicator.impl.contactlist.MetaContactListServiceImpl.removeCon tact(MetaContactListServiceImpl.java:1068)
  06-09 11:01:14.836 W/System.err:     at net.java.sip.communicator.impl.contactlist.MetaContactListServiceImpl.removeMet aContact(MetaContactListServiceImpl.java:1106)
  06-09 11:01:14.836 W/System.err:     at org.atalk.android.gui.contactlist.MetaContactListManager$2.run(MetaContactListM anager.java:81)
  06-09 11:01:14.836 W/System.err:     at java.lang.Thread.run(Thread.java:818)
  Like • Show 0 Likes0
  Actions
  - Flow @ cmeng on Jun 9, 2017 2:39 AM
    Mark Correct
    Correct Answer
    There appears to be an issue with IQ requests to the user's account. I've created [SMACK-768] Smack throws NoResponse timeout when waiting for IQ although there was a response - IgniteRealtime JIRA
    Like • Show 0 Likes0
    Actions
    - cmeng @ Flow on Jun 9, 2017 12:35 PM
      Mark Correct
      Correct Answer
      I did further testing on the response timeout issue. Upon execution break on
      setCarbonsEnabled##connection().createStanzaCollectorAndSend(setIQ).nextResultOr Throw();
      I place two more break points br#1 and br#2 in the following method; and caught it reaches br#1. Below is the captured debug variables when this happens. I checked through the packetFilter, and seems it is being correctly set, however the result == null although the correct IQ result has already been received. It looks like the problem is within the nextResult(timeout);
      
      Another observation is that the reply is received 10mS after sending the IQ-set. Will there be a race condition; where under this case the StanzaCollector is slow in the preparation to receive the IQ-result.
      
      I did more testings, capturing instances for passed and failed cases (see log below). Based on the measured data, it seems ~110mS is the pivot point for pass or fail.
      
      -----------------------------
      public <P extends Stanza> P nextResultOrThrow(long timeout) throws NoResponseException,
         XMPPErrorException, InterruptedException, NotConnectedException {
         P result = nextResult(timeout);
         cancel();
         if (result == null) {
         if (!connection.isConnected()) {
         throw new NotConnectedException(connection, packetFilter);
         }
      br#1   throw NoResponseException.newWith(connection, this);
         }
         XMPPErrorException.ifHasErrorThenThrow(result);
      br#2   return result;
      }
      
      ============ aTalk debug log to enable carbon ===================
      06-10 02:35:58.126 D/SMACK: SENT (0): <iq id='26c6I-69' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq>
      06-10 02:35:58.136 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='26c6I-69'/>
      
      ============= aTalk debug variable =================
      result = null
      packetFilter = {IQReplyFilter@22283} "IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=26c6I-69)), : fromFilter (OrFilter: (FromMatchesFilter (full): null, FromMatchesFilter (ignoreResourcepart): newx@atalk.org, FromMatchesFilter (full): atalk.org))"
      fromFilter = {OrFilter@22287} "OrFilter: (FromMatchesFilter (full): null, FromMatchesFilter (ignoreResourcepart): newx@atalk.org, FromMatchesFilter (full): atalk.org)"
      iqAndIdFilter = {AndFilter@22288} "AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=26c6I-69)"
      local = {LocalDomainAndResourcepartJid@22289} "newx@atalk.org/atalk"
      packetId = "26c6I-69"
      server = {DomainpartJid@22291} "atalk.org"
      to = null
      shadow$_klass_ = {Class@22151} "class org.jivesoftware.smack.filter.IQReplyFilter"
      shadow$_monitor_ = -1123969654
      
      ==================================================================
      ============ aTalk debug for carbon enabled passed/failed cases based on reply time ===============
      06-10 03:16:51.786 D/SMACK: SENT (0): <iq id='52KFZ-74' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq>
      06-10 03:16:51.896 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='52KFZ-74'/>
      06-10 03:16:51.906 I/αTalk: [11] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().678 Successfully setting carbon new state for: newx@atalk.org/atalk to true
      
      06-10 03:19:37.226 D/SMACK: SENT (0): <iq id='15ajs-69' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq>
      06-10 03:19:37.316 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='15ajs-69'/>
      06-10 03:19:42.226 E/αTalk: [14] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().683 Failed to set carbon state for: newx@atalk.org/atalk to true
      
      06-10 03:23:18.216 D/SMACK: SENT (0): <iq id='DzdIF-75' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq>
      06-10 03:23:18.366 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='DzdIF-75'/>
      06-10 03:23:18.366 I/αTalk: [12] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().678 Successfully setting carbon new state for: newx@atalk.org/atalk to true
      
      06-10 03:25:31.686 D/SMACK: SENT (0): <iq id='3qAtg-68' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq>
      06-10 03:25:31.896 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='3qAtg-68'/>
      06-10 03:25:31.906 I/αTalk: [11] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().678 Successfully setting carbon new state for: newx@atalk.org/atalk to true
      
      06-10 03:27:06.766 D/SMACK: SENT (0): <iq id='ArHmR-75' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq><r xmlns='urn:xmpp:sm:3'/>
      06-10 03:27:06.876 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='ArHmR-75'/>
      06-10 03:27:11.776 E/αTalk: [12] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().683 Failed to set carbon state for: newx@atalk.org/atalk to true
      
      06-10 03:29:19.296 D/SMACK: SENT (0): <iq id='6R3bW-75' type='set'><enable xmlns='urn:xmpp:carbons:2'/></iq><r xmlns='urn:xmpp:sm:3'/>
      06-10 03:29:19.386 D/SMACK: RECV (0): <iq xml:lang='en' to='newx@atalk.org/atalk' from='newx@atalk.org' type='result' id='6R3bW-75'/>
      06-10 03:29:24.296 E/αTalk: [13] impl.protocol.jabber.OperationSetBasicInstantMessagingJabberImpl.enableDisableC arbon().683 Failed to set carbon state for: newx@atalk.org/atalk to true
      Like • Show 0 Likes0
      Actions
  - Flow @ cmeng on Jun 16, 2017 12:56 PM
    Mark Correct
    Correct Answer
    Could you create a test account on atalk.org for me and send the me credentials via private message? I'd like to try re-creating the issue.
    Like • Show 0 Likes0
    Actions
    - Flow @ Flow on Jun 16, 2017 2:39 PM
      Mark Correct
      Correct Answer
      Should be fixed in Smack 4.2.1-SNAPSHOTS and in the upcoming Smack 4.2.1 release.
      Like • Show 0 Likes0
      Actions
      - cmeng @ Flow on Jun 17, 2017 2:24 AM
        Mark Correct
        Correct Answer
        I have just tested the latest Smack 4.2.1-SNAPSHOT, I do not encounter anymore problem on response timeout.
        Thanks for the new release
        Like • Show 0 Likes0
        Actions

Incoming Links

Re: Smack OmemoManager.purgeDevices() throws NoResponseException prior to sending the stanza

Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121

Outcomes

Related Content

Recommended Content

Incoming Links