Subscription crashing application due to "java.util.NoSuchElementException" exception

[SahajRana]

Describe the bug
Subscription crashing application due to "AppSyncSubscriptionCall$Callback.onCompleted()" on a null object reference, after some time of using subscription on cancel.

Error

02-09 12:22:37.718 5278-5964/com.rana.sahaj.myyu E/AndroidRuntime: FATAL EXCEPTION: Thread-90
    Process: com.rana.sahaj.myyu, PID: 5278
    java.lang.NullPointerException: Attempt to invoke interface method 'void com.amazonaws.mobileconnectors.appsync.AppSyncSubscriptionCall$Callback.onCompleted()' on a null object reference
        at com.apollographql.apollo.internal.RealAppSyncSubscriptionCall$2.run(RealAppSyncSubscriptionCall.java:167)
        at java.lang.Thread.run(Thread.java:760)
02-09 12:22:37.719 5278-5965/com.rana.sahaj.myyu E/AndroidRuntime: FATAL EXCEPTION: Thread-91
    Process: com.rana.sahaj.myyu, PID: 5278
    java.lang.NullPointerException: Attempt to invoke interface method 'void com.amazonaws.mobileconnectors.appsync.AppSyncSubscriptionCall$Callback.onCompleted()' on a null object reference
        at com.apollographql.apollo.internal.RealAppSyncSubscriptionCall$2.run(RealAppSyncSubscriptionCall.java:167)
        at java.lang.Thread.run(Thread.java:760)
02-09 12:22:37.719 5278-5966/com.rana.sahaj.myyu E/AndroidRuntime: FATAL EXCEPTION: Thread-92
    Process: com.rana.sahaj.myyu, PID: 5278
    java.lang.NullPointerException: Attempt to invoke interface method 'void com.amazonaws.mobileconnectors.appsync.AppSyncSubscriptionCall$Callback.onCompleted()' on a null object reference
        at com.apollographql.apollo.internal.RealAppSyncSubscriptionCall$2.run(RealAppSyncSubscriptionCall.java:167)
        at java.lang.Thread.run(Thread.java:760)
02-09 12:22:37.719 5278-5967/com.rana.sahaj.myyu E/AndroidRuntime: FATAL EXCEPTION: Thread-93
    Process: com.rana.sahaj.myyu, PID: 5278
    java.lang.NullPointerException: Attempt to invoke interface method 'void com.amazonaws.mobileconnectors.appsync.AppSyncSubscriptionCall$Callback.onCompleted()' on a null object reference
        at com.apollographql.apollo.internal.RealAppSyncSubscriptionCall$2.run(RealAppSyncSubscriptionCall.java:167)
        at java.lang.Thread.run(Thread.java:760)

Environment(please complete the following information):

• AppSync SDK Version: 2.7.+

Device Information (please complete the following information):
-Checked on Lolipop and Nougat

I think this is happening due to the below closing of subscription.

if (subscriptionWatcher!=null)
            subscriptionWatcher.cancel();

It was working on 2.6.+ version without any problem, I just updated it to 2.7+ version and app started crashing with the above error.

[mutablealligator]

@SahajRana Sorry for the inconvenience caused. By any chance did you encounter the following log message in your Logcat?

Subscription Infrastructure: Callback passed into subscription [" + subscription +"] was null. Will not subscribe.

Can you post a code snippet where you create and invoke the subscription with a callback?

[mutablealligator]

PR #117 fixes this issue. The next upcoming release should include this fix.

[SahajRana]

@kvasukib thanks for the great response!, After I opened the issue I downgraded the version and then, after your request I changed it back to the newer version. But now, I'm not able to find the issue anymore. I think there could be some post upgrading files problem. I will let you guys know if I find it again, cheers!

[mutablealligator]

@SahajRana This fix has been released in 2.7.7 version of the SDK. Please upgrade and let us know any feedback you have.

[SahajRana]

@kvasukib I think this problem is resolved but now I'm getting another error and then app is crashed

02-15 14:46:07.918 29734-31104/com.xxx.xxx V/RealSubscriptionManager: Subscription Infrastructure: Attempting to reconnect
02-15 14:46:07.919 29734-31104/com.xxx.xxx E/AndroidRuntime: FATAL EXCEPTION: Thread-101
    Process: com.xxx.xxx, PID: 29734
    java.util.NoSuchElementException
        at java.util.HashMap$HashIterator.nextEntry(HashMap.java:854)
        at java.util.HashMap$KeyIterator.next(HashMap.java:885)
        at com.amazonaws.mobileconnectors.appsync.subscription.RealSubscriptionManager$3.run(RealSubscriptionManager.java:459)
        at java.lang.Thread.run(Thread.java:760)

[SahajRana]

@kvasukib @cbommas @muellerfr guys, the above error is pretty frequent and crashing an idle application after some time of opening.

[scb01]

@SahajRana
Can you share code snippets of how you are creating the subscription, cancelling it etc., and your logcat? That will help in pinpointing why this crash is happening.

[SahajRana]

@cbommas, @kvasukib, @muellerfr Hey, this error is not easily trackable as it appears randomly, below is the code where the error is

                        //Initiate Retry if required
                        if (subscriptionToRetry != null) {
                            Log.v(TAG, "Subscription Infrastructure: Attempting to reconnect");
                            reconnectCountdownLatch = new CountDownLatch(1);
                 --> mApolloClient.subscribe(subscriptionToRetry.subscription).execute((AppSyncSubscriptionCall.Callback) subscriptionToRetry.getListeners().iterator().next());

                            try {
                                reconnectCountdownLatch.await(1, TimeUnit.MINUTES);
                            } catch (InterruptedException ioe) {
                                Log.v(TAG, "Subscription Infrastructure: Wait interrupted.");
                            }
                        }

Error::

02-23 16:46:14.403 9910-9910/xxx.xxx V/MqttSubscriptionClient: Subscription Infrastructure: Errror [Client is currently disconnecting (32102)] when disconnecting from topic [068151923254/csd4svqhmfedjj3pirtaaguxai/messageListener/a575609906dbeedbc8e68cfaf66e67047d791ab4820a827a67f1d7c3a151c013]
02-23 16:46:14.413 9910-9910/xxx.xxx D/MqttSubscriptionClient: Subscription Infrastructure: Successfully closed the connection. Client ID [n7utpcauqnfqrnp5gzjx4ozt4m]
02-23 16:46:14.413 9910-9910/xxx.xxx V/MqttSubscriptionClient: Subscription Infrastructure: client connection lost for client [n7utpcauqnfqrnp5gzjx4ozt4m]
    Subscription Infrastructure: Transmitting client connection lost for client [n7utpcauqnfqrnp5gzjx4ozt4m]
02-23 16:46:14.413 9910-9910/xxx.xxx V/RealSubscriptionManager: Subscription Infrastructure: onError called com.amazonaws.mobileconnectors.appsync.subscription.SubscriptionDisconnectedException: Client disconnected
02-23 16:46:14.413 9910-9910/xxx.xxx V/RealSubscriptionManager: Subscription Infrastructure: Disconnect received. Unexpected - Initiating reconnect sequence.
02-23 16:46:14.414 9910-9910/xxx.xxx V/RealSubscriptionManager: Subscription Infrastructure: Connection Error reported!
02-23 16:46:14.422 9910-10062/xxx.xxx I/RetryInterceptor: Returning network response: success
02-23 16:46:14.431 9910-10442/xxx.xxx V/RealSubscriptionManager: Subscription Infrastructure: Attempting to reconnect
02-23 16:46:14.432 9910-10442/xxx.xxx E/AndroidRuntime: FATAL EXCEPTION: Thread-100
    Process: com.rana.sahaj.myyu, PID: 9910
    java.util.NoSuchElementException
        at java.util.HashMap$HashIterator.nextEntry(HashMap.java:854)
        at java.util.HashMap$KeyIterator.next(HashMap.java:885)
        at com.amazonaws.mobileconnectors.appsync.subscription.RealSubscriptionManager$3.run(RealSubscriptionManager.java:459)
        at java.lang.Thread.run(Thread.java:760)
02-23 16:46:14.436 9910-10442/xxx.xxx E/SahajLOG008: UNCAUGHT Called

[SahajRana]

@cbommas @kvasukib please have a look as we are moving to production pretty soon so it would be a real problem if the application crashes!

[paulfthomas]

I'm encountering the same issue with the version 2.7.7:

java.util.NoSuchElementException
        at java.util.HashMap$HashIterator.nextEntry(HashMap.java:808)
        at java.util.HashMap$KeyIterator.next(HashMap.java:833)
        at com.amazonaws.mobileconnectors.appsync.subscription.RealSubscriptionManager$3.run(RealSubscriptionManager.java:459)
        at java.lang.Thread.run(Thread.java:841)

Downgrading to 2.7.6 solves it but the initial bug described by @SahajRana reappears.

[scb01]

@SahajRana, @paulfthomas

The latest release of the SDK, 2.7.8, has logic to protect against this crash. The crash appears to be due to a race condition between a subscription cancellation and subscription re-connection logic.

I wasn't able to reproduce this locally, as this is somewhat of a tricky one to reproduce. Could give the latest rev a try and let me know if resolves the issue?

[paulfthomas]

@cbommas it seems that 2.7.8 resolves the issue 👍

[scb01]

@paulfthomas

Excellent! thank you for confirming. I will go ahead and close this out. Please feel free to post back on this thread if you or @SahajRana run into further issues.

[SahajRana]

@cbommas yes, it seems from my side as well that it's fixed. 👍