search

RevenueCat / purchases-android

Android in-app purchases and subscriptions made easy.
https://www.revenuecat.com/
MIT License
258 stars 52 forks source link

Performance issue in retryBillingServiceConnectionWithExponentialBackoff #1288

Closed rantianhua closed 1 year ago

rantianhua commented 1 year ago

Describe the bug It looks like a dead loop in retrying BillingClient connection.

2023-09-23 13:04:55.112 28721-29147 [Purchases] - DEBUG                        D  ℹ️ Saving tokens []
2023-09-23 13:04:55.113 28721-29147 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.117 28721-29150 [Purchases] - DEBUG                        D  ℹ️ Cleaning previously sent tokens
2023-09-23 13:04:55.117 28721-29150 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.118 28721-29150 [Purchases] - DEBUG                        D  ℹ️ Saving tokens []
2023-09-23 13:04:55.118 28721-29150 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.119 28721-29150 [Purchases] - DEBUG                        D  ℹ️ No pending purchases to sync
2023-09-23 13:04:55.119 28721-29133 [Purchases] - DEBUG                        D  ℹ️ Cleaning previously sent tokens
2023-09-23 13:04:55.120 28721-29133 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.120 28721-29133 [Purchases] - DEBUG                        D  ℹ️ Saving tokens []
2023-09-23 13:04:55.121 28721-29133 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.121 28721-29133 [Purchases] - DEBUG                        D  ℹ️ No pending purchases to sync
2023-09-23 13:04:55.122 28721-29147 [Purchases] - DEBUG                        D  ℹ️ No pending purchases to sync
2023-09-23 13:04:55.124 28721-29034 [Purchases] - DEBUG                        D  ℹ️ Cleaning previously sent tokens
2023-09-23 13:04:55.125 28721-29034 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.125 28721-29034 [Purchases] - DEBUG                        D  ℹ️ Saving tokens []
2023-09-23 13:04:55.126 28721-29034 [Purchases] - DEBUG                        D  ℹ️ Tokens already posted: []
2023-09-23 13:04:55.126 28721-29034 [Purchases] - DEBUG                        D  ℹ️ No pending purchases to sync
2023-09-23 13:04:55.436 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 1000 milliseconds.
2023-09-23 13:04:55.437 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 2000 milliseconds.
2023-09-23 13:04:55.438 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 4000 milliseconds.
2023-09-23 13:04:55.440 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 8000 milliseconds.
2023-09-23 13:04:55.441 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 16000 milliseconds.
2023-09-23 13:04:55.442 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 32000 milliseconds.
2023-09-23 13:04:55.444 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 64000 milliseconds.
2023-09-23 13:04:55.446 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 128000 milliseconds.
2023-09-23 13:04:55.447 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 256000 milliseconds.
2023-09-23 13:04:55.448 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 512000 milliseconds.
2023-09-23 13:04:55.450 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.452 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.453 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.454 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.456 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.457 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.460 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.461 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.463 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.465 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.467 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.468 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.469 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.471 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.472 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.473 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.475 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.476 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.477 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.479 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.480 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.481 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.482 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.483 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.484 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.485 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.486 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.487 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.488 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.488 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.489 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.491 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.491 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.492 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.493 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.494 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.494 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.495 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.496 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.496 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.497 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.498 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.498 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.499 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.500 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.501 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.501 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.502 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.503 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.503 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Retrying BillingClient connection after backoff of 900000 milliseconds.
2023-09-23 13:04:55.504 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.504 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.505 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.505 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.505 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.506 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.506 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.507 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.507 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.508 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.508 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.508 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.509 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.509 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.510 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.510 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.511 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Starting connection for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.530 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.531 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.531 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.532 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.532 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.533 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.533 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.533 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.534 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.534 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.535 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.535 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.535 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.536 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.536 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.537 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.537 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.538 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.538 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.539 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.539 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.539 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.540 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.540 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.541 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.541 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.542 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.542 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.542 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.543 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.543 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.544 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.544 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.545 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@fc8d31a
2023-09-23 13:04:55.545 28721-28721 [Purchases] - DEBUG                        D  ℹ️ Starting connection for com.android.billingclient.api.BillingClientImpl@fc8d31a

The CPU is occupied by the retrying. Screenshot 2023-09-23 at 11 26 33

Screenshot 2023-09-23 at 11 28 18
  1. Environment
    1. Platform: Android
    2. SDK version: com.revenuecat.purchases:purchases:6.9.4
    3. OS version: Android 13
    4. Android Studio version: Android Studio Flamingo | 2022.2.1
    5. How widespread is the issue. No data.

Additional context Add any other context about the problem here.

RCGitBot commented 1 year ago

👀 We've just linked this issue to our internal tracker and notified the team. Thank you for reporting, we're checking this out!

Fossor commented 1 year ago

It can be that the problem is on Google side. I am not using RevenueCat, but have a similar problem with Billing client. https://github.com/android/play-billing-samples/issues/636 I tried to open a case on Google IssueTracker, but I don't see it after submitting.

tonidero commented 1 year ago

Hi @rantianhua, we're taking a look at this issue but we haven't been able to reproduce. A few questions that might help us:

As mentioned in this ticket and as can be seen in that tracing, the likely explanation to this issue is that we get several consecutive onBillingServiceDisconnected calls from Google play. We do schedule reconnects with exponential backoff, but those should be scheduled in the future, so it shouldn't perform much work at that point in time. This seems to be an issue on Google's side as discussed but we will study our options. Please let us know the above information if you can to be able to understand the issue better.

rantianhua commented 1 year ago

@tonidero

What device model are you testing on?

Device Model : Pixel 6 Android 13

Just to confirm, does that device have the play services/play store installed?

Yes

Is it consistent? If not, how often does it reproduce?

Frequency : Almost 30%. Maybe it's relevant with the network situation.

rantianhua commented 1 year ago

@tonidero I saw you merged https://github.com/RevenueCat/purchases-android/pull/1300 to optimize the problem. When will you publish a new version containing the optimization?

tonidero commented 1 year ago

Hi @rantianhua, sorry for the delay! Yeah, we should be releasing a version with this fix this week. Will update this issue once that ships 🙏

tonidero commented 1 year ago

Hi @rantianhua, we just released 7.0.1 which includes that optimization change. Could you try it out and see if it improves the situation for you?

rantianhua commented 1 year ago

Ok, I'll have a try.

rantianhua commented 1 year ago

@tonidero I've tried 7.0.1, but the problem still exists.

Partial Log:

2023-10-14 20:51:53.173 28946-28946 [Purchases] - WARN      xxx                        W  🤖‼️ Billing is not available in this device. DebugMessage: Google Play In-app Billing API version is less than 3. ErrorCode: BILLING_UNAVAILABLE.
2023-10-14 20:51:53.173 28946-29439 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-29426 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-28946 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=PurchaseNotAllowedError, underlyingErrorMessage=Billing is not available in this device. DebugMessage: Google Play In-app Billing API version is less than 3. ErrorCode: BILLING_UNAVAILABLE., message='The device or user is not allowed to make the purchase.')
2023-10-14 20:51:53.173 28946-29427 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-29439 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.173 28946-29426 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.173 28946-29428 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.173 28946-29439 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-29200 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.173 28946-29426 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-29308 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.173 28946-29310 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@30762a3
2023-10-14 20:51:53.174 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ BillingClient connection retry already scheduled. Ignoring
2023-10-14 20:51:53.174 28946-29308 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.174 28946-29439 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.174 28946-29308 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-29200 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@30762a3
2023-10-14 20:51:53.174 28946-29439 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ BillingClient connection retry already scheduled. Ignoring
2023-10-14 20:51:53.174 28946-29427 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.174 28946-29428 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-29440 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.174 28946-29440 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-29427 [Purchases] - ERROR     xxx                        E  🤖‼️ PurchasesError(code=StoreProblemError, underlyingErrorMessage=Error when querying subscriptions. DebugMessage: Service connection is disconnected.. ErrorCode: SERVICE_DISCONNECTED., message='There was a problem with the store.')
2023-10-14 20:51:53.174 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@30762a3
2023-10-14 20:51:53.175 28946-29308 BillingClient           xxx                        W  Got exception trying to get purchasesm try to reconnect
                                                                                                    java.lang.NullPointerException: Attempt to invoke interface method 'android.os.Bundle com.google.android.gms.internal.play_billing.zze.zzj(int, java.lang.String, java.lang.String, java.lang.String, android.os.Bundle)' on a null object reference
                                                                                                        at com.android.billingclient.api.BillingClientImpl.zzN(com.android.billingclient:billing@@6.0.1:5)
                                                                                                        at com.android.billingclient.api.zzy.call(com.android.billingclient:billing@@6.0.1:1)
                                                                                                        at java.util.concurrent.FutureTask.run(FutureTask.java:264)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
                                                                                                        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
                                                                                                        at java.lang.Thread.run(Thread.java:1012)
2023-10-14 20:51:53.175 28946-28946 [Purchases] - WARN      xxx                        W  ⚠️ BillingClient connection retry already scheduled. Ignoring
rantianhua commented 1 year ago

Maybe we need to check the error code. Some errors are non-retriable, such as https://developer.android.com/google/play/billing/errors#non-retriable_billingresult_responses.

tonidero commented 1 year ago

Maybe we need to check the error code. Some errors are non-retriable, such as https://developer.android.com/google/play/billing/errors#non-retriable_billingresult_responses.

Hi @rantianhua, we do indeed check the error code when trying to connect to determine whether we need to reconnect: https://github.com/RevenueCat/purchases-android/blob/main/purchases/src/main/kotlin/com/revenuecat/purchases/google/BillingWrapper.kt#L679.

As for the error, I see this in the new logs you sent:

2023-10-14 20:51:53.173 28946-28946 [Purchases] - WARN      xxx                        W  🤖‼️ Billing is not available in this device. DebugMessage: Google Play In-app Billing API version is less than 3. ErrorCode: BILLING_UNAVAILABLE.

That error may happen if the version of play services/play store in the device is very old.

As for the original issue, did you notice a performance improvement with 7.0.1? The fix provided there won't actually fix the issue of getting multiple disconnect callbacks simultaneously since that seems to come from Google. But hopefully the changes made it so we don't cause as much performance overhead in this situation.

ahmtbrk commented 1 year ago

As far as I understand, this problem is related to the Google Billing library. Even though I updated my RevenueCat version to 7.0.1, it did not improve and some of my users cannot make purchases in the application (around 3%). I removed RevenueCat from the project and added Google Billing directly, and it keeps connecting-disconnecting. Has anyone found a solution to the problem?

rantianhua commented 1 year ago

@tonidero The 7.0.1 doesn't fix the performance issue. Now I do a tricky way to solve it:

        BillingClient.newBuilder(context)
            .enablePendingPurchases()
            .setListener { _, _ -> }
            .build()
            .let { billingClient ->
                val handler = Handler(Looper.getMainLooper())
                billingClient.startConnection(
                    object : BillingClientStateListener {
                        override fun onBillingSetupFinished(billingResult: BillingResult) {
                            if (billingResult.responseCode == BillingResponseCode.OK) {
                                // According to empirical observations, if disconnect is received immediately after receiving OK,
                                // then this service is basically unavailable, which will cause repeated reconnections in RevenueCat
                                // and cause the main thread to be stuck.
                                // According to empirical observation, the delay of checking whether there is a disconnection after 1s is enough.
                                handler.postDelayed({
                                    billingClient.endConnection()
                                    if (receivedDisconnect) return@postDelayed
                                    if (initialized) return@postDelayed
                                    initialized = true
                                    initialize(context)
                                }, 1000)
                            }
                        }

                        override fun onBillingServiceDisconnected() {
                            receivedDisconnect = true
                        }
                    },
                )
            }

That error may happen if the version of play services/play store in the device is very old.

Actually no, my google play service is fresh, the connection will be normal after I clear all data of Google Play Store.

tonidero commented 1 year ago

Hmm I see... Could you share the logs when this happens using 7.0.1 @rantianhua? We want to make sure it's following the path we expect (after that change, it should only schedule one reconnect, even if we receive multiple onBillingServiceDisconnected.

@ahmtbrk, we are currently investigating the issue, but we haven't been able to reproduce yet. As you said, it seems to be an issue on the billing library, but we haven't found a reliable solution, since we would prefer not to delay initialization by a whole second if possible.

rantianhua commented 1 year ago

https://github.com/RevenueCat/purchases-android/issues/1288#issuecomment-1762890918 here is the log in version 7.0.1

tonidero commented 1 year ago

@rantianhua Oh right, sorry I missed that 🙇.

So, seems that it is going through the new paths so we only try to reconnect once, but seems that it didn't help with the performance issue, so it seems that the performance issue happens on the billing library side, since we don't do almost any processing at that point in time anymore.

the connection will be normal after I clear all data of Google Play Store.

I was wondering about this. Do you have any steps to repro again after you clear data on the Play Store? It might helps us to reproduce the issue.

chris-lin commented 1 year ago

I'm also encountering a similar issue in version 7.0.1. after switching the language in the system settings and relaunching the app, there's a possibility of encountering repeated logs below 🙏 


 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
 W  ⚠️ Billing Service disconnected for com.android.billingclient.api.BillingClientImpl@ba98497
 W  ⚠️ BillingClient connection retry already scheduled. Ignoring
vegaro commented 1 year ago

@chris-lin thanks for that! We've finally been able to reproduce those logs by changing the language then opening the app.

What's interesting is that the app will continue to be in that state forever, at least in my device, until I reopen the Play Store 🤔

tkortekaas commented 1 year ago

Same for me, this issue happened after switching my language in my system settings. For me restarting my phone fixed it. Samsung Galaxy A53

vegaro commented 1 year ago

We just released 7.1.1, which has a fix that improves the performance issues you've been seeing.

We are in the process of making more improvements on the handling of the interactions with the BillingClient

Please let us know if the performance hasn't improved

github-actions[bot] commented 1 year ago

This issue has been automatically locked due to no recent activity after it was closed. Please open a new issue for related reports.