Fatal Exception: java.lang.IllegalStateException Reply already submitted

[kestasb]

We're using purchases_flutter: ^3.4.5 in our app and receive the following crash reports from Android users:

Fatal Exception: java.lang.IllegalStateException: Reply already submitted
at io.flutter.embedding.engine.dart.DartMessenger$Reply.reply(DartMessenger.java:164)
at io.flutter.plugin.common.MethodChannel$IncomingMethodCallHandler$1.error(MethodChannel.java:243)
at com.revenuecat.purchases_flutter.PurchasesFlutterPlugin.reject(PurchasesFlutterPlugin.java:595)
at com.revenuecat.purchases_flutter.PurchasesFlutterPlugin.access$100(PurchasesFlutterPlugin.java:41)
at com.revenuecat.purchases_flutter.PurchasesFlutterPlugin$5.onError(PurchasesFlutterPlugin.java:589)
at com.revenuecat.purchases.hybridcommon.CommonKt$getOfferings$1.invoke(common.kt:44)
at com.revenuecat.purchases.hybridcommon.CommonKt$getOfferings$1.invoke(:2)
at com.revenuecat.purchases.ListenerConversionsKt$receiveOfferingsListener$1.onError(listenerConversions.kt:118)
at com.revenuecat.purchases.Purchases$handleErrorFetchingOfferings$1.invoke(Purchases.kt:1241)
at com.revenuecat.purchases.Purchases$handleErrorFetchingOfferings$1.invoke(Purchases.kt:98)
at com.revenuecat.purchases.PurchasesKt$sam$java_lang_Runnable$0.run(:2)
at android.os.Handler.handleCallback(Handler.java:900)
at android.os.Handler.dispatchMessage(Handler.java:103)
at android.os.Looper.loop(Looper.java:219)
at android.app.ActivityThread.main(ActivityThread.java:8393)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1055)

Any ideas what could cause this crash?

[vegaro]

I have never seen this issue before. I read a bit about it and looks like it's happening to more plugins. I made sure that we are not calling Result.reject more than once when calling getOfferings. Can you reproduce it on your end?

[kestasb]

@vegaro Unfortunately, we're not able to reproduce it on our end. 80% of affected devices are Huawei, 19% Samsung and <1% Motorola. What is interesting that the crash occurs 91% when the app is in a background state.

[beylmk]

Hey @kestasb, I'm continuing to look into this issue...it's a tricky one to diagnose. Can you confirm to me how/where you are calling getOfferings, and attach debug logs from app startup until the offerings call? This may help me figure out what's going on...

[JCKodel]

@maddie

atal Exception: java.lang.IllegalStateException: Reply already submitted
       at io.flutter.embedding.engine.dart.DartMessenger$Reply.reply(DartMessenger.java:164)
       at io.flutter.plugin.common.MethodChannel$IncomingMethodCallHandler$1.success(MethodChannel.java:238)
       at com.revenuecat.purchases_flutter.PurchasesFlutterPlugin$5.onReceived(PurchasesFlutterPlugin.java:584)
       at com.revenuecat.purchases.hybridcommon.CommonKt$restoreTransactions$2.invoke(common.kt:187)
       at com.revenuecat.purchases.hybridcommon.CommonKt$restoreTransactions$2.invoke(common.kt)
       at com.revenuecat.purchases.ListenerConversionsKt$receivePurchaserInfoListener$1.onReceived(listenerConversions.kt:127)
       at com.revenuecat.purchases.Purchases$retrievePurchaseInfo$1.invoke(Purchases.kt:846)
       at com.revenuecat.purchases.Purchases$retrievePurchaseInfo$1.invoke(Purchases.kt:98)
       at com.revenuecat.purchases.PurchasesKt$sam$java_lang_Runnable$0.run(Purchases.kt)
       at android.os.Handler.handleCallback(Handler.java:739)
       at android.os.Handler.dispatchMessage(Handler.java:95)
       at android.os.Looper.loop(Looper.java:148)
       at android.app.ActivityThread.main(ActivityThread.java:7325)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)

[kestasb]

@beylmk We're calling Purchases.getOfferings() during app launch to get the current offering and its availablePackages. See the attached debug log:

D/[Purchases] - DEBUG( 3172): ℹ️ Debug logging enabled
D/[Purchases] - DEBUG( 3172): ℹ️ SDK Version - 4.3.1
D/[Purchases] - DEBUG( 3172): 👤 Initial App User ID - null
D/[Purchases] - DEBUG( 3172): 👤 Identifying App User ID: Klsf8aPL7iQzbu142sM7tQ9C8273
D/[Purchases] - DEBUG( 3172): ℹ️ Deleting old synced subscriber attributes that don't belong to Klsf8aPL7iQzbu142sM7tQ9C8273
D/[Purchases] - DEBUG( 3172): ℹ️ App foregrounded
D/[Purchases] - DEBUG( 3172): ℹ️ PurchaserInfo cache is stale, updating from network in foreground.
D/[Purchases] - DEBUG( 3172): ℹ️ Offerings cache is stale, updating from network in foreground
D/[Purchases] - DEBUG( 3172): 😻 Offerings updated from network.
D/[Purchases] - DEBUG( 3172): ℹ️ Skipping updating pending purchase queue since BillingClient is not connected yet.
D/[Purchases] - DEBUG( 3172): ℹ️ No subscriber attributes to synchronize.
D/[Purchases] - DEBUG( 3172): ℹ️ Listener set
D/[Purchases] - DEBUG( 3172): ℹ️ Sending latest PurchaserInfo to listener.
D/[Purchases] - DEBUG( 3172): ℹ️ Starting connection for com.android.billingclient.api.BillingClientImpl@761536a
D/[Purchases] - DEBUG( 3172): ℹ️ Ending connection for com.android.billingclient.api.BillingClientImpl@3141915
D/[Purchases] - DEBUG( 3172): ℹ️ Vending PurchaserInfo from cache.
D/[Purchases] - DEBUG( 3172): ℹ️ Checking if cache is stale AppInBackground false
D/[Purchases] - DEBUG( 3172): ℹ️ Billing Service Setup finished for com.android.billingclient.api.BillingClientImpl@761536a
D/[Purchases] - DEBUG( 3172): ℹ️ Updating pending purchase queue
D/[Purchases] - DEBUG( 3172): ℹ️ API request started: GET /subscribers/Klsf8aPL7iQzbu142sM7tQ9C8273
D/[Purchases] - DEBUG( 3172): ℹ️ API request completed with status: GET /subscribers/Klsf8aPL7iQzbu142sM7tQ9C8273 304
D/[Purchases] - DEBUG( 3172): ℹ️ PurchaserInfo updated, sending to listener.
D/[Purchases] - DEBUG( 3172): ℹ️ API request started: GET /subscribers/Klsf8aPL7iQzbu142sM7tQ9C8273/offerings
D/[Purchases] - DEBUG( 3172): ℹ️ API request completed with status: GET /subscribers/Klsf8aPL7iQzbu142sM7tQ9C8273/offerings 304
D/[Purchases] - DEBUG( 3172): ℹ️ Requesting products from the store with identifiers: premium_monthly, premium_yearly, premium_lifetime, premium_yearly_extended_trial, premium_yearly_discount, premium_lifetime_discount, remove_ads, premium_lifetime_discount_standard, 2021_premium_monthly, 2021_premium_yearly, 2021_premium_yearly_discount
D/[Purchases] - DEBUG( 3172): ℹ️ Querying purchases
D/[Purchases] - DEBUG( 3172): ℹ️ Cleaning previously sent tokens
D/[Purchases] - DEBUG( 3172): ℹ️ Tokens already posted: []
D/[Purchases] - DEBUG( 3172): ℹ️ Saving tokens []
D/[Purchases] - DEBUG( 3172): ℹ️ Tokens already posted: []
D/[Purchases] - DEBUG( 3172): ℹ️ Products request finished for premium_monthly, premium_yearly, premium_lifetime, premium_yearly_extended_trial, premium_yearly_discount, premium_lifetime_discount, remove_ads, premium_lifetime_discount_standard, 2021_premium_monthly, 2021_premium_yearly, 2021_premium_yearly_discount
D/[Purchases] - DEBUG( 3172): 💰 Retrieved skuDetailsList: 
D/[Purchases] - DEBUG( 3172): ℹ️ Requesting products from the store with identifiers: premium_monthly, premium_yearly, premium_lifetime, premium_yearly_extended_trial, premium_yearly_discount, premium_lifetime_discount, remove_ads, premium_lifetime_discount_standard, 2021_premium_monthly, 2021_premium_yearly, 2021_premium_yearly_discount
D/[Purchases] - DEBUG( 3172): ℹ️ Products request finished for premium_monthly, premium_yearly, premium_lifetime, premium_yearly_extended_trial, premium_yearly_discount, premium_lifetime_discount, remove_ads, premium_lifetime_discount_standard, 2021_premium_monthly, 2021_premium_yearly, 2021_premium_yearly_discount
D/[Purchases] - DEBUG( 3172): 💰 Retrieved skuDetailsList: 

The next time we call Purchases.getOfferings() during app usage, the debug log shows:

D/[Purchases] - DEBUG( 3172): ℹ️ Vending Offerings from cache
D/[Purchases] - DEBUG( 3172): ℹ️ Checking if cache is stale AppInBackground false

[beylmk]

Hey @kestasb thanks for the details! I'm going to try to reproduce this issue today...in the meantime, can you confirm whether you and @JCKodel are working on the same app?

[kestasb]

@beylmk Thanks! No, we're not working on the same app.

[beylmk]

Hey @kestasb, just an update -- I tried to reproduce this in a few different ways yesterday, with no success. This is definitely happening in other plugins, but it's really hard to tell whether it's a Flutter bug or an issue with our logic.

For both you and @JCKodel. any other information you could provide would be great...such as:

1. Is this only happening in a particular version of our SDK?
2. @JCKodel is it also happening mostly when your app is in the background?
3. Can you confirm there is no similar exception being thrown for ios?

[JCKodel]

1. Is this only happening in a particular version of our SDK?

I don't know. The SDK is updated to the last version (the error was not happening before).

2. @JCKodel is it also happening mostly when your app is in the background?

I don't know. Those errors are from Crashlytics. I don't know when they appear.

3. Can you confirm there is no similar exception being thrown for ios?

I don't know. I don't have Crashlytics enabled for iOS.

@beylmk

[beylmk]

@JCKodel @kestasb Just an update -- we've only been able to reproduce this once. We believe it's a scenario wherein Google's BillingClient times out, calls the listener, then retries and calls it again. Both getOfferings and restorePurchases, the methods in the stacktraces from your crashes, call into BillingClient.

We are looking into ways to verify this now..

[kestasb]

@beylmk Glad to hear that you were able to reproduce the issue!

1. Is this only happening in a particular version of our SDK?

What we see in Crashlytics logs, the issue occurs with purchases_flutter: ^3.3.1 - 3.4.5.

3. Can you confirm there is no similar exception being thrown for ios?

We checked Crashlytics for iOS app and didn't find any similar issue.

[vegaro]

Hi @kestasb, it looks like we've managed to figure out what the issue is. Apparently Google is calling the callback to fetch the products twice. Looks like they retry when there's an error connecting to the Play Store which ends up calling the callback a second time.

We are going to report it to Google and also patch it so there's only one callback triggered and this exception doesn't occur. We'll report back.

[vegaro]

We reported to Google https://issuetracker.google.com/issues/201628456

It looks like there's another report for the same issue here https://issuetracker.google.com/issues/189727982

[beylmk]

@JCKodel @kestasb just pushed a release with the fix! Check out 3.4.6

If you're curious, here's the PR for the fix in our Android repo.
We'd love to hear back once you've incorporated the new version to confirm you're no longer seeing the crash...

[kestasb]

@beylmk Thank you, it seems that the problem is fixed!

[beylmk]

@kestasb that's great news! I'll go ahead and close out the ticket for now. Let me know if you run into any other issues, and thanks for following up!

[leidig54]

I'm getting this issue again. Android only.

[dmitry-kotorov]

I am also getting this issue again on Android Emulator Pixel XL API 33. It occurs only on first start after install the app.

D/AndroidRuntime(30441): Shutting down VM
E/AndroidRuntime(30441): FATAL EXCEPTION: main
E/AndroidRuntime(30441): Process: com.ThreeBoots, PID: 30441
E/AndroidRuntime(30441): java.lang.IllegalStateException: Reply already submitted
E/AndroidRuntime(30441): at io.flutter.embedding.engine.dart.DartMessenger$Reply.reply(DartMessenger.java:430)
E/AndroidRuntime(30441): at io.flutter.plugin.common.MethodChannel$IncomingMethodCallHandler$1.success(MethodChannel.java:267)
E/AndroidRuntime(30441): at com.revenuecat.purchases_flutter.PurchasesFlutterPlugin$4.onReceived(PurchasesFlutterPlugin.java:579)
E/AndroidRuntime(30441): at com.revenuecat.purchases.hybridcommon.CommonKt$logIn$2.invoke(common.kt:202)
E/AndroidRuntime(30441): at com.revenuecat.purchases.hybridcommon.CommonKt$logIn$2.invoke(common.kt:195)
E/AndroidRuntime(30441): at com.revenuecat.purchases.ListenerConversionsKt$logInSuccessListener$1.onReceived(listenerConversions.kt:86)
E/AndroidRuntime(30441): at com.revenuecat.purchases.Purchases$logIn$2$1$1.invoke(Purchases.kt:560)
E/AndroidRuntime(30441): at com.revenuecat.purchases.Purchases$logIn$2$1$1.invoke(Purchases.kt:559)
E/AndroidRuntime(30441): at com.revenuecat.purchases.Purchases.dispatch$lambda-18(Purchases.kt:1278)
E/AndroidRuntime(30441): at com.revenuecat.purchases.Purchases.$r8$lambda$r99wGZP2CqD_UT2SJ3OnAAUSmvU(Unknown Source:0)
E/AndroidRuntime(30441): at com.revenuecat.purchases.Purchases$$ExternalSyntheticLambda2.run(Unknown Source:2)
E/AndroidRuntime(30441): at android.os.Handler.handleCallback(Handler.java:942)
E/AndroidRuntime(30441): at android.os.Handler.dispatchMessage(Handler.java:99)
E/AndroidRuntime(30441): at android.os.Looper.loopOnce(Looper.java:201)
E/AndroidRuntime(30441): at android.os.Looper.loop(Looper.java:288)
E/AndroidRuntime(30441): at android.app.ActivityThread.main(ActivityThread.java:7898)
E/AndroidRuntime(30441): at java.lang.reflect.Method.invoke(Native Method)
E/AndroidRuntime(30441): at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
E/AndroidRuntime(30441): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
D/[Purchases] - DEBUG(30441): ℹ️ API request started: GET /subscribers/erhqernwenwtnwtn34t34/offerings
D/[Purchases] - DEBUG(30441): ℹ️ API request completed with status: GET /subscribers/erhqernwenwtnwtn34t34/offerings 304
D/[Purchases] - DEBUG(30441): ℹ️ Requesting products from the store with identifiers: xxx
I/Process (30441): Sending signal. PID: 30441 SIG: 9