j3k0 / cordova-plugin-purchase

In-App Purchase for Cordova on iOS, Android and Windows
https://purchase.cordova.fovea.cc
1.3k stars 537 forks source link

[ANDROID] Product is returning as "invalid" on Android 9 #718

Closed Cycododge closed 5 years ago

Cycododge commented 6 years ago

System Info

Compiled via: Windows 10
minTargetSdk: 27
cordova: 8.0.0
cordova-android: 7.1.0
cordova-android-play-services-gradle-release: 1.4.3
Device: Google Pixel 2, Android 9.0
Plugin Version: 7.1.3

Expected behavior

Product data should be returned.

Observed behavior

App running on Android versions prior to 9 return product data correctly. Recent Android 9 upgrade on device running same version of app does not return correct data.

Steps to reproduce

  1. Running cordova debug mode via Pixel 2 (Android 9)
  2. Using chrome:inspect, set store.verbosity = 4 in dev tools.
  3. Run store.refresh() in dev tools.

The following prints:

[store.js] DEBUG: store.trigger -> triggering action refreshed store-android.js:1496 [store.js] DEBUG: queries !! 'refreshed' store-android.js:2023 InAppBilling[js]: setup ok store-android.js:2023 InAppBilling[js]: load ["cycosoft.dtrack.pro"] undefined store-android.js:1496 [store.js] DEBUG: plugin -> ready store-android.js:2023 InAppBilling[js]: getAvailableProducts called! store-android.js:1496 [store.js] DEBUG: plugin -> loaded - [] store-android.js:1496 [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro invalid' store-android.js:1496 [store.js] DEBUG: store.queries !! 'non consumable invalid' store-android.js:1496 [store.js] DEBUG: store.queries !! 'invalid invalid' store-android.js:1496 [store.js] DEBUG: store.queries !! 'invalid' store-android.js:1496 [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'non consumable updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'invalid updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro loaded' store-android.js:1496 [store.js] DEBUG: store.queries !! 'non consumable loaded' store-android.js:1496 [store.js] DEBUG: store.queries !! 'invalid loaded' store-android.js:1496 [store.js] DEBUG: store.queries !! 'loaded' store-android.js:1496 [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'non consumable updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'invalid updated' store-android.js:1496 [store.js] DEBUG: store.queries !! 'updated' store-android.js:2023 InAppBilling[js]: getPurchases called!

  1. Running store.products[0] returns:
    {
    additionalData: null,
    alias: "cycosoft.dtrack.pro",
    canPurchase: false,
    currency: null,
    description: null,
    downloaded: false,
    downloading: false,
    id: "cycosoft.dtrack.pro",
    loaded: true,
    owned: false,
    price: null,
    priceMicros: null,
    state: "invalid",
    title: null,
    transaction: null,
    type: "non consumable",
    valid: false
    }
Dexus commented 6 years ago

Hi @Cycododge

I request you to send some more logs, use android studio and connect your phone to your system and deploy the debug apk to the phone and send the logs for the app.

Thanks!

Cycododge commented 6 years ago

Thank you for your response.

Here is the log output when launching the app.

UPDATED IN NEXT COMMENT

Here is the log when restoring a purchase.

UPDATED IN NEXT COMMENT

Here is the log when clicking the purchase button. This action also produces an on screen error of, "Error retrieving information from server. [DF-AA-20]"

UPDATED IN NEXT COMMENT
Cycododge commented 6 years ago

UPDATE

I realized I was testing with an incorrect app id, and have also updated the following dependencies:

cordova: 8.1.1 cc.fovea.cordova.purchase: 7.2.0

Here are the new results.

  1. App does not load IAB data on load, but store.register() prints the following with DEBUG = 4.

    [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro registered'
    store-android.js:1513 [store.js] DEBUG: store.queries !! 'non consumable registered'
    store-android.js:1513 [store.js] DEBUG: store.queries !! 'registered'
    store-android.js:1513 [store.js] DEBUG: store.queries !! 'cycosoft.dtrack.pro updated'
    store-android.js:1513 [store.js] DEBUG: store.queries !! 'non consumable updated'
    store-android.js:1513 [store.js] DEBUG: store.queries !! 'updated'
  2. I can successfully restore a purchase, and get the product details (see log below).

Log On Load (unrestored purchase)

app start 1

2018-09-28 17:29:19.846 694-21022/? W/DnsTlsSocket: SSL_connect error 5, errno=111
2018-09-28 17:29:20.578 778-875/? I/CHRE: @ 703116.562: [AR_CHRE] IDLE => ON
2018-09-28 17:29:20.593 7976-7976/? I/PhenotypeExpConfig: refreshConfiguration() : Force = false : UpdateAvailable = false : Age = 634 minutes : MaxAge = 720 minutes
2018-09-28 17:29:20.599 7976-7976/? I/LatinIme: onDeactivate()

    --------- beginning of system
2018-09-28 17:29:20.648 1160-2712/? I/ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.phonegap.dtrack/.MainActivity (has extras)} from uid 10163
2018-09-28 17:29:20.655 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON
2018-09-28 17:29:20.673 1160-1203/? I/ActivityManager: Start proc 27020:com.phonegap.dtrack/u0a248 for activity com.phonegap.dtrack/.MainActivity
2018-09-28 17:29:20.674 27020-27020/? I/phonegap.dtrac: Late-enabling -Xcheck:jni
2018-09-28 17:29:20.710 8194-26625/? E/NetworkScheduler: Invalid component specified.
2018-09-28 17:29:20.743 27020-27020/com.phonegap.dtrack I/phonegap.dtrac: The ClassLoaderContext is a special shared library.
2018-09-28 17:29:20.769 8209-8231/? W/gle.android.gm: Couldn't lock the profile file /data/user/0/com.google.android.gms/cache/oat/1526594665595.jar.cur.prof: Failed to open file '/data/user/0/com.google.android.gms/cache/oat/1526594665595.jar.cur.prof': No such file or directory
2018-09-28 17:29:20.769 8209-8231/? W/gle.android.gm: Could not forcefully load profile /data/user/0/com.google.android.gms/cache/oat/1526594665595.jar.cur.prof
2018-09-28 17:29:20.874 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: JIT profile information will not be recorded: profile file does not exits.
2018-09-28 17:29:20.876 27020-27020/com.phonegap.dtrack I/chatty: uid=10248(com.phonegap.dtrack) identical 10 lines
2018-09-28 17:29:20.876 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: JIT profile information will not be recorded: profile file does not exits.
2018-09-28 17:29:20.890 27020-27020/com.phonegap.dtrack I/InstantRun: starting instant run server: is main process
2018-09-28 17:29:20.910 27020-27037/com.phonegap.dtrack D/libEGL: loaded /vendor/lib64/egl/libEGL_adreno.so
2018-09-28 17:29:20.916 27020-27037/com.phonegap.dtrack D/libEGL: loaded /vendor/lib64/egl/libGLESv1_CM_adreno.so
2018-09-28 17:29:20.928 27020-27037/com.phonegap.dtrack D/libEGL: loaded /vendor/lib64/egl/libGLESv2_adreno.so
2018-09-28 17:29:20.934 27020-27020/com.phonegap.dtrack I/CordovaLog: Changing log level to DEBUG(3)
2018-09-28 17:29:20.934 27020-27020/com.phonegap.dtrack I/CordovaActivity: Apache Cordova native platform version 7.1.0 is starting
2018-09-28 17:29:20.934 27020-27020/com.phonegap.dtrack D/CordovaActivity: CordovaActivity.onCreate()
2018-09-28 17:29:20.967 27020-27020/com.phonegap.dtrack I/WebViewFactory: Loading com.android.chrome version 69.0.3497.100 (code 349710052)
2018-09-28 17:29:20.999 27020-27020/com.phonegap.dtrack I/cr_LibraryLoader: Time to load native libraries: 3 ms (timestamps 899-902)
2018-09-28 17:29:21.006 27020-27041/com.phonegap.dtrack E/cr_VariationsUtils: Failed reading seed file "/data/user/0/com.phonegap.dtrack/app_webview/variations_seed_new": /data/user/0/com.phonegap.dtrack/app_webview/variations_seed_new (No such file or directory)
2018-09-28 17:29:21.026 27020-27020/com.phonegap.dtrack I/chromium: [INFO:library_loader_hooks.cc(36)] Chromium logging enabled: level = 0, default verbosity = 0
2018-09-28 17:29:21.026 27020-27020/com.phonegap.dtrack I/cr_LibraryLoader: Expected native library version number "69.0.3497.100", actual native library version number "69.0.3497.100"
2018-09-28 17:29:21.032 27020-27042/com.phonegap.dtrack W/cr_ChildProcLH: Create a new ChildConnectionAllocator with package name = com.android.chrome, sandboxed = true
2018-09-28 17:29:21.040 27020-27020/com.phonegap.dtrack I/cr_BrowserStartup: Initializing chromium process, singleProcess=false
2018-09-28 17:29:21.047 1160-1203/? I/ActivityManager: Start proc 27045:com.android.chrome:sandboxed_process0/u0i591 for webview_service com.phonegap.dtrack/org.chromium.content.app.SandboxedProcessService0
2018-09-28 17:29:21.048 27045-27045/? E/dboxed_process: Not starting debugger since process cannot load the jdwp agent.
2018-09-28 17:29:21.061 27020-27020/com.phonegap.dtrack I/chromium: [INFO:aw_field_trial_creator.cc(54)] First-WebView-Experiment not found
2018-09-28 17:29:21.075 27045-27045/? I/cr_ChildProcessService: Creating new ChildProcessService pid=27045
2018-09-28 17:29:21.107 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker;-><init>(Landroid/content/Context;I)V (light greylist, reflection)
2018-09-28 17:29:21.107 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker;->logEvent(Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;)V (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionStarted(I)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionModified(II)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionModified(IILandroid/view/textclassifier/TextClassification;)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionModified(IILandroid/view/textclassifier/TextSelection;)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionAction(III)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.108 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Accessing hidden method Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent;->selectionAction(IIILandroid/view/textclassifier/TextClassification;)Landroid/view/textclassifier/logging/SmartSelectionEventTracker$SelectionEvent; (light greylist, reflection)
2018-09-28 17:29:21.114 27020-27020/com.phonegap.dtrack D/IonicWebViewEngine: Ionic Web View Engine Starting Right Up 1...
2018-09-28 17:29:21.142 27020-27020/com.phonegap.dtrack D/SystemWebViewEngine: CordovaWebView is running on device made by: Google
2018-09-28 17:29:21.151 27020-27020/com.phonegap.dtrack D/PluginManager: init()
2018-09-28 17:29:21.174 27020-27020/com.phonegap.dtrack D/CordovaWebViewImpl: >>> loadUrl(file:///android_asset/www/index.html)
2018-09-28 17:29:21.180 27020-27083/com.phonegap.dtrack I/Adreno: QUALCOMM build                   : 7bf2852, Ie32bfa6f6f
    Build Date                       : 06/03/18
    OpenGL ES Shader Compiler Version: EV031.24.00.00
    Local Branch                     : googdrp
    Remote Branch                    : 
    Remote Branch                    : 
    Reconstruct Branch               : 
2018-09-28 17:29:21.180 27020-27083/com.phonegap.dtrack I/Adreno: Build Config                     : S L 4.0.10 AArch64
2018-09-28 17:29:21.180 27020-27067/com.phonegap.dtrack W/cr_media: Requires BLUETOOTH permission
2018-09-28 17:29:21.186 27020-27020/com.phonegap.dtrack D/CordovaActivity: Started the activity.
2018-09-28 17:29:21.187 27020-27020/com.phonegap.dtrack D/CordovaActivity: Resumed the activity.
2018-09-28 17:29:21.188 27020-27020/com.phonegap.dtrack D/OpenGLRenderer: Skia GL Pipeline
2018-09-28 17:29:21.188 27020-27083/com.phonegap.dtrack I/Adreno: PFP: 0x005ff110, ME: 0x005ff066
2018-09-28 17:29:21.191 27020-27083/com.phonegap.dtrack I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 1
2018-09-28 17:29:21.192 27020-27083/com.phonegap.dtrack I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 0
2018-09-28 17:29:21.214 27020-27020/com.phonegap.dtrack D/CordovaWebViewImpl: onPageDidNavigate(file:///android_asset/www/index.html)
2018-09-28 17:29:21.217 27045-27071/? I/cr_LibraryLoader: Time to load native libraries: 0 ms (timestamps 1120-1120)
2018-09-28 17:29:21.218 27045-27071/? I/chromium: [INFO:library_loader_hooks.cc(36)] Chromium logging enabled: level = 0, default verbosity = 0
2018-09-28 17:29:21.218 27045-27071/? I/cr_LibraryLoader: Expected native library version number "69.0.3497.100", actual native library version number "69.0.3497.100"
2018-09-28 17:29:21.229 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706433 for video/avc
2018-09-28 17:29:21.230 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706434 for video/avc
2018-09-28 17:29:21.232 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706433 for video/avc
2018-09-28 17:29:21.232 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706434 for video/avc
2018-09-28 17:29:21.241 27020-27085/com.phonegap.dtrack I/OpenGLRenderer: Initialized EGL, version 1.4
2018-09-28 17:29:21.241 27020-27085/com.phonegap.dtrack D/OpenGLRenderer: Swap behavior 1
2018-09-28 17:29:21.247 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 4 for video/hevc
2018-09-28 17:29:21.267 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706433 for video/avc
2018-09-28 17:29:21.267 27020-27083/com.phonegap.dtrack W/VideoCapabilities: Unrecognized profile 2130706434 for video/avc
2018-09-28 17:29:21.277 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/
2018-09-28 17:29:21.278 1160-1210/? I/ActivityManager: Displayed com.phonegap.dtrack/.MainActivity: +615ms
2018-09-28 17:29:21.281 27020-27020/com.phonegap.dtrack D/CordovaWebViewImpl: onPageDidNavigate(http://localhost:8080/)
2018-09-28 17:29:21.282 27020-27083/com.phonegap.dtrack I/VideoCapabilities: Unsupported profile 4 for video/mp4v-es
2018-09-28 17:29:21.285 27020-27095/com.phonegap.dtrack W/cr_CrashFileManager: /data/user/0/com.phonegap.dtrack/cache/WebView/Crash Reports does not exist or is not a directory
2018-09-28 17:29:21.289 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH OFF
2018-09-28 17:29:21.323 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/polyfills.js
2018-09-28 17:29:21.325 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/roboto.css
2018-09-28 17:29:21.325 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/cordova.js
2018-09-28 17:29:21.327 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/material.css
2018-09-28 17:29:21.327 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/app.e5a8351b.css
2018-09-28 17:29:21.327 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/app.89fe0fca.js
2018-09-28 17:29:21.328 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-vendors.4068f3a6.css
2018-09-28 17:29:21.329 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/index.css
2018-09-28 17:29:21.329 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-vendors.a856994c.js
2018-09-28 17:29:21.347 27020-27020/com.phonegap.dtrack D/JsMessageQueue: Set native->JS mode to EvalBridgeMode
2018-09-28 17:29:21.353 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-04537248.abf1d58e.css
2018-09-28 17:29:21.355 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-0e05d038.3fd8331f.css
2018-09-28 17:29:21.367 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-18c1e08e.f2b0e052.css
2018-09-28 17:29:21.368 27045-27071/? E/chromium: [ERROR:budget_service.cc(145)] Unable to connect to the Mojo BudgetService.
2018-09-28 17:29:21.368 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-1b181372.db709644.css
2018-09-28 17:29:21.370 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-2ce7b9ff.48ed6c17.css
2018-09-28 17:29:21.372 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-4b0a98d8.ed6b006b.css
2018-09-28 17:29:21.374 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-58a15dae.2f0434fb.css
2018-09-28 17:29:21.378 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-5b59662e.f2b0e052.css
2018-09-28 17:29:21.417 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/cordova_plugins.js
2018-09-28 17:29:21.418 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-7899d70b.5a8291b3.css
2018-09-28 17:29:21.420 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-7b504c3a.31be6f99.css
2018-09-28 17:29:21.421 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-a1e3ea2e.f2b0e052.css
2018-09-28 17:29:21.422 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-c13154ea.61f571be.css
2018-09-28 17:29:21.422 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/roboto/roboto-v18-latin-regular.woff2
2018-09-28 17:29:21.429 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-c3e8a6b8.9f86725e.css
2018-09-28 17:29:21.429 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-da68848c.76bc2aba.css
2018-09-28 17:29:21.430 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-e16a7486.5165645e.css
2018-09-28 17:29:21.432 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/css/chunk-f228e58a.6ad38fcf.css
2018-09-28 17:29:21.433 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-04537248.6ab7f632.js
2018-09-28 17:29:21.435 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-0e05d038.c4bfb201.js
2018-09-28 17:29:21.442 611-644/? W/SurfaceFlinger: Attempting to set client state on removed layer: Splash Screen com.phonegap.dtrack#0
2018-09-28 17:29:21.442 611-644/? W/SurfaceFlinger: Attempting to destroy on removed layer: Splash Screen com.phonegap.dtrack#0
2018-09-28 17:29:21.452 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-admobpro/www/AdMob.js
2018-09-28 17:29:21.453 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/es6-promise-plugin/www/promise.js
2018-09-28 17:29:21.454 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-x-socialsharing/www/SocialSharing.js
2018-09-28 17:29:21.455 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-splashscreen/www/splashscreen.js
2018-09-28 17:29:21.456 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-statusbar/www/statusbar.js
2018-09-28 17:29:21.459 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-inappbrowser/www/inappbrowser.js
2018-09-28 17:29:21.462 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-app-version/www/AppVersionPlugin.js
2018-09-28 17:29:21.463 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-device/www/device.js
2018-09-28 17:29:21.464 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cc.fovea.cordova.purchase/www/store-android.js
2018-09-28 17:29:21.464 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-ionic-webview/src/www/util.js
2018-09-28 17:29:21.466 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/plugins/cordova-plugin-google-analytics/www/analytics.js
2018-09-28 17:29:21.469 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-18c1e08e.16377620.js
2018-09-28 17:29:21.470 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-2ce7b9ff.c1d581c7.js
2018-09-28 17:29:21.470 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-1b181372.78341e0a.js
2018-09-28 17:29:21.471 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-2d221b9a.21289557.js
2018-09-28 17:29:21.472 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-2d2223e7.b18275ac.js
2018-09-28 17:29:21.473 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-4b0a98d8.46eef30c.js
2018-09-28 17:29:21.475 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-58a15dae.df29c002.js
2018-09-28 17:29:21.477 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-5b59662e.1e784f5e.js
2018-09-28 17:29:21.477 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-7899d70b.268d3ecf.js
2018-09-28 17:29:21.478 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-7b504c3a.f58c3069.js
2018-09-28 17:29:21.478 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-c13154ea.5ad49707.js
2018-09-28 17:29:21.479 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-a1e3ea2e.6e666190.js
2018-09-28 17:29:21.480 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-c3e8a6b8.8295cb0b.js
2018-09-28 17:29:21.483 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-e16a7486.19b08f04.js
2018-09-28 17:29:21.483 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-da68848c.699fcf51.js
2018-09-28 17:29:21.484 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/js/chunk-f228e58a.145c80d6.js
2018-09-28 17:29:21.535 27020-27020/com.phonegap.dtrack D/CordovaWebViewImpl: onPageFinished(http://localhost:8080/#/)
2018-09-28 17:29:21.678 27020-27099/com.phonegap.dtrack I/GAv4: Google Analytics 12.4.51 is starting up. To enable debug logging on a device run:
      adb shell setprop log.tag.GAv4 DEBUG
      adb logcat -s GAv4
2018-09-28 17:29:21.700 27020-27099/com.phonegap.dtrack W/PluginManager: THREAD WARNING: exec() call to UniversalAnalytics.startTrackerWithId blocked the main thread for 31ms. Plugin should use CordovaInterface.getThreadPool().
2018-09-28 17:29:21.704 27020-27099/com.phonegap.dtrack W/CordovaPlugin: Attempted to send a second callback for ID: UniversalAnalytics1353533089
    Result was: "Invalid action"
2018-09-28 17:29:21.708 27020-27099/com.phonegap.dtrack W/CordovaPlugin: Attempted to send a second callback for ID: UniversalAnalytics1353533090
    Result was: "Invalid action"
2018-09-28 17:29:21.713 27020-27099/com.phonegap.dtrack D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2018-09-28 17:29:21.918 27020-27099/com.phonegap.dtrack D/GenericAdPlugin: createBanner: {ID_HERE}, true
2018-09-28 17:29:21.919 27020-27099/com.phonegap.dtrack W/PluginManager: THREAD WARNING: exec() call to AdMob.createBanner blocked the main thread for 209ms. Plugin should use CordovaInterface.getThreadPool().
2018-09-28 17:29:21.955 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Unsupported class loader
2018-09-28 17:29:21.957 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Skipping duplicate class check due to unsupported classloader
2018-09-28 17:29:22.010 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/roboto/roboto-v18-latin-500.woff2
2018-09-28 17:29:22.012 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/material/2fcrYFNaTjcS6g4U3t-Y5ZjZjT5FdEJ140U2DJYC3mY.woff2
2018-09-28 17:29:22.025 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/images/logo-no-text.svg
2018-09-28 17:29:22.032 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/fonts/roboto/roboto-v18-latin-italic.woff2
2018-09-28 17:29:22.048 27020-27020/com.phonegap.dtrack I/phonegap.dtrac: The ClassLoaderContext is a special shared library.
2018-09-28 17:29:22.050 27020-27020/com.phonegap.dtrack I/chatty: uid=10248(com.phonegap.dtrack) identical 1 line
2018-09-28 17:29:22.051 27020-27020/com.phonegap.dtrack I/phonegap.dtrac: The ClassLoaderContext is a special shared library.
2018-09-28 17:29:22.052 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.053 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.053 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.054 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.055 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.057 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.080 27020-27020/com.phonegap.dtrack I/DynamiteModule: Considering local module com.google.android.gms.ads.dynamite:0 and remote module com.google.android.gms.ads.dynamite:310
2018-09-28 17:29:22.080 27020-27020/com.phonegap.dtrack I/DynamiteModule: Selected remote version of com.google.android.gms.ads.dynamite, version >= 310
2018-09-28 17:29:22.095 27020-27020/com.phonegap.dtrack W/phonegap.dtrac: Unsupported class loader
2018-09-28 17:29:22.155 27020-27020/com.phonegap.dtrack D/DynamitePackage: Instantiated singleton DynamitePackage.
2018-09-28 17:29:22.155 27020-27020/com.phonegap.dtrack D/DynamitePackage: Instantiating com.google.android.gms.ads.ChimeraAdManagerCreatorImpl
2018-09-28 17:29:22.245 27020-27020/com.phonegap.dtrack I/Ads: Updating ad debug logging enablement.
2018-09-28 17:29:22.262 27020-27106/com.phonegap.dtrack I/phonegap.dtrac: The ClassLoaderContext is a special shared library.
2018-09-28 17:29:22.276 27020-27020/com.phonegap.dtrack I/Ads: Starting ad request.
2018-09-28 17:29:22.277 27020-27020/com.phonegap.dtrack I/Ads: SDK version: afma-sdk-a-v13283037.12451000.1
2018-09-28 17:29:22.278 27020-27020/com.phonegap.dtrack I/Ads: Use AdRequest.Builder.addTestDevice("ID_HERE") to get test ads on this device.
2018-09-28 17:29:22.299 27020-27137/com.phonegap.dtrack W/Ads: Invoke Firebase method getInstance error.
2018-09-28 17:29:22.299 27020-27137/com.phonegap.dtrack W/Ads: The Google Mobile Ads SDK will not integrate with Firebase. Admob/Firebase integration requires the latest Firebase SDK jar, but Firebase SDK is either missing or out of date
2018-09-28 17:29:22.304 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.305 27020-27065/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.306 27020-27070/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.306 27020-27065/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.306 27020-27065/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.308 27020-27069/com.phonegap.dtrack D/SERVER: Handling local request: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.308 27020-27108/com.phonegap.dtrack W/Ads: Update ad debug logging enablement as false
2018-09-28 17:29:22.311 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.317 27020-27065/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.318 27020-27065/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.318 27020-27065/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.324 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-16x16.png
2018-09-28 17:29:22.326 27020-27069/com.phonegap.dtrack E/WebViewAssetServer: Unable to open asset URL: http://localhost:8080/img/icons/favicon-32x32.png
2018-09-28 17:29:22.396 8209-8209/? W/Ads: #004 The webview is destroyed. Ignoring action.
2018-09-28 17:29:22.397 8209-8209/? W/Ads: #004 The webview is destroyed. Ignoring action.
2018-09-28 17:29:22.579 1493-1806/? V/WifiManager: registerSoftApCallback: callback=com.android.systemui.statusbar.policy.HotspotControllerImpl@bf507d5, handler=Handler (android.os.Handler) {3756bea}
2018-09-28 17:29:22.583 1493-1880/? V/WifiManager: SoftApCallbackProxy: onStateChanged: state=11, failureReason=0
2018-09-28 17:29:22.583 1493-1880/? V/WifiManager: SoftApCallbackProxy: onNumClientsChanged: numClients=0
2018-09-28 17:29:22.594 1493-1806/? V/WifiManager: registerSoftApCallback: callback=com.android.systemui.statusbar.policy.HotspotControllerImpl@bf507d5, handler=Handler (android.os.Handler) {3756bea}
2018-09-28 17:29:22.597 1493-8061/? V/WifiManager: SoftApCallbackProxy: onStateChanged: state=11, failureReason=0
2018-09-28 17:29:22.598 1493-8061/? V/WifiManager: SoftApCallbackProxy: onNumClientsChanged: numClients=0

Log on Restore

2018-09-28 17:33:43.474 27748-27825/com.phonegap.dtrack D/CordovaPurchase: Num SKUs Found: 1
2018-09-28 17:33:43.474 27748-27825/com.phonegap.dtrack D/CordovaPurchase: Product SKU Added: cycosoft.dtrack.pro
2018-09-28 17:33:43.474 27748-27825/com.phonegap.dtrack D/CordovaPurchase: init start
2018-09-28 17:33:43.474 27748-27825/com.phonegap.dtrack D/CordovaPurchase: Creating IAB helper.
2018-09-28 17:33:43.480 27748-27825/com.phonegap.dtrack D/CordovaPurchase: Starting setup.
2018-09-28 17:33:43.481 27748-27825/com.phonegap.dtrack D/IabHelper: Starting in-app billing setup.
2018-09-28 17:33:43.493 27748-27825/com.phonegap.dtrack W/PluginManager: THREAD WARNING: exec() call to InAppBillingPlugin.init blocked the main thread for 19ms. Plugin should use CordovaInterface.getThreadPool().
2018-09-28 17:33:43.500 27748-27748/com.phonegap.dtrack D/IabHelper: Billing service connected.
2018-09-28 17:33:43.502 27748-27748/com.phonegap.dtrack D/IabHelper: Checking for in-app billing 3 support.
2018-09-28 17:33:43.507 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.509 27748-27748/com.phonegap.dtrack D/IabHelper: In-app billing version 3 supported for com.phonegap.dtrack
2018-09-28 17:33:43.512 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.515 27748-27748/com.phonegap.dtrack D/IabHelper: Subscription re-signup AVAILABLE.
2018-09-28 17:33:43.515 27748-27748/com.phonegap.dtrack D/CordovaPurchase: Setup finished.
2018-09-28 17:33:43.515 27748-27748/com.phonegap.dtrack D/CordovaPurchase: Setup successful. Querying inventory w/ SKUs.
2018-09-28 17:33:43.515 27748-27748/com.phonegap.dtrack D/IabHelper: Starting async operation: refresh inventory
2018-09-28 17:33:43.518 27748-27890/com.phonegap.dtrack D/IabHelper: Querying owned items, item type: inapp
2018-09-28 17:33:43.519 27748-27890/com.phonegap.dtrack D/IabHelper: Package name: com.phonegap.dtrack
2018-09-28 17:33:43.519 27748-27890/com.phonegap.dtrack D/IabHelper: Calling getPurchases with continuation token: null
2018-09-28 17:33:43.523 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.528 27748-27890/com.phonegap.dtrack D/IabHelper: Owned items response: 0
2018-09-28 17:33:43.531 27748-27890/com.phonegap.dtrack D/IabHelper: Sku is owned: cycosoft.dtrack.pro
2018-09-28 17:33:43.531 27748-27890/com.phonegap.dtrack D/IabHelper: Continuation token: null
2018-09-28 17:33:43.531 27748-27890/com.phonegap.dtrack D/IabHelper: Querying SKU details.
2018-09-28 17:33:43.532 27748-27890/com.phonegap.dtrack D/IabHelper: moreSkus: Building SKUs List
2018-09-28 17:33:43.532 27748-27890/com.phonegap.dtrack D/IabHelper: moreSkus: cycosoft.dtrack.pro
2018-09-28 17:33:43.537 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.544 27748-27890/com.phonegap.dtrack D/IabHelper: Got sku details: SkuDetails:{"productId":"cycosoft.dtrack.pro","type":"inapp","price":"$2.99","price_amount_micros":2990000,"price_currency_code":"USD","title":"D-Track Ad-free (D-Track - Dialysis Tracker)","description":"Enjoy an ad-free D-Track experience"}
2018-09-28 17:33:43.544 27748-27890/com.phonegap.dtrack D/IabHelper: Querying owned items, item type: subs
2018-09-28 17:33:43.544 27748-27890/com.phonegap.dtrack D/IabHelper: Package name: com.phonegap.dtrack
2018-09-28 17:33:43.544 27748-27890/com.phonegap.dtrack D/IabHelper: Calling getPurchases with continuation token: null
2018-09-28 17:33:43.568 1725-2132/? D/TelephonyProvider: subIdString = 2 subId = 2
2018-09-28 17:33:43.620 27185-27185/? W/Finsky: [2] com.google.android.finsky.billing.acquirecache.j.a(44): Got an exception trying to get proto method: java.lang.NoSuchMethodException: getFingerprintValid []
2018-09-28 17:33:43.620 27185-27185/? W/Finsky: [2] com.google.android.finsky.billing.acquirecache.j.a(44): Got an exception trying to get proto method: java.lang.NoSuchMethodException: getDesiredAuthMethod []
2018-09-28 17:33:43.620 27185-27185/? W/Finsky: [2] com.google.android.finsky.billing.acquirecache.j.a(44): Got an exception trying to get proto method: java.lang.NoSuchMethodException: getAuthFrequency []
2018-09-28 17:33:43.621 27185-27185/? W/Finsky: [2] com.google.android.finsky.billing.acquirecache.j.a(44): Got an exception trying to get proto method: java.lang.NoSuchMethodException: getUserHasFop []
2018-09-28 17:33:43.621 27185-27185/? I/Finsky: [2] com.google.android.finsky.billing.acquirecache.m.run(13): Skipping a request to /bulkAcquire since cache has all the records.
2018-09-28 17:33:43.623 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.626 27748-27890/com.phonegap.dtrack D/IabHelper: Owned items response: 0
2018-09-28 17:33:43.626 27748-27890/com.phonegap.dtrack D/IabHelper: Continuation token: null
2018-09-28 17:33:43.626 27748-27890/com.phonegap.dtrack D/IabHelper: Querying SKU details.
2018-09-28 17:33:43.626 27748-27890/com.phonegap.dtrack D/IabHelper: moreSkus: Building SKUs List
2018-09-28 17:33:43.626 27748-27890/com.phonegap.dtrack D/IabHelper: moreSkus: cycosoft.dtrack.pro
2018-09-28 17:33:43.634 27185-27324/? I/Finsky: [4291] com.google.android.finsky.billing.iab.aj.b(40): com.phonegap.dtrack: Account from first account - [dbGdRBur_KhdTgKwMhd9Awt0o6s]
2018-09-28 17:33:43.639 27748-27890/com.phonegap.dtrack D/IabHelper: Ending async operation: refresh inventory
2018-09-28 17:33:43.639 27748-27748/com.phonegap.dtrack D/CordovaPurchase: Inside mGotInventoryListener
2018-09-28 17:33:43.639 27748-27748/com.phonegap.dtrack D/CordovaPurchase: Query inventory was successful.
2018-09-28 17:33:43.642 27748-27825/com.phonegap.dtrack D/CordovaPurchase: SKUDetails: Title: D-Track Ad-free (D-Track - Dialysis Tracker)
2018-09-28 17:33:43.649 27748-27825/com.phonegap.dtrack D/GenericAdPlugin: removeBanner
2018-09-28 17:33:43.649 27748-27748/com.phonegap.dtrack D/GenericAdPlugin: hideBanner
2018-09-28 17:33:44.870 750-750/? I//vendor/bin/hw/android.hardware.health@2.0-service.wahoo: SRAM data: 2452675
2018-09-28 17:33:44.882 761-25850/? I/android.hardware.usb.gadget@1.0-service.wahoo: event=1 on fd=16
2018-09-28 17:33:44.882 1725-1725/? E/QtiImsExtUtils: getConfigForPhoneId phoneId is invalid
2018-09-28 17:33:44.882 1725-1725/? E/QtiImsExtUtils: isCarrierConfigEnabled bundle is null
Cycododge commented 5 years ago

@Dexus Is there more information that I could provide to help resolve this?

j3k0 commented 5 years ago

@Cycododge solved this? I don't get how you could have product loaded on devices with Android < 9 when the product ID was incorrect? What's the exact status now?

Cycododge commented 5 years ago

The status is the same. I did have a user tell me this week that their new RCA Galileo tablet (Android 6.x) does nothing when they click the purchase link. I have no logs in support of this though.

Cycododge commented 5 years ago

Perhaps this additional information will help. From my latest release.

config.xml

Also, my analytics data since posting this ticket shows that I've had 8 successful purchases on Android devices running version 8.0.0 and 9 (interestingly), and 1 on iOS 12.1.

j3k0 commented 5 years ago

From the logs, it seems like you are not initializing the plugin when the app starts but only when clicking restore? Android doesn't need a Restore button BTW, so am I mistaken?

Sorry, I don't really understand what you are doing...

Cycododge commented 5 years ago

Correct; Android does not, but Apple requested it. So for UX consistency a purchase will not be automatically restored when the app is opened.

However, perhaps I will spend time going through the process as if setting up a new project to see if that resolves my issue. Will update with results.

Cycododge commented 5 years ago

Sorry, I don't really understand what you are doing...

I guess I didn't either. When I first released IAP in the app, it was decided not to call store.refresh() on load to prevent the app from displaying as purchased unless explicitly requested via the restore button as encouraged by Apple. I do not understand why on some devices the data appears, and on others it does not. Due to that, it sent me down the path of something outside of my code being the issue. Through further research today, the "invalid" state of the product that I was receiving was caused by building the app with the --debug flag to run it on a device.

I appreciate your time and help on this, and think it is safe to close out the ticket.