display.captureScreen only capturing some display objects on older devices?

Alan_PlantPot · January 29, 2015, 5:02pm

We’ve just come across a slightly odd bug. Our game has a function which takes a “screenshot” of the game using display.captureScreen().

This is then scaled down and put into a popup as if you’ve taken a photo and are seeing a preview: http://i.imgur.com/zmKxze1.png (the area inside the black rect was the previous screen).

On some devices (reported on Samsung Galaxy Nexus GT-I9250, Samsung galaxy s2 and MotoRazr) it takes the screenshot but some of the display objects get left out for some reason: http://i.imgur.com/xW2MtiD.jpg

In the second image, all text plus the logo at the top and a rect that covers the bottom buttons has not been saved to the screenshot.

Our best guess is that somewhere during the process where the screen is assigned to a display object an error is occurring, which prevents the rest of the objects being added, but we’re not sure. The only error I’ve seen in the log when it happened is this one:

01-19 20:11:06.804: I/GLSUser(661): [GLSUser] extracting token using key:Auth 01-19 20:11:06.804: W/GLSActivity(661): gms.StatusHelper Status from wire: BadAuthentication status: BAD\_AUTHENTICATION 01-19 20:11:06.804: I/GLSUser(661): GLS error: BadAuthentication someemailaddress@gmail.com oauth2:https://www.googleapis.com/auth/plus.me https://www.googleapis.com/auth/plus.stream.read https://www.googleapis.com/auth/plus.stream.write https://www.googleapis.com/auth/plus.circles.write https://www.googleapis.com/auth/plus.circles.read https://www.googleapis.com/auth/plus.photos.readwrite https://www.googleapis.com/auth/plus.native 01-19 20:11:06.811: V/GLSActivity(661): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService } 01-19 20:11:06.843: I/GLSActivity(661): Use browser flow? false 01-19 20:11:06.890: E/HttpOperation(1044): [jzt{fetchnotificationscount, fetchnotifications, fetchnotifications}] Unexpected exception 01-19 20:11:06.890: E/HttpOperation(1044): java.io.IOException: Cannot obtain authentication token 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:65) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.u(PG:385) 01-19 20:11:06.890: E/HttpOperation(1044): at jza.a(PG:29) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.l(PG:132) 01-19 20:11:06.890: E/HttpOperation(1044): at dqb.a(PG:791) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:1112) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:901) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.890: E/HttpOperation(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: android.accounts.AuthenticatorException: Cannot get Oauth2 token from GMS 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:22) 01-19 20:11:06.890: E/HttpOperation(1044): at jzs.a(PG:91) 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:62) 01-19 20:11:06.890: E/HttpOperation(1044): ... 8 more 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: gaw: User intervention required. Notification has been pushed. 01-19 20:11:06.890: E/HttpOperation(1044): at gas.c(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at gas.b(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:19) 01-19 20:11:06.890: E/HttpOperation(1044): ... 10 more 01-19 20:11:06.897: E/EsSyncAdapterService(1044): Sync failure 01-19 20:11:06.897: E/EsSyncAdapterService(1044): java.io.IOException: Error: 0 [null] 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at dqb.a(PG:791) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:1112) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:901) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.913: D/SyncManager(404): failed sync operation someemailaddress@gmail.com u0 (com.google), com.google.android.apps.plus.content.EsProvider, POLL, earliestRunTime 20992684, reason: AccountsUpdated, SyncResult: stats [numIoExceptions: 2]

I’m not sure that’s related though, it seems to be an email error. We do have the option for the user to send the screen capture function to a friend using email - but at this point no email functions have been called.

Does anyone have any ideas about what could be happening here?

Alan_PlantPot · February 1, 2015, 10:49am

Can anyone from Corona help with this one?

rob · February 1, 2015, 7:14pm

You need to see if there are crash reports, ways to get the console log of the device, or something to look at. This “feels” like a low memory issue since you said its on older devices, or perhaps underpowered GPU’s. Do you have largeheap turned on?

Rob

Alan_PlantPot · February 2, 2015, 12:44pm

Yes largeHeap is turned on. The game doesn’t crash, so there are no crash reports.

I do however have a copy of the log from just before and after the screenshot is taken:

01-19 20:10:58.054: I/Corona(5526): single tap 01-19 20:10:58.069: I/ALmixer(5526): 08Testing errpr before unqueue because getting stuff, for OS X this is expected: Invalid Name 01-19 20:10:58.585: I/Corona(5526): qnum = 69 01-19 20:10:58.647: D/dalvikvm(5526): GC\_CONCURRENT freed 818K, 10% free 11862K/13116K, paused 4ms+4ms, total 53ms 01-19 20:10:58.647: D/dalvikvm(5526): WAIT\_FOR\_CONCURRENT\_GC blocked 37ms 01-19 20:10:58.647: I/Corona(5526): QF = 800 01-19 20:10:58.655: I/Corona(5526): Saved creditData.json 01-19 20:10:58.655: I/Corona(5526): Saved consumableData.json 01-19 20:10:58.710: D/dalvikvm(5526): GC\_FOR\_ALLOC freed 487K, 11% free 11743K/13116K, paused 41ms, total 41ms 01-19 20:10:58.718: I/Corona(5526): opencount 1 01-19 20:10:58.718: I/Corona(5526): offset 0 01-19 20:10:58.726: I/Corona(5526): showCentralObjects = false 01-19 20:10:58.726: I/Corona(5526): centralGroup.x = 0 01-19 20:10:59.226: I/Corona(5526): [IAP] Trying To Load Products 01-19 20:10:59.226: I/Corona(5526): [IAP] Load Products Initialized 01-19 20:10:59.226: D/IabHelper(5526): Starting async operation: refresh inventory 01-19 20:10:59.226: D/dchan(5526): Inventory refresh successful. (response: 0:OK) 01-19 20:10:59.233: D/IabHelper(5526): Querying owned items, item type: inapp 01-19 20:10:59.233: D/IabHelper(5526): Package name: com.quiztix.mygame 01-19 20:10:59.233: D/IabHelper(5526): Calling getPurchases with continuation token: null 01-19 20:10:59.233: D/Finsky(2350): [242] InAppBillingUtils.getPreferredAccount: com.quiztix.mygame: Account from first account - [iNtMi0MWfNUej6UKNSm4R4qbOcQ] 01-19 20:10:59.241: D/IabHelper(5526): Owned items response: 0 01-19 20:10:59.241: D/IabHelper(5526): Continuation token: null 01-19 20:10:59.241: D/IabHelper(5526): Querying SKU details. 01-19 20:10:59.249: D/Finsky(2350): [208] InAppBillingUtils.getPreferredAccount: com.quiztix.mygame: Account from first account - [iNtMi0MWfNUej6UKNSm4R4qbOcQ] 01-19 20:10:59.296: I/GLSUser(1516): GLS error: BadAuthentication jumpqa@gmail.com androidmarket 01-19 20:10:59.296: V/GoogleLoginService(1516): Returning error intent with: ComponentInfo{com.google.android.gsf.login/com.google.android.gsf.login.LoginActivity} 01-19 20:10:59.311: D/dalvikvm(2350): GC\_CONCURRENT freed 674K, 8% free 10647K/11496K, paused 5ms+4ms, total 74ms 01-19 20:10:59.319: D/IabHelper(5526): getSkuDetails() failed: 6:Error 01-19 20:10:59.319: D/dchan(5526): Error refreshing inventory (querying prices of items). (response: 6:Error) 01-19 20:10:59.319: D/IabHelper(5526): Ending async operation: refresh inventory 01-19 20:10:59.319: I/Corona(5526): 6 01-19 20:10:59.319: I/Corona(5526): Error refreshing inventory (querying prices of items). (response: 6:Error) 01-19 20:10:59.491: I/Corona(5526): activateButtons 01-19 20:11:00.710: I/Log:(5526): ADJUST PLUGIN: trackevent() called 01-19 20:11:00.710: I/System.out(5526): true 01-19 20:11:00.710: E/Adjust(5526): Malformed Event Token '' 01-19 20:11:00.710: I/Corona(5526): google string http://www.google-analytics.com/collect?an=mygame&sr=720x1184&cd=Question%3a%2069&t=event&ev=69&v=1&el=Hint%20used%3a%20Ask&ul=English&av=1%2e64%2e13&z=71647&ec=Questions&ea=click&tid=UA%2d47277470%2d2&cid=FCE1BC7D%2d241F%2d2196%2d8865%2d71AF59AE3647 01-19 20:11:00.718: I/Corona(5526): Saved creditData.json 01-19 20:11:00.718: I/Corona(5526): Saved consumableData.json 01-19 20:11:01.061: I/Corona(5526): GA: Submitting custom event(s): 'design': { y='0', x='0', event\_id='Questions:HintUsed:Ask', z='0', value='69', area='Game' } - Server response: {"status":"ok"} 01-19 20:11:01.436: D/dalvikvm(5526): GC\_FOR\_ALLOC freed 324K, 11% free 11748K/13116K, paused 46ms, total 46ms 01-19 20:11:01.452: I/dalvikvm-heap(5526): Grow heap (frag case) to 14.758MB for 3409936-byte allocation 01-19 20:11:01.499: D/dalvikvm(5526): GC\_FOR\_ALLOC freed \<1K, 9% free 15078K/16448K, paused 43ms, total 43ms 01-19 20:11:01.554: D/dalvikvm(5526): GC\_CONCURRENT freed 3K, 9% free 15074K/16448K, paused 10ms+4ms, total 54ms 01-19 20:11:01.554: D/dalvikvm(5526): WAIT\_FOR\_CONCURRENT\_GC blocked 43ms 01-19 20:11:01.561: I/dalvikvm-heap(5526): Grow heap (frag case) to 18.006MB for 3409936-byte allocation 01-19 20:11:01.608: D/dalvikvm(5526): GC\_FOR\_ALLOC freed \<1K, 7% free 18404K/19780K, paused 46ms, total 46ms 01-19 20:11:01.655: D/dalvikvm(5526): GC\_CONCURRENT freed 1K, 7% free 18409K/19780K, paused 6ms+4ms, total 49ms 01-19 20:11:01.804: I/Corona(5526): new share popup 01-19 20:11:01.811: I/Corona(5526): [SP] hasRotated = false 01-19 20:11:02.335: I/Corona(5526): cap 01-19 20:11:06.679: D/dalvikvm(1044): GC\_CONCURRENT freed 6K, 59% free 10693K/25728K, paused 3ms+3ms, total 44ms 01-19 20:11:06.804: I/GLSUser(661): [GLSUser] extracting token using key:Auth 01-19 20:11:06.804: W/GLSActivity(661): gms.StatusHelper Status from wire: BadAuthentication status: BAD\_AUTHENTICATION 01-19 20:11:06.804: I/GLSUser(661): GLS error: BadAuthentication jump0051@gmail.com oauth2:https://www.googleapis.com/auth/plus.me https://www.googleapis.com/auth/plus.stream.read https://www.googleapis.com/auth/plus.stream.write https://www.googleapis.com/auth/plus.circles.write https://www.googleapis.com/auth/plus.circles.read https://www.googleapis.com/auth/plus.photos.readwrite https://www.googleapis.com/auth/plus.native 01-19 20:11:06.811: V/GLSActivity(661): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService } 01-19 20:11:06.843: I/GLSActivity(661): Use browser flow? false 01-19 20:11:06.890: E/HttpOperation(1044): [jzt{fetchnotificationscount, fetchnotifications, fetchnotifications}] Unexpected exception 01-19 20:11:06.890: E/HttpOperation(1044): java.io.IOException: Cannot obtain authentication token 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:65) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.u(PG:385) 01-19 20:11:06.890: E/HttpOperation(1044): at jza.a(PG:29) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.l(PG:132) 01-19 20:11:06.890: E/HttpOperation(1044): at dqb.a(PG:791) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:1112) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:901) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.890: E/HttpOperation(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: android.accounts.AuthenticatorException: Cannot get Oauth2 token from GMS 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:22) 01-19 20:11:06.890: E/HttpOperation(1044): at jzs.a(PG:91) 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:62) 01-19 20:11:06.890: E/HttpOperation(1044): ... 8 more 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: gaw: User intervention required. Notification has been pushed. 01-19 20:11:06.890: E/HttpOperation(1044): at gas.c(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at gas.b(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:19) 01-19 20:11:06.890: E/HttpOperation(1044): ... 10 more 01-19 20:11:06.897: E/EsSyncAdapterService(1044): Sync failure 01-19 20:11:06.897: E/EsSyncAdapterService(1044): java.io.IOException: Error: 0 [null] 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at dqb.a(PG:791) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:1112) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:901) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.913: D/SyncManager(404): failed sync operation jump0051@gmail.com u0 (com.google), com.google.android.apps.plus.content.EsProvider, POLL, earliestRunTime 20992684, reason: AccountsUpdated, SyncResult: stats [numIoExceptions: 2] 01-19 20:11:06.929: D/dalvikvm(661): GC\_CONCURRENT freed 430K, 5% free 10295K/10828K, paused 3ms+2ms, total 44ms 01-19 20:11:06.952: D/dalvikvm(1044): GC\_CONCURRENT freed 101K, 57% free 11197K/25728K, paused 2ms+3ms, total 35ms 01-19 20:11:06.952: D/dalvikvm(1044): WAIT\_FOR\_CONCURRENT\_GC blocked 31ms

Is there anything in there which immediately jumps out as being an issue?

rob · February 2, 2015, 11:56pm

Well there is this: 01-19 20:11:06.890: E/HttpOperation(1044): java.io.IOException: Cannot obtain authentication token

and a crash afterwards. I don’t know what you’re app is trying to do at this point, or even if this is from your app…

There seems to be something going on with IAP going on too:

01-19 20:10:59.311: D/dalvikvm(2350): GC_CONCURRENT freed 674K, 8% free 10647K/11496K, paused 5ms+4ms, total 74ms
01-19 20:10:59.319: D/IabHelper(5526): getSkuDetails() failed: 6:Error
01-19 20:10:59.319: D/dchan(5526): Error refreshing inventory (querying prices of items). (response: 6:Error)
01-19 20:10:59.319: D/IabHelper(5526): Ending async operation: refresh inventory
01-19 20:10:59.319: I/Corona(5526): 6
01-19 20:10:59.319: I/Corona(5526): Error refreshing inventory (querying prices of items). (response: 6:Error)

Alan_PlantPot · February 3, 2015, 7:20pm

The error in question actually begins at this point:

01-19 20:11:01.804: I/Corona(5526): new share popup

I don’t think that java.io.IOException error is anything to do with our app, we’re not making any network requests at that point.

All that has happened in our app at this point (with regards to this error) is:

Opened a new popup, which is just a rounded rect with a few buttons on it.

01-19 20:11:01.804: I/Corona(5526): new share popup

Checked to see if the device has been rotated (we redraw the popup if it has

01-19 20:11:01.811: I/Corona(5526): [SP] hasRotated = false

Add screen capture to group.

01-19 20:11:02.335: I/Corona(5526): cap

As mentioned before - from there the user can send the image via email, but at this point no email functions have been called (showPopup, openURL, etc).

I’ve asked for more logs from the QA guys, so hopefully I’ll be able to find out what it is and let you know.

rob · February 3, 2015, 11:19pm

Well native.showPopup() may be suspending your app since it’s calling another Android Activity to handle the sharing. When your app suspends, Android dumps all the OpenGL textures. It could be a case that screenCapture is firing before the system has a chance to rebuild the display after it resumes.

Can you try to capture the screen before you call native.showPopup?

Rob

Alan_PlantPot · February 4, 2015, 8:15am

It already is called before native.showpopup.

The screen is captured, and the resulting image is shown as a preview on top of a rounded rect.
4 buttons are also then drawn on this rounded rect.
Pressing one of these buttons will either: cancel, post to facebook, post to twitter, open email client.

The screen capture can be taken and the user will see images/text etc missing from the capture WITHOUT pressing any of those 4 buttons, so Facebook/Twitter/Email/nativePopup etc never come into the mix.

I have a longer log from the QA team where they have tried the capture numerous times in one session, and there are no error messages that I can see. It’s over 3000 lines long and has some debug code such as our server requests that I’d rather not post, but at any rate whenever the screen capture is made this is what it is showing every time:

02-03 20:18:25.289: I/Corona(12758): new share popup 02-03 20:18:25.297: I/Corona(12758): [SP] hasRotated = false 02-03 20:18:25.821: I/Corona(12758): cap 02-03 20:18:28.172: D/STATUSBAR-NetworkController(604): refreshSignalCluster: data=0 bt=false 02-03 20:18:30.742: I/InputReader(358): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1157] 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.883: I/InputReader(358): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=] 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.914: I/ClipboardServiceEx(358): Send intent for dismiss clipboard dialog inside hideCurrentInputLocked() ! 02-03 20:18:31.321: E/Watchdog(358): !@Sync 125 02-03 20:18:32.055: D/InputReader(358): Input event: value=1 02-03 20:18:32.055: D/lights(358): button : 1 + 02-03 20:18:32.055: I/PowerManagerService(358): Ulight 0x3-\>0x7|0x0 02-03 20:18:32.086: D/lights(358): button : 1 - 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.117: D/InputReader(358): Input event: value=0 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:34.766: I/InputReader(358): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1158] 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.906: I/InputReader(358): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=] 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.961: I/System.out(12758): true 02-03 20:18:35.610: D/dalvikvm(12758): GC\_FOR\_ALLOC freed 4527K, 33% free 13115K/19399K, paused 51ms, total 52ms 02-03 20:18:35.610: I/dalvikvm-heap(12758): Grow heap (frag case) to 14.713MB for 1536016-byte allocation 02-03 20:18:35.664: D/dalvikvm(12758): GC\_FOR\_ALLOC freed \<1K, 25% free 14614K/19399K, paused 52ms, total 52ms 02-03 20:18:35.735: D/dalvikvm(12758): GC\_CONCURRENT freed 25K, 18% free 16099K/19399K, paused 02-03 20:18:35.757: I/Corona(12758): Saved creditData.json 02-03 20:18:35.757: I/Corona(12758): Saved consumableData.json 02-03 20:18:35.757: I/Corona(12758): return to game

I don’t see anything out of place there?

Alan_PlantPot · February 9, 2015, 11:43am

I have footage that shows this happening, and hopefully makes it easier to understand what we are doing:

https://www.dropbox.com/s/vw727wucxmu5xix/0001850_Reopen.mp4?dl=0%27

At 0:05 the user taps a button which places a full screen rect behind the question UI, and then takes a screenshot - you can see that the text just vanishes, as does the icon on the button in the bottom left corner (the timer bar near the top and images next to it are supposed to disappear, so not concerned about those).

As well as the text that disappears, there is also supposed to be a header image which appears at the top, but that is not shown either.

Still no errors in the log, and it works on some devices but not others. If it was failing to load an image I’d expect it to throw an error and probably not finish the screen capture process, but that carries on as normal. I also wouldn’t expect text that is already there to disappear.

Alan_PlantPot · February 1, 2015, 10:49am

Can anyone from Corona help with this one?

rob · February 1, 2015, 7:14pm

You need to see if there are crash reports, ways to get the console log of the device, or something to look at. This “feels” like a low memory issue since you said its on older devices, or perhaps underpowered GPU’s. Do you have largeheap turned on?

Rob

Alan_PlantPot · February 2, 2015, 12:44pm

Yes largeHeap is turned on. The game doesn’t crash, so there are no crash reports.

I do however have a copy of the log from just before and after the screenshot is taken:

01-19 20:10:58.054: I/Corona(5526): single tap 01-19 20:10:58.069: I/ALmixer(5526): 08Testing errpr before unqueue because getting stuff, for OS X this is expected: Invalid Name 01-19 20:10:58.585: I/Corona(5526): qnum = 69 01-19 20:10:58.647: D/dalvikvm(5526): GC\_CONCURRENT freed 818K, 10% free 11862K/13116K, paused 4ms+4ms, total 53ms 01-19 20:10:58.647: D/dalvikvm(5526): WAIT\_FOR\_CONCURRENT\_GC blocked 37ms 01-19 20:10:58.647: I/Corona(5526): QF = 800 01-19 20:10:58.655: I/Corona(5526): Saved creditData.json 01-19 20:10:58.655: I/Corona(5526): Saved consumableData.json 01-19 20:10:58.710: D/dalvikvm(5526): GC\_FOR\_ALLOC freed 487K, 11% free 11743K/13116K, paused 41ms, total 41ms 01-19 20:10:58.718: I/Corona(5526): opencount 1 01-19 20:10:58.718: I/Corona(5526): offset 0 01-19 20:10:58.726: I/Corona(5526): showCentralObjects = false 01-19 20:10:58.726: I/Corona(5526): centralGroup.x = 0 01-19 20:10:59.226: I/Corona(5526): [IAP] Trying To Load Products 01-19 20:10:59.226: I/Corona(5526): [IAP] Load Products Initialized 01-19 20:10:59.226: D/IabHelper(5526): Starting async operation: refresh inventory 01-19 20:10:59.226: D/dchan(5526): Inventory refresh successful. (response: 0:OK) 01-19 20:10:59.233: D/IabHelper(5526): Querying owned items, item type: inapp 01-19 20:10:59.233: D/IabHelper(5526): Package name: com.quiztix.mygame 01-19 20:10:59.233: D/IabHelper(5526): Calling getPurchases with continuation token: null 01-19 20:10:59.233: D/Finsky(2350): [242] InAppBillingUtils.getPreferredAccount: com.quiztix.mygame: Account from first account - [iNtMi0MWfNUej6UKNSm4R4qbOcQ] 01-19 20:10:59.241: D/IabHelper(5526): Owned items response: 0 01-19 20:10:59.241: D/IabHelper(5526): Continuation token: null 01-19 20:10:59.241: D/IabHelper(5526): Querying SKU details. 01-19 20:10:59.249: D/Finsky(2350): [208] InAppBillingUtils.getPreferredAccount: com.quiztix.mygame: Account from first account - [iNtMi0MWfNUej6UKNSm4R4qbOcQ] 01-19 20:10:59.296: I/GLSUser(1516): GLS error: BadAuthentication jumpqa@gmail.com androidmarket 01-19 20:10:59.296: V/GoogleLoginService(1516): Returning error intent with: ComponentInfo{com.google.android.gsf.login/com.google.android.gsf.login.LoginActivity} 01-19 20:10:59.311: D/dalvikvm(2350): GC\_CONCURRENT freed 674K, 8% free 10647K/11496K, paused 5ms+4ms, total 74ms 01-19 20:10:59.319: D/IabHelper(5526): getSkuDetails() failed: 6:Error 01-19 20:10:59.319: D/dchan(5526): Error refreshing inventory (querying prices of items). (response: 6:Error) 01-19 20:10:59.319: D/IabHelper(5526): Ending async operation: refresh inventory 01-19 20:10:59.319: I/Corona(5526): 6 01-19 20:10:59.319: I/Corona(5526): Error refreshing inventory (querying prices of items). (response: 6:Error) 01-19 20:10:59.491: I/Corona(5526): activateButtons 01-19 20:11:00.710: I/Log:(5526): ADJUST PLUGIN: trackevent() called 01-19 20:11:00.710: I/System.out(5526): true 01-19 20:11:00.710: E/Adjust(5526): Malformed Event Token '' 01-19 20:11:00.710: I/Corona(5526): google string http://www.google-analytics.com/collect?an=mygame&sr=720x1184&cd=Question%3a%2069&t=event&ev=69&v=1&el=Hint%20used%3a%20Ask&ul=English&av=1%2e64%2e13&z=71647&ec=Questions&ea=click&tid=UA%2d47277470%2d2&cid=FCE1BC7D%2d241F%2d2196%2d8865%2d71AF59AE3647 01-19 20:11:00.718: I/Corona(5526): Saved creditData.json 01-19 20:11:00.718: I/Corona(5526): Saved consumableData.json 01-19 20:11:01.061: I/Corona(5526): GA: Submitting custom event(s): 'design': { y='0', x='0', event\_id='Questions:HintUsed:Ask', z='0', value='69', area='Game' } - Server response: {"status":"ok"} 01-19 20:11:01.436: D/dalvikvm(5526): GC\_FOR\_ALLOC freed 324K, 11% free 11748K/13116K, paused 46ms, total 46ms 01-19 20:11:01.452: I/dalvikvm-heap(5526): Grow heap (frag case) to 14.758MB for 3409936-byte allocation 01-19 20:11:01.499: D/dalvikvm(5526): GC\_FOR\_ALLOC freed \<1K, 9% free 15078K/16448K, paused 43ms, total 43ms 01-19 20:11:01.554: D/dalvikvm(5526): GC\_CONCURRENT freed 3K, 9% free 15074K/16448K, paused 10ms+4ms, total 54ms 01-19 20:11:01.554: D/dalvikvm(5526): WAIT\_FOR\_CONCURRENT\_GC blocked 43ms 01-19 20:11:01.561: I/dalvikvm-heap(5526): Grow heap (frag case) to 18.006MB for 3409936-byte allocation 01-19 20:11:01.608: D/dalvikvm(5526): GC\_FOR\_ALLOC freed \<1K, 7% free 18404K/19780K, paused 46ms, total 46ms 01-19 20:11:01.655: D/dalvikvm(5526): GC\_CONCURRENT freed 1K, 7% free 18409K/19780K, paused 6ms+4ms, total 49ms 01-19 20:11:01.804: I/Corona(5526): new share popup 01-19 20:11:01.811: I/Corona(5526): [SP] hasRotated = false 01-19 20:11:02.335: I/Corona(5526): cap 01-19 20:11:06.679: D/dalvikvm(1044): GC\_CONCURRENT freed 6K, 59% free 10693K/25728K, paused 3ms+3ms, total 44ms 01-19 20:11:06.804: I/GLSUser(661): [GLSUser] extracting token using key:Auth 01-19 20:11:06.804: W/GLSActivity(661): gms.StatusHelper Status from wire: BadAuthentication status: BAD\_AUTHENTICATION 01-19 20:11:06.804: I/GLSUser(661): GLS error: BadAuthentication jump0051@gmail.com oauth2:https://www.googleapis.com/auth/plus.me https://www.googleapis.com/auth/plus.stream.read https://www.googleapis.com/auth/plus.stream.write https://www.googleapis.com/auth/plus.circles.write https://www.googleapis.com/auth/plus.circles.read https://www.googleapis.com/auth/plus.photos.readwrite https://www.googleapis.com/auth/plus.native 01-19 20:11:06.811: V/GLSActivity(661): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService } 01-19 20:11:06.843: I/GLSActivity(661): Use browser flow? false 01-19 20:11:06.890: E/HttpOperation(1044): [jzt{fetchnotificationscount, fetchnotifications, fetchnotifications}] Unexpected exception 01-19 20:11:06.890: E/HttpOperation(1044): java.io.IOException: Cannot obtain authentication token 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:65) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.u(PG:385) 01-19 20:11:06.890: E/HttpOperation(1044): at jza.a(PG:29) 01-19 20:11:06.890: E/HttpOperation(1044): at jze.l(PG:132) 01-19 20:11:06.890: E/HttpOperation(1044): at dqb.a(PG:791) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:1112) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.a(PG:901) 01-19 20:11:06.890: E/HttpOperation(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.890: E/HttpOperation(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: android.accounts.AuthenticatorException: Cannot get Oauth2 token from GMS 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:22) 01-19 20:11:06.890: E/HttpOperation(1044): at jzs.a(PG:91) 01-19 20:11:06.890: E/HttpOperation(1044): at jzu.a(PG:62) 01-19 20:11:06.890: E/HttpOperation(1044): ... 8 more 01-19 20:11:06.890: E/HttpOperation(1044): Caused by: gaw: User intervention required. Notification has been pushed. 01-19 20:11:06.890: E/HttpOperation(1044): at gas.c(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at gas.b(Unknown Source) 01-19 20:11:06.890: E/HttpOperation(1044): at idt.a(PG:19) 01-19 20:11:06.890: E/HttpOperation(1044): ... 10 more 01-19 20:11:06.897: E/EsSyncAdapterService(1044): Sync failure 01-19 20:11:06.897: E/EsSyncAdapterService(1044): java.io.IOException: Error: 0 [null] 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at dqb.a(PG:791) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:1112) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.a(PG:901) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at ffi.onPerformSync(PG:631) 01-19 20:11:06.897: E/EsSyncAdapterService(1044): at android.content.AbstractThreadedSyncAdapter$SyncThread.run(AbstractThreadedSyncAdapter.java:254) 01-19 20:11:06.913: D/SyncManager(404): failed sync operation jump0051@gmail.com u0 (com.google), com.google.android.apps.plus.content.EsProvider, POLL, earliestRunTime 20992684, reason: AccountsUpdated, SyncResult: stats [numIoExceptions: 2] 01-19 20:11:06.929: D/dalvikvm(661): GC\_CONCURRENT freed 430K, 5% free 10295K/10828K, paused 3ms+2ms, total 44ms 01-19 20:11:06.952: D/dalvikvm(1044): GC\_CONCURRENT freed 101K, 57% free 11197K/25728K, paused 2ms+3ms, total 35ms 01-19 20:11:06.952: D/dalvikvm(1044): WAIT\_FOR\_CONCURRENT\_GC blocked 31ms

Is there anything in there which immediately jumps out as being an issue?

rob · February 2, 2015, 11:56pm

Well there is this: 01-19 20:11:06.890: E/HttpOperation(1044): java.io.IOException: Cannot obtain authentication token

and a crash afterwards. I don’t know what you’re app is trying to do at this point, or even if this is from your app…

There seems to be something going on with IAP going on too:

01-19 20:10:59.311: D/dalvikvm(2350): GC_CONCURRENT freed 674K, 8% free 10647K/11496K, paused 5ms+4ms, total 74ms
01-19 20:10:59.319: D/IabHelper(5526): getSkuDetails() failed: 6:Error
01-19 20:10:59.319: D/dchan(5526): Error refreshing inventory (querying prices of items). (response: 6:Error)
01-19 20:10:59.319: D/IabHelper(5526): Ending async operation: refresh inventory
01-19 20:10:59.319: I/Corona(5526): 6
01-19 20:10:59.319: I/Corona(5526): Error refreshing inventory (querying prices of items). (response: 6:Error)

Alan_PlantPot · February 3, 2015, 7:20pm

The error in question actually begins at this point:

01-19 20:11:01.804: I/Corona(5526): new share popup

I don’t think that java.io.IOException error is anything to do with our app, we’re not making any network requests at that point.

All that has happened in our app at this point (with regards to this error) is:

Opened a new popup, which is just a rounded rect with a few buttons on it.

01-19 20:11:01.804: I/Corona(5526): new share popup

Checked to see if the device has been rotated (we redraw the popup if it has

01-19 20:11:01.811: I/Corona(5526): [SP] hasRotated = false

Add screen capture to group.

01-19 20:11:02.335: I/Corona(5526): cap

As mentioned before - from there the user can send the image via email, but at this point no email functions have been called (showPopup, openURL, etc).

I’ve asked for more logs from the QA guys, so hopefully I’ll be able to find out what it is and let you know.

rob · February 3, 2015, 11:19pm

Well native.showPopup() may be suspending your app since it’s calling another Android Activity to handle the sharing. When your app suspends, Android dumps all the OpenGL textures. It could be a case that screenCapture is firing before the system has a chance to rebuild the display after it resumes.

Can you try to capture the screen before you call native.showPopup?

Rob

Alan_PlantPot · February 4, 2015, 8:15am

It already is called before native.showpopup.

The screen is captured, and the resulting image is shown as a preview on top of a rounded rect.
4 buttons are also then drawn on this rounded rect.
Pressing one of these buttons will either: cancel, post to facebook, post to twitter, open email client.

The screen capture can be taken and the user will see images/text etc missing from the capture WITHOUT pressing any of those 4 buttons, so Facebook/Twitter/Email/nativePopup etc never come into the mix.

I have a longer log from the QA team where they have tried the capture numerous times in one session, and there are no error messages that I can see. It’s over 3000 lines long and has some debug code such as our server requests that I’d rather not post, but at any rate whenever the screen capture is made this is what it is showing every time:

02-03 20:18:25.289: I/Corona(12758): new share popup 02-03 20:18:25.297: I/Corona(12758): [SP] hasRotated = false 02-03 20:18:25.821: I/Corona(12758): cap 02-03 20:18:28.172: D/STATUSBAR-NetworkController(604): refreshSignalCluster: data=0 bt=false 02-03 20:18:30.742: I/InputReader(358): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1157] 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.742: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:30.883: I/InputReader(358): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=] 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.883: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:30.914: I/ClipboardServiceEx(358): Send intent for dismiss clipboard dialog inside hideCurrentInputLocked() ! 02-03 20:18:31.321: E/Watchdog(358): !@Sync 125 02-03 20:18:32.055: D/InputReader(358): Input event: value=1 02-03 20:18:32.055: D/lights(358): button : 1 + 02-03 20:18:32.055: I/PowerManagerService(358): Ulight 0x3-\>0x7|0x0 02-03 20:18:32.086: D/lights(358): button : 1 - 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.086: I/InputDispatcher(358): Delivering key to current input target: action: 0x0 02-03 20:18:32.117: D/InputReader(358): Input event: value=0 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:32.117: I/InputDispatcher(358): Delivering key to current input target: action: 0x1 02-03 20:18:34.766: I/InputReader(358): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1158] 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.766: I/InputDispatcher(358): Delivering touch to current input target: action: 0x0 02-03 20:18:34.906: I/InputReader(358): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=] 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.906: I/InputDispatcher(358): Delivering touch to current input target: action: 0x1 02-03 20:18:34.961: I/System.out(12758): true 02-03 20:18:35.610: D/dalvikvm(12758): GC\_FOR\_ALLOC freed 4527K, 33% free 13115K/19399K, paused 51ms, total 52ms 02-03 20:18:35.610: I/dalvikvm-heap(12758): Grow heap (frag case) to 14.713MB for 1536016-byte allocation 02-03 20:18:35.664: D/dalvikvm(12758): GC\_FOR\_ALLOC freed \<1K, 25% free 14614K/19399K, paused 52ms, total 52ms 02-03 20:18:35.735: D/dalvikvm(12758): GC\_CONCURRENT freed 25K, 18% free 16099K/19399K, paused 02-03 20:18:35.757: I/Corona(12758): Saved creditData.json 02-03 20:18:35.757: I/Corona(12758): Saved consumableData.json 02-03 20:18:35.757: I/Corona(12758): return to game

I don’t see anything out of place there?

Alan_PlantPot · February 9, 2015, 11:43am

I have footage that shows this happening, and hopefully makes it easier to understand what we are doing:

https://www.dropbox.com/s/vw727wucxmu5xix/0001850_Reopen.mp4?dl=0%27

At 0:05 the user taps a button which places a full screen rect behind the question UI, and then takes a screenshot - you can see that the text just vanishes, as does the icon on the button in the bottom left corner (the timer bar near the top and images next to it are supposed to disappear, so not concerned about those).

As well as the text that disappears, there is also supposed to be a header image which appears at the top, but that is not shown either.

Still no errors in the log, and it works on some devices but not others. If it was failing to load an image I’d expect it to throw an error and probably not finish the screen capture process, but that carries on as normal. I also wouldn’t expect text that is already there to disappear.