I am using Google Play In app Billing and submit my request using the IabHelper, which under the hood uses startIntentSenderForResult.
As expected, upon completion of the call (Google Play Activity closes) the result is returned to my Activity in the onActivityResult method which then delegates it to the waiting OnIabPurchaseFinishedListener instance via IabHelper. If an error occurs during the purchase, a dialog is shown to the user (my code) in the finished listener. It appears as though the result is being returned to my application prior to the user being finished with the called play store activity.
Details: In my app I press the purchase button which launches the purchase intent, the play store is shown and an error shows up (item not available, it is inactive (deliberately for negative testing)).
04-03 20:21:14.371: D/com.satalyst.android.ui.PurchaseAction(10129): Launching purchase flow request for sku: demo_test
04-03 20:21:14.371: D/IabHelper(10129): Starting in-app billing setup.
04-03 20:21:14.446: D/IabHelper(10129): Billing service connected.
04-03 20:21:14.446: D/IabHelper(10129): Checking for in-app billing 3 support.
04-03 20:21:14.461: D/IabHelper(10129): In-app billing version 3 supported for com.satalyst.android
04-03 20:21:14.476: D/IabHelper(10129): Subscriptions AVAILABLE.
04-03 20:21:14.476: D/IabHelper(10129): Starting async operation: launchPurchaseFlow
04-03 20:21:14.476: D/IabHelper(10129): Constructing buy intent for demo_test, item type: inapp
04-03 20:21:14.506: D/IabHelper(10129): Launching buy intent for demo_test. Request code: 1
04-03 20:21:14.846: D/IabHelper(10129): Ending async operation: launchPurchaseFlow
04-03 20:21:14.846: E/IabHelper(10129): In-app billing error: Null data in IAB activity result.
04-03 20:21:14.846: D/com.satalyst.android.ui.PurchaseAction$PurchaseCompleteListener(10129): Received purchase code: -1002
04-03 20:21:14.846: E/com.satalyst.android.ui.PurchaseAction$PurchaseCompleteListener(10129): Unable to purchase item: demo_test due to error: -1002 with message: Null data in IAB result (response: -1002:Bad response received)
04-03 20:21:14.856: I/ACTIVITY-RESUME(10129): com.satalyst.android.ui.MainActivity@4151b760
04-03 20:21:15.526: D/com.satalyst.android.ui.MainActivity(10129): Request update of cache
04-03 20:21:15.601: D/com.satalyst.android.ui.HomeFragment(10129): Payload currently selected: demopayload updating UI
04-03 20:21:16.091: E/WindowManager(10129): Activity com.satalyst.android.ui.MainActivity has leaked window com.android.internal.policy.impl.PhoneWindow$DecorView@41a9d218 that was originally added here
04-03 20:21:16.091: E/WindowManager(10129): android.view.WindowLeaked: Activity com.satalyst.android.ui.MainActivity has leaked window com.android.internal.policy.impl.PhoneWindow$DecorView@41a9d218 that was originally added here
04-03 20:21:16.091: E/WindowManager(10129): at android.view.ViewRootImpl.<init>(ViewRootImpl.java:386)
04-03 20:21:16.091: E/WindowManager(10129): at android.view.WindowManagerImpl.addView(WindowManagerImpl.java:267)
04-03 20:21:16.091: E/WindowManager(10129): at android.view.WindowManagerImpl.addView(WindowManagerImpl.java:215)
04-03 20:21:16.091: E/WindowManager(10129): at android.view.WindowManagerImpl$CompatModeWrapper.addView(WindowManagerImpl.java:140)
04-03 20:21:16.091: E/WindowManager(10129): at android.view.Window$LocalWindowManager.addView(Window.java:537)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.Dialog.show(Dialog.java:278)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.AlertDialog$Builder.show(AlertDialog.java:932)
04-03 20:21:16.091: E/WindowManager(10129): at com.satalyst.android.ui.PurchaseAction.showSendEmailErrorDialog(PurchaseAction.java:176)
04-03 20:21:16.091: E/WindowManager(10129): at com.satalyst.android.ui.PurchaseAction.access$5(PurchaseAction.java:152)
04-03 20:21:16.091: E/WindowManager(10129): at com.satalyst.android.ui.PurchaseAction$PurchaseCompleteListener.onIabPurchaseFinished(PurchaseAction.java:240)
04-03 20:21:16.091: E/WindowManager(10129): at com.satalyst.android.iab.IabHelper.handleActivityResult(IabHelper.java:434)
04-03 20:21:16.091: E/WindowManager(10129): at com.satalyst.android.ui.MainActivity.onActivityResult(MainActivity.java:225)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.Activity.dispatchActivityResult(Activity.java:4649)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.ActivityThread.deliverResults(ActivityThread.java:2988)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.ActivityThread.handleSendResult(ActivityThread.java:3035)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.ActivityThread.access$1100(ActivityThread.java:127)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1189)
04-03 20:21:16.091: E/WindowManager(10129): at android.os.Handler.dispatchMessage(Handler.java:99)
04-03 20:21:16.091: E/WindowManager(10129): at android.os.Looper.loop(Looper.java:137)
04-03 20:21:16.091: E/WindowManager(10129): at android.app.ActivityThread.main(ActivityThread.java:4507)
04-03 20:21:16.091: E/WindowManager(10129): at java.lang.reflect.Method.invokeNative(Native Method)
04-03 20:21:16.091: E/WindowManager(10129): at java.lang.reflect.Method.invoke(Method.java:511)
04-03 20:21:16.091: E/WindowManager(10129): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:790)
04-03 20:21:16.091: E/WindowManager(10129): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:557)
04-03 20:21:16.091: E/WindowManager(10129): at dalvik.system.NativeStart.main(Native Method)
At this point the play store application is still shown (in the foreground). It looks to me as if the error is caused because the operation returns to the calling activity (which doesn't have focus), resulting in the error when the dialog is attached (leaks immediately upon creation). Pressing "OK" in the error in the play store activity results in the following (a new activity for my application is created and given focus).
04-03 20:21:18.296: I/com.satalyst.android.ui.MainActivity(10129): Loading selected payload: demopayload
04-03 20:21:18.341: I/ACTIVITY-RESUME(10129): com.satalyst.android.ui.MainActivity@41adf048
04-03 20:21:18.601: D/com.satalyst.android.ui.MainActivity(10129): Request update of cache
04-03 20:21:18.626: D/com.satalyst.android.ui.HomeFragment(10129): Payload currently selected: demopayload updating UI
Fixing this has me stumped as I would like to show a dialog in my Activity when a purchase error occurs allowing them to email me with details so that I can help customers with purchase errors as a priority. I am sure there are some hack fixes I could do, perhaps persisting the details when the error occurs and returns prematurely, then checking every time the activity is resumed for a persisted failure and taking the appropriate action; however this feels like a nasty work around.
Stacktrace without dialog:
04-03 21:15:40.236: D/com.satalyst.android.ui.PurchaseAction(12415): Launching purchase flow request for sku: demo_test
04-03 21:15:40.236: D/IabHelper(12415): Starting async operation: launchPurchaseFlow
04-03 21:15:40.236: D/IabHelper(12415): Constructing buy intent for demo_test, item type: inapp
04-03 21:15:40.276: D/IabHelper(12415): Launching buy intent for demo_test. Request code: 1
04-03 21:15:40.806: D/IabHelper(12415): Ending async operation: launchPurchaseFlow
04-03 21:15:40.806: E/IabHelper(12415): In-app billing error: Null data in IAB activity result.
04-03 21:15:40.806: D/com.satalyst.android.ui.PurchaseAction$PurchaseCompleteListener(12415): Received purchase code: -1002
04-03 21:15:40.811: E/com.satalyst.android.ui.PurchaseAction$PurchaseCompleteListener(12415): Unable to purchase item: demo_test due to error: -1002 with message: Null data in IAB result (response: -1002:Bad response received)
04-03 21:15:40.811: I/ACTIVITY-RESUME(12415): com.satalyst.android.ui.MainActivity@414cb8e0
04-03 21:15:41.681: I/com.satalyst.android.ui.MainActivity(12415): Destroying MainActivity: com.satalyst.android.ui.MainActivity@414cb8e0
04-03 21:15:42.396: I/ACTIVITY-RESUME(12415): com.satalyst.android.ui.MainActivity@414d8f5
The code which triggers the purchase:
/**
* Stage #1, ensure the server is contactable and has correct protocol
* version
*/
@Override
public void onClick() {
// Verify server can be communicated with
final ProgressDialog dlg = new ProgressDialog(activity);
dlg.setMessage(activity.getString(R.string.preparing_purchase));
dlg.setIndeterminate(true);
dlg.setProgressStyle(ProgressDialog.STYLE_SPINNER);
dlg.show();
AsyncTask.execute(new Runnable() {
@Override
public void run() {
try {
versionAgent.checkCloudServiceVersion();
dlg.dismiss();
purchasePayload(payload);
} catch (VersionQueryException e) {
activity.runOnUiThread(new Runnable() {
@Override
public void run() {
Toast.makeText(
activity,
activity.getResources().getString(
R.string.query_version_error),
Toast.LENGTH_LONG).show();
}
});
Log.e(this,
"Purchase disabled, could not query service version");
} catch (VersionMismatchException e) {
activity.runOnUiThread(new Runnable() {
@Override
public void run() {
Toast.makeText(
activity,
activity.getResources()
.getString(
R.string.query_version_update_required),
Toast.LENGTH_LONG).show();
}
});
Log.e(this, "Purchase disabled, update is required");
}
}
});
}
/**
* Stage #2, trigger IAB purchase of given payload
*
* @param payload
*/
private void purchasePayload(@Nonnull final Payload payload) {
final String sku = payload.getSku();
Log.d(this, "Launching purchase flow request for sku: " + sku);
final IabHelper helper = ((MainActivity) activity).helper;
final OnIabPurchaseFinishedListener onPurchasedListener = new PurchaseCompleteListener();
if (!helper.isSetup()) {
helper.startSetup(new OnIabSetupFinishedListener() {
@Override
public void onIabSetupFinished(IabResult result) {
helper.launchPurchaseFlow(activity, sku,
BillingConstants.PURCHASE_REQUEST,
onPurchasedListener);
}
});
} else {
helper.launchPurchaseFlow(activity, sku,
BillingConstants.PURCHASE_REQUEST, onPurchasedListener);
}
}
The onResume/onPause/onActivityResult and onDestroy in MainActivity code:
/**
* {@inheritDoc}
*/
@Override
protected void onResume() {
super.onResume();
Log.i("ACTIVITY-RESUME", this.toString());
eventBus.register(this);
}
/**
* {@inheritDoc}
*/
@Override
protected void onPause() {
super.onPause();
eventBus.unregister(this);
}
@Override
protected void onDestroy() {
super.onDestroy();
Log.i(this, "Destroying MainActivity: "+ this);
}
/**
* {@inheritDoc}
*/
@Override
protected void onActivityResult(int requestCode, int resultCode, Intent data) {
if (helper == null
|| !helper.handleActivityResult(requestCode, resultCode, data)) {
super.onActivityResult(requestCode, resultCode, data);
}
}
The OnIabPurchaseFinishedListener which is triggered in onActivityResult via helper:
private final class PurchaseCompleteListener implements
OnIabPurchaseFinishedListener {
@Override
public void onIabPurchaseFinished(IabResult result, Purchase purchase) {
Log.d(this, "Received purchase code: " + result.getResponse());
if (result.isSuccess()) {
// Removed this code since else is triggered in trouble case.
} else {
int responseCode = result.getResponse();
switch (responseCode) {
case IabHelper.BILLING_RESPONSE_RESULT_USER_CANCELED:
Log.i(this, "Billing response received: User Canceled");
// Do nothing
break;
default:
String message = result.getMessage();
Log.e(this, "Unable to purchase item: " + payload.getSku()
+ " due to error: " + responseCode
+ " with message: " + message);
break;
}
}
}
}
Activity definition in manifest XML
<activity
android:name="com.satalyst.android.ui.MainActivity"
android:label="@string/app_name"
android:launchMode="singleInstance"
android:screenOrientation="portrait"
android:theme="@android:style/Theme.Holo.Light" >
<intent-filter>
<action android:name="android.intent.action.MAIN" />
<category android:name="android.intent.category.LAUNCHER" />
</intent-filter>
</activity>
Error Log (full) which shows premature Activity destruction:
D/IabHelper( 4462): Launching buy intent for demo_test. Request code: 1
I/power ( 2004): *** acquire_dvfs_lock : lockType : 1 freq : 1200000
I/ActivityManager( 2004): START {intent.toShortString} from pid -1
D/PowerManagerService( 2004): acquireDVFSLockLocked : type : DVFS_MIN_LIMIT frequency : 1200000 uid : 1000 pid : 2004 tag : ActivityManager
W/ActivityManager( 2004): mDVFSLock.acquire()
D/dalvikvm( 2004): JIT code cache reset in 2 ms (1048532 bytes 1/0)
D/dalvikvm( 2004): GC_CONCURRENT freed 1981K, 18% free 19557K/23623K, paused 3ms+11ms
I/ALSAModule( 1837): Terminated ALSA PLAYBACK device hifi
W/WifiStateTracker( 2004): getNetworkInfo : NetworkInfo: type: wifi[], state: UNKNOWN/IDLE, reason: (unspecified), extra: (none), roaming: false, failover: false, isAvailable: false
E/WifiP2pStateTracker( 2004): getNetworkInfo : NetworkInfo: type: wifi_p2p[], state: UNKNOWN/IDLE, reason: (unspecified), extra: (none), roaming: false, failover: false, isAvailable: false
I/SurfaceFlinger( 1834): id=48 Removed idx=3 Map Size=4
I/SurfaceFlinger( 1834): id=48 Removed idx=-2 Map Size=4
D/dalvikvm( 4462): GC_CONCURRENT freed 12727K, 37% free 44670K/69959K, paused 2ms+4ms
D/ActivityManager( 2004): Trying to launch applicationName
V/GCMRegistrar( 3130): Is registered on server: true
W/WifiStateTracker( 2004): getNetworkInfo : NetworkInfo: type: wifi[], state: UNKNOWN/IDLE, reason: (unspecified), extra: (none), roaming: false, failover: false, isAvailable: false
E/WifiP2pStateTracker( 2004): getNetworkInfo : NetworkInfo: type: wifi_p2p[], state: UNKNOWN/IDLE, reason: (unspecified), extra: (none), roaming: false, failover: false, isAvailable: false
I/SurfaceFlinger( 1834): id=49(3) createSurface 0x398ec (1x1),1 flag=400
D/Finsky ( 3130): [1] SelfUpdateScheduler.checkForSelfUpdate: Skipping DFE self-update. Local Version [8016014] >= Server Version [-1]
W/InputManagerService( 2004): Starting input on non-focused client com.android.internal.view.IInputMethodClient$Stub$Proxy@4211eaa0 (uid=10110 pid=4462)
I/ActivityManager( 2004): Displayed shortComponentName: +105ms
V/yamaha::media::VolumeCtrl( 1837): VolumeCtrl::createVolume()
V/yamaha::media::VolumeCtrl( 1837): VolumeCtrl::setVolume()
D/yamaha::media::VolumeCtrl( 1837): VolumeCtrl::setVolume() FM Playback: Ready
D/yamaha::media::VolumeCtrl( 1837): VolumeCtrl::setVolume() VoiceCall: Ready
W/Finsky ( 3130): [1] CarrierParamsAction.run: Saving carrier billing params failed.
E/Finsky ( 3130): [184] FileBasedKeyValueStore.delete: Attempt to delete 'params1Fzx-vZz47HyPCTxqb1ncg' failed!
D/Finsky ( 3130): [1] GetBillingCountriesAction.run: Skip getting fresh list of billing countries.
I/SurfaceFlinger( 1834): id=47 Removed idx=1 Map Size=4
I/SurfaceFlinger( 1834): id=47 Removed idx=-2 Map Size=4
I/power ( 2004): *** release_dvfs_lock : lockType : 1
D/PowerManagerService( 2004): releaseDVFSLockLocked : all DVFS_MIN_LIMIT are released
W/ActivityManager( 2004): mDVFSLock.release()
I/ACTIVITY-IS-FINISHING( 4462): false com.satalyst.android.ui.MainActivity@416d9098
I/ACTIVITY-IS-FINISHING( 4462): false com.satalyst.android.ui.MainActivity@416d9098
I/ACTIVITY-IS-FINISHING( 4462): false com.satalyst.android.ui.MainActivity@416d9098
I/ACTIVITY-DESTROY( 4462): com.satalyst.android.ui.MainActivity@416d9098
D/com.satalyst.android.ui.MainActivity( 4462): Destroying helper.
D/IabHelper( 4462): Disposing.
D/IabHelper( 4462): Unbinding from service.
D/STATUSBAR-NetworkController( 2127): onDataActivity: direction=3
E/DataRouter( 1832): usb connection is true
E/DataRouter( 1832): DSR is ON. Don't send DTR ON.
E/Finsky ( 3130): [1] CheckoutPurchase.setError: type=PURCHASE_FAILED, code=-1, permissionCode=4, message=The item you requested is not available for purchase
