carlosCharz / fcmxmppserverv2

XMPP Connection Server for FCM using the latest version of the Smack library (4.3.4) + Connection Draining Implementation
47 stars 33 forks source link

SmackException$NoResponseException #6

Closed long1eu closed 7 years ago

long1eu commented 7 years ago

I started to get this. Any ideas?

/usr/lib/jvm/java-1.8.0-openjdk-amd64/bin/java -javaagent:/home/long1eu/.local/share/JetBrains/Toolbox/apps/IDEA-U/ch-0/171.3780.52/lib/idea_rt.jar=46371:/home/long1eu/.local/share/JetBrains/Toolbox/apps/IDEA-U/ch-0/171.3780.52/bin -Dfile.encoding=UTF-8 -classpath /usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/charsets.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/cldrdata.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/dnsns.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/icedtea-sound.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/jaccess.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/localedata.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/nashorn.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/sunec.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/sunjce_provider.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/sunpkcs11.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/ext/zipfs.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/jce.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/jsse.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/management-agent.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/resources.jar:/usr/lib/jvm/java-1.8.0-openjdk-amd64/jre/lib/rt.jar:/home/long1eu/Desktop/fcmxmppserverv2-master/target/classes:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-java7/4.1.9/smack-java7-4.1.9.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-core/4.1.9/smack-core-4.1.9.jar:/home/long1eu/.m2/repository/xpp3/xpp3/1.1.4c/xpp3-1.1.4c.jar:/home/long1eu/.m2/repository/org/jxmpp/jxmpp-core/0.4.2/jxmpp-core-0.4.2.jar:/home/long1eu/.m2/repository/org/jxmpp/jxmpp-util-cache/0.4.2/jxmpp-util-cache-0.4.2.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-resolver-javax/4.1.9/smack-resolver-javax-4.1.9.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-sasl-javax/4.1.9/smack-sasl-javax-4.1.9.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-tcp/4.1.9/smack-tcp-4.1.9.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-extensions/4.1.9/smack-extensions-4.1.9.jar:/home/long1eu/.m2/repository/org/igniterealtime/smack/smack-im/4.1.9/smack-im-4.1.9.jar:/home/long1eu/.m2/repository/com/googlecode/json-simple/json-simple/1.1.1/json-simple-1.1.1.jar com.wedevol.xmpp.EntryPoint
09:40:36 PM SENT (0): <stream:stream xmlns='jabber:client' to='FCM XMPP Client Connection Server' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
09:40:37 PM RECV (0): <stream:stream from="FCM XMPP Client Connection Server" id="8E67FC6D5490BA24" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">
09:40:37 PM RECV (0): <stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>X-OAUTH2</mechanism><mechanism>X-GOOGLE-TOKEN</mechanism><mechanism>PLAIN</mechanism></mechanisms></stream:features>
09:40:37 PM SENT (0): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='PLAIN'>ADk1NTYxODM1OTYxOUBnY20uZ29vZ2xlYXBpcy5jb20AQUFBQTNuOUstVU06QVBBOTFiRllOVzlFMnYxRXNFS3FfbjBDaTlWOWZxaVRleU5aSkJsYjJEdk1yXzRJdVRLUjlTR2RPNTBiM01pelRTbng3VU0zNDU3NW1RaHNXQkRUaHFMVnRhaks1ZTkzRFliV1oyWURYTjZ1UFJfd01LV2lQbVh5SmZnUGx1SDhVd2dRdTZwSGl0UGQ=</auth>
09:40:37 PM RECV (0): <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>
09:40:37 PM SENT (0): <stream:stream xmlns='jabber:client' to='FCM XMPP Client Connection Server' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='8E67FC6D5490BA24' xml:lang='en'>
09:40:37 PM RECV (0): <stream:stream from="FCM XMPP Client Connection Server" id="CF195EA8A5FA80DC" version="1.0" xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client">
09:40:37 PM RECV (0): <stream:features><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features>
09:40:37 PM SENT (0): <iq id='4MHY9-3' type='set'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><resource>Smack</resource></bind></iq>
Mar 16, 2017 9:40:37 PM com.wedevol.xmpp.server.CcsClient$4 processPacket
INFO: Sent: {}
09:40:37 PM RECV (0): <iq id="4MHY9-3" type="result"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>955618359619@gcm.googleapis.com/SmackE5840541</jid></bind></iq>
09:40:37 PM RECV (0):  
Mar 16, 2017 9:40:37 PM com.wedevol.xmpp.server.CcsClient$4 processPacket
INFO: Sent: {}
09:40:37 PM SENT (0): <iq id='4MHY9-5' type='set'><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/></iq>
09:40:37 PM RECV (0): <iq type="result" id="4MHY9-5"/>
09:40:37 PM User logged (0): 955618359619@gcm.googleapis.com:5236/SmackE5840541
Mar 16, 2017 9:40:37 PM com.wedevol.xmpp.server.CcsClient$4 processPacket
INFO: Sent: {}
Mar 16, 2017 9:40:37 PM com.wedevol.xmpp.server.CcsClient$2 authenticated
INFO: User authenticated
Mar 16, 2017 9:40:37 PM com.wedevol.xmpp.server.CcsClient connect
INFO: Logged in: 955618359619@gcm.googleapis.com
09:40:37 PM SENT (0): <iq id='4MHY9-7' type='get'><query xmlns='jabber:iq:roster'></query></iq>
09:40:37 PM XMPPConnection authenticated (0)
Mar 16, 2017 9:40:42 PM org.jivesoftware.smack.roster.Roster$3 processException
SEVERE: Exception reloading roster
org.jivesoftware.smack.SmackException$NoResponseException: No response received within reply timeout. Timeout was 5000ms (~5s). Used filter: IQReplyFilter: iqAndIdFilter (AndFilter: (OrFilter: (IQTypeFilter: type=error, IQTypeFilter: type=result), StanzaIdFilter: id=4MHY9-7)), : fromFilter (OrFilter: (FromMatchesFilter (full): null, FromMatchesFilter (bare): 955618359619@gcm.googleapis.com, FromMatchesFilter (full): gcm.googleapis.com)).
    at org.jivesoftware.smack.SmackException$NoResponseException.newWith(SmackException.java:106)
    at org.jivesoftware.smack.AbstractXMPPConnection$6.run(AbstractXMPPConnection.java:1448)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
carlosCharz commented 7 years ago

It is an error that I am having as well but it does not block the incoming messages. Everything work well after this. Put a lower number in the ping time and you should see something like this after that stacktrace error:

09:14:16 AM SENT (0): 09:14:16 AM RECV (0):

It means that your server is alive listening for messages!

long1eu commented 7 years ago

ok, thanks

AgentLV commented 7 years ago

I got the exception removed by adding Roster.getInstanceFor(connection).setRosterLoadedAtLogin(false); in line 107 in the CcsClient class

carlosCharz commented 7 years ago

That's amazing @AgentLV I am gonna commit that to the master branch. Thank you!

spyzip commented 6 years ago

setRosterLoadedAtLogin - this dose not remove the exception, you just don't see it first time, if you try to reload the roster, it is there again.

It looks like more like a problem with the presence stanza not being processed right

carlosCharz commented 6 years ago

Did you try id with this new code? Because I applied that and the problem was solved. Can you test with this latest release if this works for you?