Lets start with the crash issue. Can you reproduce it? If you can please check the unfiltered logs and post the full stack trace.
Hello,
I can't reproduce all the errors I was seeing the other night, but I do have 2 questions.
The second question has to do with "Manager.PURCHASE_STATE_CANCELED".
When is this PurchaseStateChange reported. I tried inventing a credit card number, but when I used it to make a purchase Google responded with a state_purchased.
In the marketplace I have to manually approve each charge, it only checks for sufficient balance when you do the actual purchase. During testing rather than approving the charge I cancel the transaction.
The first question: on a valid transaction, in my Main "ThankYouForYourPurchase" subroutine (which is basically a copy of your tutorial code) if I allow the MessageBox to stay displayed for 15 seconds or so, Android displays a "your app has stopped responding" "force close or wait" dialogue. I've included the unfiltered logs for an entire purchase transaction:
B4X:
Installing file.
GC_FOR_ALLOC freed 273K, 11% free 6507K/7303K, paused 30ms
GC_FOR_ALLOC freed 217K, 11% free 6507K/7303K, paused 21ms
Starting: Intent { act=android.intent.action.VIEW dat=file:///mnt/sdcard/temp.apk typ=application/vnd.android.package-archive flg=0x10000000 cmp=com.android.packageinstaller/.PackageInstallerActivity } from pid 32331
** Activity (main) Pause, UserClosed = false **
Start proc com.android.packageinstaller for activity com.android.packageinstaller/.PackageInstallerActivity: pid=11497 uid=10016 gids={}
GC_FOR_ALLOC freed 42K, 4% free 6398K/6659K, paused 25ms
Grow heap (frag case) to 6.836MB for 513744-byte allocation
GC_FOR_ALLOC freed 2K, 4% free 6898K/7175K, paused 18ms
GC_CONCURRENT freed 2K, 4% free 6916K/7175K, paused 2ms+3ms
GC_FOR_ALLOC freed <1K, 4% free 6915K/7175K, paused 19ms
Grow heap (frag case) to 7.852MB for 1048592-byte allocation
GC_FOR_ALLOC freed 0K, 4% free 7939K/8263K, paused 19ms
GC_CONCURRENT freed <1K, 4% free 7939K/8263K, paused 2ms+2ms
[HAL] hw_get_module:share library path:/system/lib/hw/gralloc.tegra.so
Displayed com.android.packageinstaller/.PackageInstallerActivity: +616ms
Starting: Intent { dat=file:///mnt/sdcard/temp.apk cmp=com.android.packageinstaller/.InstallAppProgress (has extras) } from pid 11497
lights on
Replacing package:canalrun.apps.splmptst
GC_FOR_ALLOC freed 101K, 3% free 8089K/8327K, paused 27ms
Grow heap (frag case) to 8.999MB for 1048592-byte allocation
GC_CONCURRENT freed 0K, 4% free 9113K/9415K, paused 2ms+2ms
GC_EXPLICIT freed 19K, 6% free 6319K/6659K, paused 4ms+4ms
No content provider found for:
Scanning package: /data/app/vmdl1868403443.tmp
No content provider found for:
Removing non-system package:canalrun.apps.splmptst
Force stopping package canalrun.apps.splmptst uid=10111
Sending signal. PID: 11439 SIG: 9
Scheduling restart of crashed service canalrun.apps.splmptst/.inappbillingservice in 5000ms
GC_CONCURRENT freed 1474K, 33% free 13712K/20359K, paused 5ms+9ms
Displayed com.android.packageinstaller/.InstallAppProgress: +473ms
Scanning package canalrun.apps.splmptst
Package canalrun.apps.splmptst codePath changed from /data/app/canalrun.apps.splmptst-2.apk to /data/app/canalrun.apps.splmptst-1.apk; Retaining data and using new
Unpacking native libraries for /data/app/canalrun.apps.splmptst-1.apk
DexOpt: load 44ms, verify+opt 261ms
Force stopping package canalrun.apps.splmptst uid=10111
Services: canalrun.apps.splmptst.inappbillingservice
Receivers: canalrun.apps.splmptst.inappbillingservice$inappbillingservice_BR
Activities: com.google.ads.AdActivity canalrun.apps.splmptst.main
Code path for pkg : canalrun.apps.splmptst changing from /data/app/canalrun.apps.splmptst-2.apk to /data/app/canalrun.apps.splmptst-1.apk
Resource path for pkg : canalrun.apps.splmptst changing from /data/app/canalrun.apps.splmptst-2.apk to /data/app/canalrun.apps.splmptst-1.apk
New package installed in /data/app/canalrun.apps.splmptst-1.apk
Force stopping package canalrun.apps.splmptst uid=10111
Loaded meta-data for 3 account types, 2 accounts in 4ms
generateServicesMap(android.accounts.AccountAuthenticator): 4 services unchanged
PackageAdded: package:canalrun.apps.splmptst
onreceive :Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:canalrun.apps.splmptst flg=0x10000010 cmp=com.acer.app/.ApInApReceiver (has extras) }
Loaded meta-data for 3 account types, 2 accounts in 4ms
generateServicesMap(android.content.SyncAdapter): 13 services unchanged
generateServicesMap(android.accounts.AccountAuthenticator): 4 services unchanged
generateServicesMap(android.content.SyncAdapter): 13 services unchanged
setLoadOnResume
[GTalkService.1] handlePackageInstalled: re-initialize providers
[RawStanzaProvidersMgr] ##### searchProvidersFromIntent
GC_CONCURRENT freed 1067K, 25% free 14614K/19271K, paused 3ms+10ms
Alarm type : 2, from setRepeating operation : com.google.android.apps.maps
onHandleIntent checked action=com.ebay.mobile.service.START_MFTD
onHandleIntent, no authenticated user, returning
Scheduled MftdService to run at 86400000 ms
Alarm type : 3, from setRepeating operation : com.ebay.mobile
onHandleIntent: action=1, intent data=Bundle[{push_action=1}]
Alarm type : 2, from setRepeating operation : com.ebay.mobile
GC_CONCURRENT freed 352K, 9% free 6695K/7303K, paused 2ms+3ms
GC_CONCURRENT freed 252K, 6% free 6848K/7239K, paused 7ms+9ms
GC_EXPLICIT freed 1725K, 34% free 13501K/20359K, paused 32ms+10ms
GC_CONCURRENT freed 268K, 7% free 6948K/7431K, paused 2ms+2ms
Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 pkg=canalrun.apps.splmptst cmp=canalrun.apps.splmptst/.main } from pid 11497
Start proc canalrun.apps.splmptst for activity canalrun.apps.splmptst/.main: pid=11511 uid=10111 gids={1015, 3003}
Config changed: {1.0 0mcc0mnc en_US sw800dp w1280dp h752dp xlrg land finger -keyb/v/h -nav/h s.140}
updateProximitySensorMode: state = IDLE
No longer want com.google.android.gm (pid 11418): hidden #16
lights on
[HAL] hw_get_module:share library path:/system/lib/hw/gralloc.tegra.so
GC_FOR_ALLOC freed 53K, 4% free 6450K/6659K, paused 21ms
Grow heap (frag case) to 6.887MB for 513744-byte allocation
GC_CONCURRENT freed 0K, 4% free 6952K/7175K, paused 2ms+2ms
showStatusIcon on inactive InputConnection
lights on
lights on
Displayed canalrun.apps.splmptst/.main: +816ms
** Activity (main) Create, isFirst = true **
GC_CONCURRENT freed 285K, 6% free 7183K/7623K, paused 2ms+3ms
GC_CONCURRENT freed 406K, 7% free 7291K/7815K, paused 2ms+2ms
GC_FOR_ALLOC freed 344K, 7% free 7286K/7815K, paused 26ms
Grow heap (frag case) to 8.213MB for 1048592-byte allocation
GC_FOR_ALLOC freed 30K, 8% free 8280K/8903K, paused 22ms
GC_CONCURRENT freed 3K, 7% free 8291K/8903K, paused 2ms+2ms
GC_FOR_ALLOC freed 335K, 7% free 8317K/8903K, paused 25ms
Grow heap (frag case) to 10.198MB for 2072592-byte allocation
GC_FOR_ALLOC freed 0K, 6% free 10341K/10951K, paused 20ms
GC_CONCURRENT freed 8K, 6% free 10349K/10951K, paused 2ms+3ms
--- from triggerAlarmsLocked operation: com.acer.android.widget.digitalclock
----Alarm type: 1Second:1330038900.0
Alarm type : 1, from setRepeating operation : android
----Alarm type: 1Second:1330038060.0
** Activity (main) Resume **
lights on
** Service (inappbillingservice) Create **
** Service (inappbillingservice) Start **
Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@40a453c8
GC_CONCURRENT freed 1172K, 11% free 10556K/11847K, paused 2ms+2ms
GC_EXPLICIT freed 371K, 34% free 13471K/20359K, paused 3ms+6ms
[8] MarketBillingService.getPreferredAccount: canalrun.apps.splmptst: Account from first account.
BillingSupported: true
GC_EXPLICIT freed 10K, 6% free 6317K/6659K, paused 2ms+2ms
GC_EXPLICIT freed 86K, 5% free 6381K/6659K, paused 7ms+2ms
[24] MarketBillingService.getPreferredAccount: canalrun.apps.splmptst: Account from first account.
[24] MarketBillingService.getPreferredAccount: canalrun.apps.splmptst: Account from first account.
Starting: Intent { act=android.intent.action.VIEW cmp=com.android.vending/com.google.android.finsky.activities.IabActivity (has extras) } from pid -1
** Activity (main) Pause, UserClosed = false **
Hidden constructor called more than once per process!
Original: com.android.vending, new: com.android.vending
[1] SelfUpdateScheduler.checkForSelfUpdate: Skipping self-update. Local Version [8010004] >= Server Version [0]
[HAL] hw_get_module:share library path:/system/lib/hw/gralloc.tegra.so
I/O exception (org.apache.http.NoHttpResponseException) caught when processing request: The target server failed to respond
Retrying request
GC_CONCURRENT freed 330K, 9% free 8063K/8839K, paused 2ms+4ms
Displayed com.android.vending/com.google.android.finsky.activities.IabActivity: +308ms
[1] CarrierParamsAction.run: Saving carrier billing params failed.
[1] CarrierProvisioningAction.shouldFetchProvisioning: Required CarrierBillingParams missing. Shouldn't fetch provisioning.
[1] CarrierProvisioningAction.run: No need to fetch provisioning from carrier.
[1] GetBillingCountriesAction.run: Skip getting fresh list of billing countries.
GC_CONCURRENT freed 341K, 9% free 6736K/7367K, paused 3ms+2ms
[1] CarrierProvisioningAction.shouldFetchProvisioning: Required CarrierBillingParams missing. Shouldn't fetch provisioning.
[1] CarrierProvisioningAction.run: No need to fetch provisioning from carrier.
GC_CONCURRENT freed 422K, 9% free 8130K/8839K, paused 3ms+3ms
GC_EXPLICIT freed 55K, 6% free 6313K/6659K, paused 3ms+5ms
[1] PurchaseFragment.onStateChange: Finished purchase with ID https://android.clients.google.com/fdfe/purchaseStatus?doc=inapp:canalrun.apps.splmptst:sets1&order=12999763169054705758.01335990155046968837.1330038014.1
Jit: resizing JitTable from 4096 to 8192
Alarm type : 2, from setRepeating operation : com.google.android.gsf
[1] Request.finish: 3009 ms: [ ] https://android.clients.google.com/fdfe/purchaseStatus NORMAL 61
** Activity (main) Resume **
lights on
[1] MarketBillingService.sendResponseCode: Sending response RESULT_OK for request 4063922569015017899 to canalrun.apps.splmptst.
[1] PendingNotificationsService.setMarketAlarm: Setting alarm for account=canalrun2@gmail.com, duration=120000
Alarm type : 3, from setRepeating operation : com.android.vending
----Alarm type: 3Second:1232672.362000000
** Service (inappbillingservice) Start **
Alarm type : 2, from setRepeating operation : com.google.android.gsf
Start proc com.google.android.gm for service com.google.android.gm/.provider.MailSyncAdapterService: pid=11543 uid=10041 gids={3003, 1015}
Alarm type : 2, from setRepeating operation : android
GC_CONCURRENT freed 665K, 9% free 8467K/9287K, paused 4ms+5ms
----Alarm type: 2Second:1232582.527000000
** Service (inappbillingservice) Start **
[7] MarketBillingService.getPreferredAccount: canalrun.apps.splmptst: Account from first account.
Pub gmail-ls: com.google.android.gm.provider.MailProvider
Pub com.google.android.gmail.SuggestionProvider: com.google.android.gm.SuggestionsProvider
GC_CONCURRENT freed 409K, 9% free 6757K/7367K, paused 3ms+7ms
[1] MarketBillingService.sendResponseCode: Sending response RESULT_OK for request 8310635553547470686 to canalrun.apps.splmptst.
** Service (inappbillingservice) Start **
PurchaseStateChange: 0
ProductId: sets1
OrderId: 365216578746249
DateTime: 18:00:18
ExtraData: 896965
** Service (inappbillingservice) Start **
lights on
GC_CONCURRENT freed 203K, 5% free 6579K/6919K, paused 4ms+2ms
calculateUnknownSyncRationalesAndPurgeInBackground: queueing
MainSyncRequestProto: lowestBkwdConvoId: 0, highestHandledServerOp: 2737, normalSync: true
calculateUnknownSyncRationalesAndPurgeInBackground: running
GC_CONCURRENT freed 319K, 7% free 6777K/7239K, paused 2ms+3ms
GC_EXPLICIT freed 65K, 7% free 6754K/7239K, paused 3ms+4ms
MainSyncRequestProto: lowestBkwdConvoId: 0, highestHandledServerOp: 2749, normalSync: true
GC_FOR_ALLOC freed 382K, 9% free 6808K/7431K, paused 22ms
Inserting message 1394645946864628895. synced=true
GC_EXPLICIT freed 97K, 9% free 6812K/7431K, paused 2ms+2ms
MainSyncRequestProto: lowestBkwdConvoId: 0, highestHandledServerOp: 2752, normalSync: true
No longer want com.acer.ap.sns (pid 11472): hidden #16
GC_EXPLICIT freed 88K, 6% free 6323K/6659K, paused 7ms+2ms
GC_EXPLICIT freed 14K, 6% free 6834K/7239K, paused 6ms+6ms
GC_EXPLICIT freed 189K, 6% free 6921K/7303K, paused 6ms+2ms
Timeout executing service: ServiceRecord{41269798 canalrun.apps.splmptst/.inappbillingservice}
Sending signal. PID: 11511 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 131 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 245 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 184 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
GC_CONCURRENT freed 1364K, 32% free 13882K/20359K, paused 3ms+5ms
GC_EXPLICIT freed 18K, 32% free 13864K/20359K, paused 3ms+5ms
Sending signal. PID: 11376 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 32331 SIG: 3
threadid=4: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
ANR in canalrun.apps.splmptst
Reason: Executing service canalrun.apps.splmptst/.inappbillingservice
Load: 0.03 / 0.08 / 0.09
CPU usage from 15561ms to 0ms ago:
6.5% 131/system_server: 2.3% user + 4.1% kernel / faults: 12 minor
2.6% 105/dock_detect_daemon: 0% user + 2.6% kernel
0.7% 15949/dhd_dpc: 0% user + 0.7% kernel
0.4% 11511/canalrun.apps.splmptst: 0.2% user + 0.1% kernel / faults: 56 minor
0.1% 11366/com.google.android.apps.maps:FriendService: 0.1% user + 0% kernel / faults: 73 minor
0.3% 32331/anywheresoftware.b4a.b4abridge: 0.1% user + 0.1% kernel
0.2% 3/ksoftirqd/0: 0% user + 0.2% kernel
0.2% 446/com.google.android.gsf.login: 0.2% user + 0% kernel / faults: 15 minor
0% 11358/com.google.android.partnersetup: 0% user + 0% kernel / faults: 928 minor
0% 11376/com.google.android.apps.maps:LocationFriendService: 0% user + 0% kernel / faults: 73 minor
0.1% 262/com.google.process.gapps: 0.1% user + 0% kernel
0.1% 10927/com.android.vending: 0% user + 0% kernel / faults: 3 minor
0.1% 11543/com.google.android.gm: 0.1% user + 0% kernel
0% 57/kinteractiveup: 0% user + 0% kernel
0% 65/mmcqd: 0% user + 0% kernel
0% 100/irq/182-3d: 0% user + 0% kernel
0% 6948/ksoftirqd/1: 0% user + 0% kernel
0% 11040/kworker/0:2: 0% user + 0% kernel
0% 11199/kworker/1:0: 0% user + 0% kernel
0% 15948/dhd_watchdog: 0% user + 0% kernel
6.1% TOTAL: 1.9% user + 3.9% kernel + 0% iowait + 0% irq + 0.2% softirq
CPU usage from 317ms to 830ms later with 99% awake:
9.6% 131/system_server: 3.8% user + 5.7% kernel
5.7% 140/ActivityManager: 0% user + 5.7% kernel
1.9% 138/SensorService: 0% user + 1.9% kernel
2.8% 11376/com.google.android.apps.maps:LocationFriendService: 1.4% user + 1.4% kernel
1.4% 11377/HeapWorker: 1.4% user + 0% kernel
1.2% 3/ksoftirqd/0: 0% user + 1.2% kernel
1.3% 105/dock_detect_daemon: 0% user + 1.3% kernel
2.6% 105/dock_detect_dae: 0% user + 2.6% kernel
1.4% 15948/dhd_watchdog: 0% user + 1.4% kernel
1.4% 32331/anywheresoftware.b4a.b4abridge: 1.4% user + 0% kernel / faults: 1 minor
7.6% TOTAL: 3.8% user + 1.9% kernel + 1.9% softirq
GC_EXPLICIT freed 138K, 7% free 6348K/6791K, paused 2ms+2ms
GC_EXPLICIT freed 19K, 5% free 6399K/6727K, paused 6ms+2ms
Thanks,
Barry.