-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
FlowMay 22, 2017 2:01 AM (in response to cmeng)
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.
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
FlowMay 22, 2017 7:25 AM (in response to cmeng)
Should be fixed with Don't send 'ask' roster item attribute · Flowdalic/Smack@847890b · GitHub
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
cmeng Jun 8, 2017 9:30 PM (in response to Flow)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)
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
FlowJun 9, 2017 2:39 AM (in response to cmeng)
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
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
cmeng Jun 9, 2017 12:35 PM (in response to Flow)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
-
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
FlowJun 16, 2017 12:56 PM (in response to cmeng)
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.
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
FlowJun 16, 2017 2:39 PM (in response to Flow)
Should be fixed in Smack 4.2.1-SNAPSHOTS and in the upcoming Smack 4.2.1 release.
-
Re: Smack 4.2.0 sends 'ask' attribute in Roster.removeEntry not allowed by RFC6121
cmeng Jun 17, 2017 2:24 AM (in response to Flow)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
-
-
-
-