Amazon freezes on store initialization

Dirtybit · August 14, 2013, 8:02am

Hi,

My app freezes after I’ve loaded the Amazon plugin and the initialization (store.init() process has begun. This freeze happen occationally, and when it doesn’t freeze it works as intended. The app gives the following stack trace on freeze:

[lua]

08-14 09:50:19.826: I/Corona(27499): try to load amazon plugin

08-14 09:50:19.826: V/Corona(27499): > Class.forName: plugin.amazon.iap.LuaLoader

08-14 09:50:19.826: V/Corona(27499): < Class.forName: plugin.amazon.iap.LuaLoader

08-14 09:50:19.826: V/Corona(27499): Loading via reflection: plugin.amazon.iap.LuaLoader

08-14 09:50:19.838: I/Corona(27499): plugin loaded

08-14 09:50:19.838: I/Corona(27499): Starting Amazon appstore

08-14 09:50:19.842: I/PurchasingManager(27499): Purchasing Framework initialization complete. Build ID 1.0.3

08-14 09:50:19.846: D/PurchasingManager(27499): In App Purchasing SDK - Sandbox Mode: PurchasingObserver registered: plugin.amazon.iap.CoronaPurchasingObserver@420c3e68

08-14 09:50:19.850: D/SandboxRequestHandler(27499): In App Purchasing SDK - Sandbox Mode: sendGetUserIdRequest

08-14 09:50:19.920: I/ActivityManager(248): Start proc com.amazon.mas.test for service com.amazon.mas.test/com.amazon.testclient.KickstartService: pid=27539 uid=10067 gids={1015, 1028}

08-14 09:50:19.951: D/dalvikvm(27539): Late-enabling CheckJNI

08-14 09:50:20.037: I/dalvikvm(27539): Turning on JNI app bug workarounds for target SDK version 9…

08-14 09:50:20.170: I/ActivityThread(27539): Pub com.amazon.testclient: com.amazon.testclient.transactions.TransactionsProvider

08-14 09:50:20.244: I/AmazonSDKTester(27539): Sending UserId Response Broadcast ({“status”:“SUCCESSFUL”,“requestId”:“5d58aadb-6d31-4df9-9d5b-050663c2387d”,“userId”:“DefaultTestUser”})

08-14 09:50:20.272: I/ActivityManager(248): No longer want com.google.android.gsf.login (pid 16508): hidden #16

08-14 09:50:30.291: W/BroadcastQueue(248): Timeout of broadcast BroadcastRecord{426f84d0 com.amazon.inapp.purchasing.NOTIFY} - receiver=android.os.BinderProxy@424a5330, started 10000ms ago

08-14 09:50:30.291: W/BroadcastQueue(248): Receiver during timeout: ResolveInfo{4294d9e0 com.amazon.inapp.purchasing.ResponseReceiver p=0 o=0 m=0x108000}

08-14 09:50:30.412: I/Process(248): Sending signal. PID: 27499 SIG: 3

08-14 09:50:30.412: I/dalvikvm(27499): threadid=3: reacting to signal 3

08-14 09:50:30.565: I/dalvikvm(27499): Wrote stack traces to ‘/data/anr/traces.txt’

08-14 09:50:30.565: I/Process(248): Sending signal. PID: 248 SIG: 3

08-14 09:50:30.565: I/dalvikvm(248): threadid=3: reacting to signal 3

08-14 09:50:31.088: I/Process(248): Sending signal. PID: 432 SIG: 3

08-14 09:50:31.088: I/dalvikvm(432): threadid=3: reacting to signal 3

08-14 09:50:31.088: I/LocationManagerService(248): remove passive (pid 248), next minTime = 0

08-14 09:50:31.092: I/ActivityManager(248): Process com.google.process.location (pid 4185) has died.

08-14 09:50:31.092: W/ActivityManager(248): Scheduling restart of crashed service com.google.android.gms/com.google.android.location.internal.GoogleLocationManagerService in 5000ms

08-14 09:50:31.092: I/LocationManagerService(248): remove passive (pid 248), next minTime = 0

08-14 09:50:31.092: W/ActivityManager(248): Scheduling restart of crashed service com.google.android.gms/com.google.android.location.internal.server.GoogleLocationService in 14997ms

08-14 09:50:31.100: I/dalvikvm(248): Wrote stack traces to ‘/data/anr/traces.txt’

08-14 09:50:31.100: I/Process(248): Sending signal. PID: 328 SIG: 3

08-14 09:50:31.100: I/dalvikvm(328): threadid=3: reacting to signal 3

08-14 09:50:31.268: I/dalvikvm(432): Wrote stack traces to ‘/data/anr/traces.txt’

08-14 09:50:31.272: I/Process(248): Sending signal. PID: 443 SIG: 3

08-14 09:50:31.272: I/dalvikvm(443): threadid=3: reacting to signal 3

08-14 09:50:31.373: I/dalvikvm(328): Wrote stack traces to ‘/data/anr/traces.txt’

08-14 09:50:31.373: I/dalvikvm(443): Wrote stack traces to ‘/data/anr/traces.txt’

08-14 09:50:31.533: I/ActivityManager(248): Process com.google.android.calendar (pid 14817) has died.

08-14 09:50:31.545: W/ProcessStats(248): Skipping unknown process pid 14817

08-14 09:50:31.627: D/dalvikvm(248): WAIT_FOR_CONCURRENT_GC blocked 0ms

08-14 09:50:31.748: D/dalvikvm(248): GC_EXPLICIT freed 994K, 30% free 19316K/27591K, paused 3ms+9ms, total 119ms

08-14 09:50:32.318: I/Process(248): Sending signal. PID: 14803 SIG: 3

08-14 09:50:32.322: I/ActivityManager(248): Process com.android.providers.calendar (pid 14803) has died.

08-14 09:50:32.561: E/ActivityManager(248): ANR in no.dirtybit.funrun

08-14 09:50:32.561: E/ActivityManager(248): Reason: Broadcast of Intent { act=com.amazon.inapp.purchasing.NOTIFY flg=0x10000010 pkg=no.dirtybit.funrun cmp=no.dirtybit.funrun/com.amazon.inapp.purchasing.ResponseReceiver (has extras) }

08-14 09:50:32.561: E/ActivityManager(248): Load: 1.66 / 0.56 / 0.31

08-14 09:50:32.561: E/ActivityManager(248): CPU usage from 12225ms to 0ms ago:

08-14 09:50:32.561: E/ActivityManager(248): 26% 27499/no.dirtybit.funrun: 22% user + 3.9% kernel / faults: 4847 minor 53 major

08-14 09:50:32.561: E/ActivityManager(248): 13% 248/system_server: 5.9% user + 7.8% kernel / faults: 400 minor 19 major

08-14 09:50:32.561: E/ActivityManager(248): 5.1% 90/mediaserver: 2.7% user + 2.3% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.6% 16/ksmd: 0% user + 3.6% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.5% 96/adbd: 1.1% user + 2.4% kernel / faults: 137 minor

08-14 09:50:32.561: E/ActivityManager(248): 2.7% 27327/kworker/0:0: 0% user + 2.7% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0.7% 328/com.android.systemui: 0.6% user + 0% kernel / faults: 132 minor

08-14 09:50:32.561: E/ActivityManager(248): 0.3% 62/mmcqd/0: 0% user + 0.3% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0.1% 15/kswapd0: 0% user + 0.1% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0.1% 67/dhd_dpc: 0% user + 0.1% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0.1% 87/surfaceflinger: 0% user + 0% kernel / faults: 2 minor

08-14 09:50:32.561: E/ActivityManager(248): 0% 88/zygote: 0% user + 0% kernel / faults: 349 minor 2 major

08-14 09:50:32.561: E/ActivityManager(248): 0% 31/s3cfb-vsync: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0% 66/dhd_watchdog: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0% 84/netd: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0% 443/com.android.nfc: 0% user + 0% kernel / faults: 56 minor

08-14 09:50:32.561: E/ActivityManager(248): 0% 4185/com.google.process.location: 0% user + 0% kernel / faults: 94 minor

08-14 09:50:32.561: E/ActivityManager(248): 0% 7453/wpa_supplicant: 0% user + 0% kernel / faults: 29 minor

08-14 09:50:32.561: E/ActivityManager(248): 0% 27491/kworker/u:1: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 0% 27504/kworker/u:2: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): +0% 27539/com.amazon.mas.test: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): +0% 27557/sh: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): +0% 27559/logcat: 0% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 71% TOTAL: 35% user + 26% kernel + 9.3% iowait + 0.3% softirq

08-14 09:50:32.561: E/ActivityManager(248): CPU usage from 1406ms to 1930ms later:

08-14 09:50:32.561: E/ActivityManager(248): 25% 27499/no.dirtybit.funrun: 20% user + 5.5% kernel

08-14 09:50:32.561: E/ActivityManager(248): 20% 27520/OpenAL/sl/m: 18% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.7% 27517/er$SensorThread: 3.7% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.8% 27519/AudioTrack: 0% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 20% 248/system_server: 9.2% user + 11% kernel / faults: 2 minor

08-14 09:50:32.561: E/ActivityManager(248): 5.5% 261/system_server: 0% user + 5.5% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.7% 263/er.ServerThread: 1.8% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.7% 264/ActivityManager: 0% user + 3.7% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.8% 262/SensorService: 0% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.8% 327/er$SensorThread: 1.8% user + 0% kernel

08-14 09:50:32.561: E/ActivityManager(248): 7.4% 90/mediaserver: 3.7% user + 3.7% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.7% 173/FastMixer: 1.8% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 3.7% 273/AudioOut_2: 1.8% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.8% 272/AudioWatchdog: 0% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1% 15/kswapd0: 0% user + 1% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.8% 16/ksmd: 0% user + 1.8% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.1% 67/dhd_dpc: 0% user + 1.1% kernel

08-14 09:50:32.561: E/ActivityManager(248): 1.2% 14803/com.android.providers.calendar: 0% user + 1.2% kernel / faults: 1 minor

08-14 09:50:32.561: E/ActivityManager(248): 1.4% 27327/kworker/0:0: 0% user + 1.4% kernel

08-14 09:50:32.561: E/ActivityManager(248): 100% TOTAL: 33% user + 18% kernel + 47% iowait

[/lua]

Dirtybit · August 14, 2013, 8:28am

Our code

[lua]

print(“try to load amazon plugin”)

store = require “plugin.amazon.iap”

print(“plugin loaded”)

currentProductList = googleProductList

print(“Starting Amazon appstore”)

store.init( transactionCallback )

print("The currently logged in user is: ", store.getUserId())

print(“store loaded”)

[/lua]

tamkinp · August 15, 2013, 12:32am

Hi dirtyBit,

Thank you for the logcat. A potential issue has been identified in the Amazon IAP Plugin. I will let you know in this thread when an update has occurred.

-Preston

Dirtybit · August 19, 2013, 7:56am

Hi Preston,

Have you guys looked in to it yet?

DavidRangel · August 29, 2013, 9:46pm

dirtyBit - we’ve discussed this a bit and here is a note from one of our engineers:

Nothing is really standing out to me as to what is actually wrong. The logged warnings posted on the forum are harmless, are nothing to worry about, and happen before the “main.lua” gets executed. So, the posted log is useless.

The most likely issue is:

There is a deadlock issue on the Java side.
The Corona developer has a brute force loop in his suspend event handler, waiting for an event that never happens. We should tell him to try commenting out his suspend event handler to see if this works-around the problem.

Also, perhaps the app is not really “frozen” and there is really a Lua runtime error happening in his code which is causing unexpected behavior in his app, like it is in a bad state. I recommend that he set up his app to show Lua runtime errors as alert dialogs as described here…

http://docs.coronalabs.com/daily/guide/basics/configSettings/index.html#runtime-errors

Can you give this a shot and let us know what you see?

Dirtybit · August 14, 2013, 8:28am

Our code

[lua]

print(“try to load amazon plugin”)

store = require “plugin.amazon.iap”

print(“plugin loaded”)

currentProductList = googleProductList

print(“Starting Amazon appstore”)

store.init( transactionCallback )

print("The currently logged in user is: ", store.getUserId())

print(“store loaded”)

[/lua]

tamkinp · August 15, 2013, 12:32am

Hi dirtyBit,

Thank you for the logcat. A potential issue has been identified in the Amazon IAP Plugin. I will let you know in this thread when an update has occurred.

-Preston

Dirtybit · August 19, 2013, 7:56am

Hi Preston,

Have you guys looked in to it yet?

tamkinp · September 16, 2013, 5:10pm

Hi Dirtybit,

Did you discover the cause of your error? If so, could you share your solution?

DavidRangel · August 29, 2013, 9:46pm

dirtyBit - we’ve discussed this a bit and here is a note from one of our engineers:

Nothing is really standing out to me as to what is actually wrong. The logged warnings posted on the forum are harmless, are nothing to worry about, and happen before the “main.lua” gets executed. So, the posted log is useless.

The most likely issue is:

There is a deadlock issue on the Java side.
The Corona developer has a brute force loop in his suspend event handler, waiting for an event that never happens. We should tell him to try commenting out his suspend event handler to see if this works-around the problem.

Also, perhaps the app is not really “frozen” and there is really a Lua runtime error happening in his code which is causing unexpected behavior in his app, like it is in a bad state. I recommend that he set up his app to show Lua runtime errors as alert dialogs as described here…

http://docs.coronalabs.com/daily/guide/basics/configSettings/index.html#runtime-errors

Can you give this a shot and let us know what you see?

tamkinp · September 16, 2013, 5:10pm

Hi Dirtybit,

Did you discover the cause of your error? If so, could you share your solution?

Yoger_Games · March 28, 2014, 8:09pm

I also have a similar issue. When testing pretty much the same code on simulator (windows) I get

Error d:\MyApp\Corona Labs\Corona Simulator\Plugins\plugin_amazon_iap.lua:19 native.showAlert() expects a listener as argument #4

It freezes as soon as the init code is run on the phone.

Edit: I used daily build 2221.

Yoger_Games · March 28, 2014, 8:09pm

I also have a similar issue. When testing pretty much the same code on simulator (windows) I get

Error d:\MyApp\Corona Labs\Corona Simulator\Plugins\plugin_amazon_iap.lua:19 native.showAlert() expects a listener as argument #4

It freezes as soon as the init code is run on the phone.

Edit: I used daily build 2221.