Problems with offline mode

[Lakedaemon]

I have been using openIAB for a while now and implemented it through fragments
lots users have made purchases through Google play
some through Amazon
It works quite well

Yet, 3 of my users have reported that it doesn't work so great in offline mode.
Luckily I'm able to reproduce the issue they have on my phone :

Basically, after a reboot in offline mode, the purchase is recognized and I can use the app in premium mode a while yet if I change the screen orientation or if I exit the app and reenter it, the purchase is not recognized anymore, I gor an error code 6 (error refreshing inventory (querying prices of items))

This lasts till I go out of offline mode... then the purchase is recognized instantly and all goes well

This is quite a big problem for my app, because when it goes from free to premium or from premium to free, (which is supposed to happen only once, when a purchase is made) there is a lot of computation and wait for the user (30s) because the data cached on disk has to be processed and changed...

And also, if premium features aren't recognized, these calculation happen at each app start :/
This makes it quire horrible to use (and I get some bad reviews)

I think that the issue might come from 3 places :

1. google play doesn't cache it's purchase inventory after a reboot in offline mode or it is corrupt (very unlickely)
2. openIAB fails at some point in reboot in offline mode after a configuration change/relaunch and if some static variable has a corrupt value, it keeps on doing so while in offline mode afterwards
3. my code fails in reboot in offline mode too

I'm using openIAB 0.9.8.6+

Here is my fragment (kotlin code, versy similar to java)

final class OpenBillingFragment() : Fragment(), IabHelper.OnIabSetupFinishedListener, IabHelper.QueryInventoryFinishedListener, IabHelper.OnIabPurchaseFinishedListener {

    /** Create the helper, passing it our context
     * and the public key to verify signatures with */
    private var helper: OpenIabHelper? = null

    /** errors */
    private val errors = ArrayList<String>()

    fun addError(string: String) {
        if (errors.size() >= 5) errors.remove(0)
        errors.add(string)
        L.info(string)
    }

    fun addError(e: Exception) = addError(e.format())


    fun debug() :String ="""helper : ${helper != null}
    installer ${appContext.getPackageManager().getInstallerPackageName(App.dPackageName)}
    setup : ${helper?.setupSuccessful()} (${helper?.getSetupState() ?: ""})
    connected store : ${helper?.getConnectedAppstoreName() ?: ""}
    """


    var launchBuyAfterSetup = false


    final override fun onCreate(savedInstanceState: Bundle?) {
        super<Fragment>.onCreate(savedInstanceState)
        setHasOptionsMenu(true)
        setRetainInstance(true)
    }



    override fun onAttach(activity: Activity?) {
        super<Fragment>.onAttach(activity)
        helper = OpenIabHelper(activity, InAppBuyD.options)
        try {
            L.info("loggable ${Logger.isLoggable()}")
            helper?.startSetup(this)
        } catch (e: Exception) {
            L.info("setup fail_1")
            addError(e)
            addToAcra(KEY_OB_ATTACH, e)
        } // binding the service
    }

    final override fun onIabSetupFinished(result: IabResult?): Unit = if (result?.isSuccess() ?: false) {
        try {
            L.info("setup success")
            helper?.queryInventoryAsync(this)
        } catch (e: Exception) {
            addError(C.res(R.string.inAppBuyUnavailable) + e.format())
            addToAcra(KEY_OB_SETUP_FINISHED, e)
            asyncUpdateMenu()
        }
    } else {
        L.info("setup fail")
        addError(C.res(R.string.failedToSetupBillingToast) + "\n" + result.toString() +"\n" +debug())
        addToAcra(KEY_OB_SETUP_FINISHED, message = "bad setup<br>" + result.toString()+"<br>"+debug())
        asyncUpdateMenu()
    }

    fun asyncUpdateMenu(): Unit = Observable.just(Unit)
            .subscribeOn(Schedulers.immediate())
            .observeOn(AndroidSchedulers.mainThread())
            .subscribe({ getSupportActivity()?.supportInvalidateOptionsMenu() }, { L.info("updateMenu", it) }).toUnit()

    override fun onQueryInventoryFinished(result: IabResult?, inventory: Inventory?) = Observable.just(Unit)
            .subscribeOn(Schedulers.immediate())
            .observeOn(AndroidSchedulers.mainThread())
            .subscribe({
                val oldValue = Skus.isDictPremium
                Skus.isDictPremium = if ( inventory == null || (result?.isFailure() ?: true)) {
                    addToAcra(KEY_INVENTORY_FINISHED, message = "result:$result inventory:$inventory")
                    getSupportActivity()?.uiShowToast(C.res(R.string.purchaseStatusError) + (if (result == null) "" else "\n" + result.getMessage()))
                    false
                } else inventory.getPurchase(Skus.PREMIUM_FEATURES_0)?.verify() ?: false

                addToAcra(KEY_IS_PREMIUM, message = "$oldValue -> ${Skus.isDictPremium}")
                getSupportActivity()?.supportInvalidateOptionsMenu()

                handleBuildChange(oldValue)

                if (launchBuyAfterSetup) {// even for premium
                    launchBuyAfterSetup = false
                    uiLaunchPurchaseFlow()
                }
            }, { L.info("onQuerryFinished", it) }).toUnit()


    private fun handleBuildChange(oldValue:Boolean) :Unit = if (oldValue != Skus.isDictPremium) startbuildForcefullyD() else startbuildIfNecessary()

    fun handleBillingResultFromActivity(requestCode: Int, resultCode: Int, data: Intent?):Boolean {
        val resultBoolean = helper?.handleActivityResult(requestCode, resultCode, data)
        when (resultBoolean) {
            true -> L.info("onActivityResult handled by IABUtil.")
            else -> {
                //if (requestCode != REQUEST_CODE) samsung inApp billing uses other request code
                addError("InAppBuyActivity Returned with result : " + resultCode + data.toString())

                // not handled, so handle it ourselves (here's where you'd
                // perform any handling of activity results not related to in-app
                // billing...
                super<Fragment>.onActivityResult(requestCode, resultCode, data);
            }
        }
        asyncUpdateMenu()
        return resultBoolean ?: false
    }

    final override fun onCreateOptionsMenu(menu: Menu?, inflater: MenuInflater?) {
        inflater?.inflate(R.menu.billing, menu)
        super<Fragment>.onCreateOptionsMenu(menu, inflater)
    }

    final override fun onPrepareOptionsMenu(menu: Menu?) {
        val notBuilt = getSupportFragmentManager()?.findFragmentByTag(RxActivity.WATCHER) != null
        menu?.findItem(R.id.menuErrors)?.setVisible(!notBuilt && !Skus.isDictPremium && errors.size() > 0)
        menu?.findItem(R.id.menuBuyPremium)?.setVisible(!notBuilt && !Skus.isDictPremium)
        menu?.findItem(R.id.menuCheckAppLicense)?.setVisible(false)
        super<Fragment>.onPrepareOptionsMenu(menu)
    }

    final override fun onOptionsItemSelected(item: MenuItem?): Boolean = when (item!!.getItemId()) {
        R.id.menuBuyPremium -> {
            uiLaunchPurchaseFlow()
            true
        }
        R.id.menuErrors -> {
            val activity = getSupportActivity()
            val inflater = LayoutInflater.from(activity)
            val convertView = inflater.inflate(R.layout.listview, null)
            val lv = convertView?.findViewById(android.R.id.list) as? ListView
            lv?.setAdapter(ArrayAdapter(activity, android.R.layout.simple_list_item_1, errors))
            AlertDialog.Builder(activity).setView(convertView).setTitle(R.string.object_Errors)
                    .setPositiveButton(R.string.actionClear, fun(d: DialogInterface, r: Int) {
                        errors.clear()
                        getSupportActivity()?.supportInvalidateOptionsMenu()
                        d.dismiss()
                    })
                    .show()
            true
        }
        else -> super<Fragment>.onOptionsItemSelected(item)
    }

    fun uiLaunchPurchaseFlow() :Unit = if (!Skus.isDictPremium) try {
        if (helper?.setupSuccessful() == true) helper?.launchPurchaseFlow(getSupportActivity(), Skus.PREMIUM_FEATURES_0, REQUEST_CODE, this, PAYLOAD)
        else getSupportActivity()?.uiShowToast(R.string.failedToSetupBillingToast)
    } catch (e: Exception) {
        addToAcra(KEY_OB_DISPLAY, e)
        addError(e)
        getSupportActivity()?.uiShowToast(getString(R.string.inAppErrorToast) + "\n" + e.getMessage())
    }

    final override fun onIabPurchaseFinished(result: IabResult?, purchase: Purchase?): Unit = Observable.just(Unit)
            .subscribeOn(Schedulers.immediate())
            .observeOn(AndroidSchedulers.mainThread())
            .subscribe({
                val oldValue = Skus.isDictPremium
                val message: String =
                        if (result != null && result.isSuccess() && purchase != null && purchase.getSku() == Skus.PREMIUM_FEATURES_0) {
                            // TODO report sku change (for downloading files)
                            Skus.isDictPremium = purchase.verify()

                            when (purchase.getPurchaseState()) {
                                0 -> C.res(R.string.purchasePurchased)
                                1 -> C.res(R.string.purchaseCanceled)
                                else -> C.res(R.string.purchaseRefounded)
                            }
                        } else {
                            addToAcra(KEY_OB_PURCHASE_ERROR, message = (result?.getMessage()?:"result ") + (purchase?.toString() ?:"purchase "))
                            C.res(R.string.purchaseError) + if (result == null) "" else "\n" + result.getMessage()
                        }
                addToAcra(KEY_IS_PREMIUM, message = "$oldValue -> ${Skus.isDictPremium}")
                getSupportActivity()?.uiShowToast(message)
                getSupportActivity()?.supportInvalidateOptionsMenu()
                handleBuildChange(oldValue)
            }, { L.info("toast Error", it) }).toUnit()

    final override fun onDetach() {
        try {
            helper?.dispose()
            helper = null
        } catch (e: Exception) {
            addToAcra(KEY_OB_DETACH, e)
            L.info("onDetach error", e)
        }
        super<Fragment>.onDetach()
    }

    fun FragmentActivity.uiShowToast(charSequence: CharSequence, isLong: Boolean = false): Unit = if (isResumed() && !isFinishing()) Toast.makeText(this, charSequence, if (isLong) Toast.LENGTH_LONG else Toast.LENGTH_SHORT)?.show()
    fun FragmentActivity.uiShowToast(resId: Int, isLong: Boolean = false): Unit = uiShowToast(getString(resId), isLong)

    companion object {
        val KEY_OB_ATTACH = "OB:onAttach"
        val KEY_OB_SETUP_FINISHED = "OB:setupFinished"
        val KEY_INVENTORY_FINISHED = "OB:inventoryFinished"
        val KEY_OB_RESULT = "OB:activityResult"
        val KEY_OB_DISPLAY = "OB:display"
        val KEY_OB_DETACH = "OB:detach"
        val KEY_OB_PURCHASE_ERROR = "OB:purchaseError"
        val KEY_IS_PREMIUM = "OB:isPremium"

        private fun Purchase.verify(): Boolean = getDeveloperPayload() == PAYLOAD && getPurchaseState() == 0
    }

and I have this in my activity :

    override fun onActivityResult(requestCode: Int, resultCode: Int, data: Intent?) {
        val fragment = getSupportFragmentManager().findFragmentByTag(LicensingFragment.TAG)
        if (fragment !is OpenBillingFragment || !fragment.handleBillingResultFromActivity(requestCode, resultCode, data)) super<ActionBarActivity>.onActivityResult(requestCode, resultCode, data)
    }

[Lakedaemon]

I turned logging on (I checked , I'm using 0.9.8.6) and removed the App from the backup/restore process to see if it was the cause of the weird behavior.
But it doesn't change anything. I get the same responses and the logs look ok :

03-28 10:23:37.890 4308-4308/? I/org.lakedaemon﹕ setup success
03-28 10:23:37.890 4308-6589/? D/OpenIAB﹕ Package name: org.lakedaemon.japanese.dictionary
03-28 10:23:37.890 4514-4525/? D/Finsky﹕ [288] InAppBillingUtils.pickAccount: org.lakedaemon.japanese.dictionary: Account determined from installer data - [lDca-ej3zTH8dg_L_MhQdKWvLPg]
03-28 10:23:37.900 4514-4524/? D/Finsky﹕ [287] InAppBillingUtils.pickAccount: org.lakedaemon.japanese.dictionary: Account determined from installer data - [lDca-ej3zTH8dg_L_MhQdKWvLPg]

Next, I'm going to build a custom openIAB lib, with more debug print statements to try to understand what happens here....

[Lakedaemon]

I rebooted in offline mode and could use the app for a long while in premium mode
(I could create a lot of activities without my OpenBillingFragment, all was fine, including configuration change -> no openIAB calls there)...
Then...I pressed back... to my main activity (with an OpenBillingFragment) and left the app.
Next time, I opened the app and the issue was here.
I did the same test but instead of leaving the app, I change the orientation of the screen -> I have the same issue

Apparently, the issu happens when I have the 3 following items

1. Rebooting in offline mode (the issue doesn't happen if you go into offline mode after having been online)
2. destroying phase of an activity with my OpenBillingFragment (as the starting phase went well)
3. staying in Offline mode (going online fixes the issue)

-> My best bet would be that openIAB is doing some caching or sets a static variable and something gets wrong with the configuration change/activity destroyed (maybee because of my code or not : the helper gets destroyed in on Detach and another one gets created the next time in onAttach) and that cache/variable then prevents googlePlay (in offline mode) to tell the App that it has made the purchase

[Lakedaemon]

Silly me, I always forget that when logging is set to true, you have to filter for OpenIAB.
Here are the logs (with a google error at the bottom)

03-28 12:51:08.045 8677-8677/? D/OpenIAB﹕ setupWithStrategy() store search strategy = 2
03-28 12:51:08.045 8677-8677/? D/OpenIAB﹕ setupWithStrategy() package name = org.lakedaemon.japanese.dictionary
03-28 12:51:08.045 8677-8677/? D/OpenIAB﹕ setupWithStrategy() package installer = null
03-28 12:51:08.075 8677-8677/? D/OpenIAB﹕ packageInstalled() is true for com.sec.android.app.samsungapps
03-28 12:51:08.075 8677-8677/? D/OpenIAB﹕ packageInstalled() is false for net.skubit.android
03-28 12:51:08.085 8677-8677/? D/OpenIAB﹕ packageInstalled() is true for com.android.vending
03-28 12:51:08.215 8677-8677/? D/OpenIAB﹕ packageInstalled() is false for com.amazon.venezia
03-28 12:51:08.220 8677-8677/? D/OpenIAB﹕ packageInstalled() is false for com.skubit.android
03-28 12:51:08.220 8677-8677/? D/OpenIAB﹕ packageInstalled() is false for com.nokia.payment.iapenabler
03-28 12:51:09.175 8677-8677/? D/OpenIAB﹕ handleActivityResult() requestCode: 899 resultCode: 2 data: null
03-28 12:51:09.175 8677-8871/? D/OpenIAB﹕ isBillingAvailable() interruptedfalse
03-28 12:51:09.175 8677-8871/? D/OpenIAB﹕ isBillingAvailable() packageName: org.lakedaemon.japanese.dictionary
03-28 12:51:09.220 8677-8677/? D/OpenIAB﹕ isBillingAvailable() Google Play result: true
03-28 12:51:09.220 8677-8677/? D/OpenIAB﹕ IAB helper created.
03-28 12:51:09.220 8677-8677/? D/OpenIAB﹕ finishSetup() === SETUP DONE === result: IabResult: 0, Setup ok (response: 0:OK) Appstore: Store {name: com.google.play}
03-28 12:51:09.220 8677-8677/? D/OpenIAB﹕ dispose() was called for com.samsung.apps
03-28 12:51:09.220 8677-8677/? D/OpenIAB﹕ Starting in-app billing setup.
03-28 12:51:09.240 8677-8677/? D/OpenIAB﹕ Billing service connected.
03-28 12:51:09.240 8677-8677/? D/OpenIAB﹕ Checking for in-app billing 3 support.
03-28 12:51:09.245 8677-8677/? D/OpenIAB﹕ In-app billing version 3 supported for org.lakedaemon.japanese.dictionary
03-28 12:51:09.250 8677-8677/? D/OpenIAB﹕ Subscriptions AVAILABLE.
03-28 12:51:09.250 8677-8677/? D/OpenIAB﹕ Setup successful.
03-28 12:51:09.250 8677-8881/? D/OpenIAB﹕ Querying owned items, item type: inapp
03-28 12:51:09.250 8677-8881/? D/OpenIAB﹕ Package name: org.lakedaemon.japanese.dictionary
03-28 12:51:09.250 8677-8881/? D/OpenIAB﹕ Calling getPurchases with continuation token: null
03-28 12:51:09.255 8677-8881/? D/OpenIAB﹕ Owned items response: 0
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ Sku is owned: premium_features_0
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ getSku() restore sku from storeSku: premium_features_0 -> premium_features_0
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ Continuation token: null
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ querySkuDetails() Querying SKU details.
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ getStoreSku() using mapping for sku: premium_features_0 -> premium_features_0
03-28 12:51:09.260 8677-8881/? D/OpenIAB﹕ querySkuDetails() batches: 1, [[premium_features_0]]
03-28 12:51:09.310 8677-8881/? D/OpenIAB﹕ getSkuDetails() failed: 6:Error
03-28 12:51:09.310 8677-8881/? E/OpenIAB﹕ queryInventoryAsync() Error :
org.onepf.oms.appstore.googleUtils.IabException: Error refreshing inventory (querying prices of items). (response: 6:Error)
at org.onepf.oms.appstore.googleUtils.IabHelper.queryInventory(IabHelper.java:588)
at org.onepf.oms.OpenIabHelper.queryInventory(OpenIabHelper.java:1410)
at org.onepf.oms.OpenIabHelper$17.run(OpenIabHelper.java:1462)
at java.lang.Thread.run(Thread.java:841)

[Lakedaemon]

Ok... in my experiments, the bundle I get when openIAB queries Google play for inventory doesn't have the key RESPONSE_GET_SKU_DETAILS_LIST and looks empty.

-> issue not with my code, nor with openIAB but looks in Google code :
If you reboot in offline mode, google play doesn't seem to have the result of previous purchases anymore. What the fuck Google !

This is not how it should be. Something is really wrong here.

[Lakedaemon]

Ok, more research. This is definately not an openIAB issue (nor in my code). After some research, I found that some people had the same issue, see here https://plus.google.com/104159232075086758727/posts

That led me to stack overflow :
http://stackoverflow.com/questions/15471131/in-app-billing-v3-unable-to-query-items-without-network-connection-or-in-airplan/

I found that in my case after initially having a connection and then testing in airplane mode works. Whereas before it wasn't for me. I did find that after a long time has passed that I'm not able to query for the items. I think that's the way it's designed but haven't been able to confirm. 

Also after the reboot I seem to lose the item. Cannot find any other documentation talking on this. 

Their explanation makes sense : after a reboot in offline mode, google play can't query the server for an inventory. It may have the list of purchases from the user saved locally. But then,
querying the inventory will definately fail....when querying the purchases whose keys you know might succeed.

I'll experiment and see if I can make it work...

[Lakedaemon]

Ok, so the solution was just to call

helper.queryInventoryAsync(false, mGotInventoryListener)

instead of

helper?.queryInventoryAsync(mGotInventoryListener)

like the wiki page/documentation suggested

It just took me 11 hours to figure out.... :/

Could someone please update the openIAB documentation and close the issue, please ?

[RomanZhilich]

Looks like the issue comes from Google.
As I understand it, it suppose to cache user purchases in GooglePlay data base, and return purchased items even in offline mode. However, it seems to clear cache if it fails to load sku details. This might be due to the fact that local prices change daily according to currency fluctuations.

I'm not sure you solution (not querying sku details) is the best here. What you should probably do - cache user purchases locally (SharedPreferences is probably the easiest way) and use this value if inventory request fails.

Could someone please update the openIAB documentation and close the issue, please ?

@akarimova Can you please document this Google behavior?

P.S. thanks for writing such detailed messages.

[Lakedaemon]

You may be right about daily price changes, it would make sense.

Also, thanks for the suggestion. Yet, I would rather avoid caching results in my app if I can because it can quickly become a major headache, with different appStore practices, people able to ask for refound sometimes 15 days after a purchase, people clearing the app data or deinstalling and installing the app again... I would rather delegate the license check/purchase check to the appStores.

Also, I'm not that interested in the sku details (price and all). But I really need to know quite reliably if a particular sku has been bought or not. So that solution migt be enough for my use case. I'll test some more to see if it is.