adyen-android icon indicating copy to clipboard operation
adyen-android copied to clipboard

`DropInService` retained after `onDestroy` by `DropInActivity`

Open oscarnylander opened this issue 3 years ago • 6 comments

Describe the bug When using the Drop In-SDK, in certain cases (as explained in reproduction steps), the DropInService gets retained after onDestroy, leading to bugs caused by out-of-lifecycle method calls on the service.

To Reproduce Steps to reproduce the behavior:

  1. Launch DropIn-flow: DropIn::startPayment
  2. Select Trustly as the payment option (not sure what's the distinguishing factor here, but Trustly consistently reproduces the issue for me)
  3. Submit the details required by Trustly, until its flow is complete. The service is destroyed at the point where the Trustly WebView is presented
  4. When returning to DropInActivity, an indefinite progress indicator is presented, as DropInService::makeDetailsCall never completes, due to the service earlier having been destroyed

Expected behavior Calls to a destroyed DropInService are not made, allowing the DropInService::makeDetailsCall to complete correctly, and the DropIn-flow to complete

Smartphone:

  • Device: Android Emulator x86_64
  • OS: Android 10.0
  • Browser: Not Applicable
  • Version: adyen-android 4.0.0

Additional context While debugging the issue, I noticed that a new DropInService is indeed instantiated right before the call to DropInService::makeDetailsCall is supposed to happen, but the newly instatiated DropInService does not receive the call - the destroyed one does, instead.

LeakCanary was invaluable in discovering the root cause of this issue. I've attached a log from LeakCanary for additional context on the issue.

┬───
│ GC Root: Global variable in native code
│
├─ com.adyen.checkout.dropin.service.DropInService$DropInBinder instance
│    Leaking: UNKNOWN
│    Retaining 528 B in 1 objects
│    this$0 instance of com.hedvig.app.feature.adyen.payout.
│    AdyenPayoutDropInService
│    ↓ DropInService$DropInBinder.this$0
│                                 ~~~~~~
╰→ com.hedvig.app.feature.adyen.payout.AdyenPayoutDropInService instance
​     Leaking: YES (ObjectWatcher was watching this because com.hedvig.app.
​     feature.adyen.payout.AdyenPayoutDropInService received
​     Service#onDestroy() callback and Service not held by ActivityThread)
​     Retaining 1.6 kB in 28 objects
​     key = f98057dc-7680-4bcb-8234-5a7fc0964b8b
​     watchDurationMillis = 5215
​     retainedDurationMillis = 173
​     mApplication instance of com.hedvig.app.HedvigApplication
​     mBase instance of android.app.ContextImpl

METADATA

Build.VERSION.SDK_INT: 29
Build.MANUFACTURER: Google
LeakCanary version: 2.7
App process name: com.hedvig.dev.app
Stats: LruCache[maxSize=3000,hits=3183,misses=68923,hitRate=4%]
RandomAccess[bytes=3604502,reads=68923,travel=27114725191,range=20396023,size=25
571878]
Heap dump reason: 1 retained objects, app is not visible
Analysis duration: 7266 ms

oscarnylander avatar Aug 03 '21 07:08 oscarnylander

Hi, thanks for the detailed input, looking into it!

I have a few questions to help me understand why Trustly reproduces the issue every time:

  • When you click on Trustly, does the SDK redirect you to another app does it open a web page?
  • If it's a web page, does it open in a custom tab or in an external browser?
  • Do you have some logs that you can include?

jreij avatar Aug 03 '21 11:08 jreij

Trustly is implemented through a web page, I believe it gets launched in a Chrome Custom Tab https://developer.chrome.com/docs/android/custom-tabs/overview/

I managed to reproduce the same thing when going through the Card-flow with 3DS2 enabled (which also launches a custom tab).

Logging-wise - I tried to find adyen-related log output in logcat but was unable to find anything. Do I need to do something special to enable it?

oscarnylander avatar Aug 03 '21 13:08 oscarnylander

Thanks again! I think calling com.adyen.checkout.core.log.Logger.Logger.setLogcatLevel(Log.DEBUG) in your application class should be enough to show the logs.

jreij avatar Aug 03 '21 14:08 jreij

Hello again! Here are some logs:

08-12 10:22:32.568 17953 17953 D CO.DropIn: startPayment from Activity
08-12 10:22:32.659 17953 17953 D CO.DropInActivityKt: attachBaseContext
08-12 10:22:32.668 17953 17953 D CO.DropInActivityKt: onCreate - null
08-12 10:22:32.675 17953 17953 D CO.DropInActivityKt: showPaymentMethodsDialog
08-12 10:22:32.675 17953 17953 D CO.DropInActivityKt: handleIntent: action - null
08-12 10:22:32.677 17953 17953 E CO.DropInActivityKt: Unable to find action
08-12 10:22:32.677 17953 17953 D CO.DropInActivityKt: sendAnalyticsEvent
08-12 10:22:32.687 17953 17953 D CO.PaymentMethodListDialogFragmentKt: onAttach
08-12 10:22:32.688 17953 17953 D CO.PaymentMethodListDialogFragmentKt: onCreateView
08-12 10:22:32.688 17953 17953 D CO.PaymentMethodsListViewModel: onPaymentMethodsResponseChanged
08-12 10:22:32.689 17953 17953 D CO.PaymentMethodsListViewModel: No details required - trustly
08-12 10:22:32.689 17953 17953 D CO.PaymentMethodsListViewModel: onPaymentMethodsReady: 0 - 1
08-12 10:22:32.710 17953 17953 D CO.PaymentMethodListDialogFragmentKt: paymentMethods changed
08-12 10:22:32.710 17953 17953 D CO.DropInServiceKt: bindService - DropInActivity
08-12 10:22:32.886 17953 17953 D CO.DropInServiceKt: onCreate
08-12 10:22:32.886 17953 17953 D CO.DropInServiceKt: onBind
08-12 10:22:32.896 17953 17953 D CO.DropInActivityKt: onServiceConnected
08-12 10:22:33.976 17953 17953 D CO.PaymentMethodListDialogFragmentKt: onPaymentMethodSelected - trustly
08-12 10:22:33.976 17953 17953 D CO.PaymentMethodListDialogFragmentKt: onPaymentMethodSelected: unidentified payment method, sending payment in case of redirect
08-12 10:22:33.976 17953 17953 D CO.DropInActivityKt: requestPaymentsCall
08-12 10:22:33.976 17953 17953 D CO.DropInServiceKt: requestPaymentsCall
08-12 10:22:34.249 17953 18005 D CO.DropInServiceKt: dispatching DropInServiceResult
08-12 10:22:34.249 17953 17953 D CO.DropInActivityKt: handleDropInServiceResult - Action
08-12 10:22:34.250 17953 17953 D CO.ActionHandler: handleAction - redirect
08-12 10:22:34.251 17953 17953 D CO.RedirectDelegateKt: makeRedirect - https://test.adyen.com/hpp/checkout.shtml?u=skipDetails&p=eJx1U9tymzAQ-RrzJgYEEviBB0cmNrnYCYndpC8eIa2xEgxEyG7dr6*gTprpZUazo9lztHv2Il5Vzbdg*oATow-g8LatlOBGNXVWbxu3UoXm*rTge0i4PEGNXviRI94qdIb*92QNurOuxPddz-Uc66slayT0eTpTnRxx0BpqcRqci*W1swctdrw2EyGaQ22SOcijKicXbHn7gWW1gVIPyVxzaiFh85RdL1ePm1m6SPOM-ZN5PGuh5APOYQt9ekiIT31PbgtUCBAoxEGExpj6SBKQYxqPI4Lxp2fmoOspNzyJqU9xHBFKSIj96PKD86DKRL1Fs5vngF3Mf7DoRZZX9zmbT2ZtVtx-v-hCy6eJfBvhy*B2FqXlKJg6LT-twda*H0r3HA19f1RdsqY2mguT5Clb5Xm2mI0wWy5SdpOxa3u9mzzb8i2-W*U3yc6YthsFExvbHrED8docTLdr2hY0MtAZdxijK5r93wTr6UAflYDOXu9*Scpqy7VCcpDKqjIWOfrWVI3g1ZlzC2bXyFFw*ccMbWWfpjjCVA-9s0otMgh5VzDCpFdNet3W2JTubnjpSji6dsecDrp*iGteKanMKcEe9pEXIx8-emNbMsbWBOFX51xMvwB94-rBpzZeLw3ewd-jt4236Tc0CuOxjUg2YkviwCMRCjyKUci3W1TEkqJ4HBISy4JLjzrdq6qHxW0PhXvEbuz5dg0CSuMo8MM4du*RWq*3T8UmDXePWVU2XPkrlnvM092*en4iFbqbidXk4Sp1zj-C7UyjYSmmYLiquuFD-gTfkDuc
08-12 10:22:34.263 17953 17953 D CO.ActionHandler: handleAction - loaded a new component - RedirectComponent
08-12 10:22:34.897 17953 17953 D CO.DropInServiceKt: unbindService - DropInActivity
08-12 10:22:34.903 17953 17953 D CO.DropInActivityKt: onSaveInstanceState
08-12 10:22:34.916 17953 17953 D CO.DropInServiceKt: onUnbind
08-12 10:22:34.918 17953 17953 D CO.DropInServiceKt: onDestroy
08-12 10:23:11.949 17953 17953 D CO.DropInServiceKt: bindService - DropInActivity
08-12 10:23:11.960 17953 17953 D CO.DropInActivityKt: onNewIntent
08-12 10:23:11.960 17953 17953 D CO.DropInActivityKt: handleIntent: action - android.intent.action.VIEW
08-12 10:23:11.961 17953 17953 D CO.ActionHandler: handleAction - loaded a new component - RedirectComponent
08-12 10:23:11.961 17953 17953 D CO.RedirectUtil: parseRedirectResult - adyencheckout://com.hedvig.dev.app?payload=Ab02b4c0%21BQABAgAk2Spn4HhpL5qavb1QWAQOq9B1vLe4jrsU8zIJ%2B4OcEGfVKFiNng1VmOQqzWiVYw3SmDksP3qXJJYnZJOdWNE4eTtHfSqO%2FqnOS7LsKxYyDC9kFakeUpd3vxxntnN9ht1dz1biLTPsW8uTHh4oMO89GOfYZBQBoj4mobsRVPqkL8SnGeb4b8wfsYjXUqhCJfGMiizrEnMwjgGfZbiwZyPja%2FXgBrZflLd42Bwf9i4FZCB2ebJLNP6NtPsILkbIOMxCs6iFjir%2Fc53sMWcFdkBsiuLr29F%2B4ULNOpZ7y5JxtuP9m2WZXiJK%2BbL7%2Bm9vKlg1GcvbS%2F4odF%2BA0h8ibVaqhIyYq3y4hKMqUBJIZv4K5gDMB5j3AKshxtY19XafVI2I%2FSM5C5vIIuO9XItvGoiPAt6K34vZ0kONlruTcbjxikWqGE1yi%2BD4S8AvlRhGL0HI%2FL3o7j%2Fuf87wzXzVP5lvdPo1QsUUwzMs5bNCX0LuRzImDo21ZCvjAUz9WXJuVqwdcUF6Aa5FpizXhd5yI2Q2GrMowebuZbKf%2FJkmQvE%2B8uk9vtMuRjtilL1uLxfca4prad3mw0UFk3JznKUni7A%2Fw2bqiXvwQJllISAXNX03520R70ayN8TOM66HGW%2BCRvXtnxQujJfRVAkcp9CJAPjvtXHbQ9z%2Fudq80NAvMmsEnhD2PWVahT39zqxHBEKKNi4oAEp7ImtleSI6IkFGMEFBQTEwM0NBNTM3RUFFRDg3QzI0REQ1MzkwOUI4MEE3OEE5MjNFMzgyM0Q2OERBQ0M5NEI5RkY4MzA1REMifarSBKiXVLCkzKyu8%2F2IyOGJeTZJeMENdS5MOfZJFU7Vj%2F6nnO81Fj2Rth0o3Ij12E%2B3bvhkUWLNcuCEbccbOpkAt%2FqbnBKYE88Mf3mxggf4b3qnhCIlguhmBYuWmloKTBJXjVaju5PskjXJv8IdmJCsnNul0Pwir%2Fu0W9ZEQ2TJ1ZrhtbSXgnR2JA89ncqgGFK5uyj5qOK6SUKVxJXRtOCVskG2LoTXzxdtHA7v%2FN6AWAJT1nAoF4xZ1vSUapZaePsGeka%2F2AuVDLR9rJNxiVfAmah9fyUEPRtDbYZLDGMLmBklK6aMNCc%3D&type=complete&resultCode=received
08-12 10:23:11.963 17953 17953 D CO.DropInActivityKt: requestDetailsCall
08-12 10:23:11.963 17953 17953 D CO.DropInServiceKt: requestDetailsCall
08-12 10:23:12.197 17953 17953 D CO.DropInServiceKt: onCreate
08-12 10:23:12.197 17953 17953 D CO.DropInServiceKt: onBind
08-12 10:23:12.217 17953 17953 D CO.DropInActivityKt: onServiceConnected
08-12 10:23:12.269 17953 18009 D CO.DropInServiceKt: dispatching DropInServiceResult
08-12 10:23:12.270 17953 17953 D CO.DropInActivityKt: handleDropInServiceResult - Finished
08-12 10:23:12.270 17953 17953 D CO.DropInActivityKt: terminateSuccessfully
08-12 10:23:12.270 17953 17953 D CO.DropInActivityKt: terminate
08-12 10:23:12.464 17953 17953 D CO.DropInServiceKt: unbindService - DropInActivity
08-12 10:23:12.499 17953 17953 D CO.DropInServiceKt: onUnbind
08-12 10:23:12.500 17953 17953 D CO.DropInServiceKt: onDestroy

oscarnylander avatar Aug 12 '21 08:08 oscarnylander

Thanks for the logs @hedvigoscar. Looking into it!

ozgur00 avatar Aug 16 '21 07:08 ozgur00

Hi again @hedvigoscar, this might be fixed in the latest version, are you still on 4.0.0 or did you try to upgrade?

jreij avatar Sep 02 '21 07:09 jreij