airsdk / Adobe-Runtime-Support

Report, track and discuss issues in Adobe AIR. Monitored by Adobe - and HARMAN - and maintained by the AIR community.
200 stars 11 forks source link

[Android] Rendering issues with cacheAsBitmap on some Android and Amazon devices #103

Open FliplineStudios opened 5 years ago

FliplineStudios commented 5 years ago

We've seen a variety of rendering issues when using our AIR apps with cacheAsBitmap on some Android and Amazon devices, and specifically the 2018 Amazon Fire HD 8 model can reproduce the issues easily. Our apps run in GPU mode using vector content, with some MovieClips sets to cacheAsBitmap to improve performance.

On the majority of Android devices everything is rendering correctly and performing smoothly, but on some devices including the 2018 Amazon Fire HD 8, graphics that are using cacheAsBitmap will randomly instead show what looks like scrambled static, or as if a sprite sheet was shrunk down and tiled onto the image, or some other graphics that are either bitmaps or cacheAsBitmap sprites will be displayed in slices or tiles in its place. It's not consistent either, as sometimes the graphics will display correctly using cacheAsBitmap, and other times that same graphic will be replaced with something garbled. This happens whether or not cacheAsBitmapMatrix is used alongside cacheAsBitmap. Often the tiled/sliced graphics that are shown in its place are color-shifted from their source graphics.

The only workaround at the moment is to avoid cacheAsBitmap altogether because of its unreliability on Android/Amazon devices, which is an issue when apps are using vector graphics in GPU mode for the performance boost.

Here are some screenshots of what is occurring. These images were taken from the Amazon version of our app "Papa's Scooperia HD" on the 2018 Amazon Fire HD 8, though we've gotten multiple complaints from Google Play users of the same issues happening on other Android devices.

Here's what the screen should look like, and it occasionally does render correctly: Screenshot_20190717-111331 The character on the right is displaying correctly here, which is a MovieClip with cacheAsBitmap set to true.

Here's what will happen randomly to that same screen: Screenshot_20190717-111141 The character is instead replaced with slices of another character, and slices of other in-game graphics that have all been flipped vertically/horizontally and are somehow blue-tinted from their normal state.

Another example: Screenshot_20190717-111205

The character is replaced with slices of a different character who was previously rendered.

Another example: Screenshot_20190717-111217

Again replaced with slices of a different character, but also showing other snippets of bitmaps within the game. The green icon at the top of the scrambled image showing "Doggeria" flipped vertically/horizontally is a jpg in the library (not vector graphics with cacheAsBitmap), so this garbled rendering isn't limited to only other cacheAsBitmap clips getting mixed in.

Another example: Screenshot_20190910-155348 More in-game graphics that have been blue-tinted and scrambled instead of showing the character from the first image.

Another example: Screenshot_20190307-152901 The character is replaced by a bunch of other images, pink-tinted and overlaid/flipped/scrambled.

These are just one easily-reproducible example of one spot in one game. Similar issues have appeared in over a dozen of our games that all use GPU Mode and cacheAsBitmap.

This is occurring in the published versions using AIR 30/31/32, and also in the Harman AIR 33 version.

These issues have been reported as happening on the following devices:

2018 Amazon Fire HD 8 (using a ARM Mali-T620 MP2 GPU) Samsung Galaxy Note 5 (ARM Mali T760) Samsung Galaxy S5 Neo (ARM Mali T720) Samsung Galaxy Core Prime (Qualcomm Adreno 306) Huawei Honor 6x (ARM Mali T830) Huawei P9 Lite (ARM Mali T830) Huawei Honor 5C (ARM Mali T830) Huawei P10 Lite (2x ARM Mali T830) Moto E 4 (ARM Mali T720) (And more, this is just a sample of the affected devices)

This is confirmed to not be happening on the following devices: Amazon Fire 7 (ARM Mali-450 MP4) Google Pixel (Qualcomm Adreno 530)

FliplineStudios commented 5 years ago

I did some debugging on the Amazon Fire HD 8 device, and noticed that when there's a graphical glitch with cacheAsBitmap, this appears in the logs:

D : [Mali] CMARP ERROR: event_job c = 0xc885b800 FAILURE, event code = 0x58

This seems to appear every time there is a graphical issue. When I attempt to view a character as in my example above, if it renders correctly I don't see this error, but when there's a graphical scrambling glitch I do the see the above error.

I also found that if I minimize the app and then reopen it, the glitch fixes itself -- though that may be because I'm changing the stage.quality during deactivate/activate rather than anything inherent in minimizing/reopening: During EVENT_DEACTIVATE I am setting the stage quality from MEDIUM to HIGH, and on EVENT_ACTIVATE I am setting the stage quality back to MEDIUM (this code was to fix a previous bug with AIR where you would sometimes get a black screen when minimizing/reopening an app, and changing the stage quality seems to force the GPU into refreshing correctly).

The full log is below:


[NOTE: I TAPPED ON THE SCREEN HERE TO SHOW A CHARACTER]

09-17 16:12:44.095  1418  1431 I ECS_ECStateMachine: Received event: TOUCH_EVENT
09-17 16:12:44.100  1418  1431 D ECS_TimeoutManager: reset()
09-17 16:12:44.100  1418  1431 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:44.100  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:44.100  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:44.100  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:44.100  1418  1431 I ECS_ECStateMachine: ECS state changed from AWAKE to AWAKE with shouldEnableHDS: false
09-17 16:12:44.101  1418  1431 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.states.ECStateMachine.notifyTouchEvent:1121 com.amazon.knight.ecs.states.ECStateMachine.handleEventInternal:441 com.amazon.knight.ecs.states.ECStateMachine.handleEvent:393
09-17 16:12:44.102  1418  1431 I ECS_NightModeManager: Received event: TOUCH_EVENT
09-17 16:12:44.102  1418  1431 I ECS_ECService: Received event: TOUCH_EVENT
09-17 16:12:44.102  1418  1431 I ECS_ECStateMachine: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:44.102  1418  1431 I ECS_NightModeManager: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:44.102  1418  1431 I ECS_ECService: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:44.311  6579  6621 D         : [Mali] CMARP ERROR: event_job c = 0xc885b800 FAILURE, event code = 0x58
09-17 16:12:44.311  6579  6621 D         : [Mali] CMARP ERROR: event_job c = 0xc885b000 FAILURE, event code = 0x58

[NOTE: GRAPHICS APPEAR SCRAMBLED HERE AFTER THE ABOVE MALI CMARP ERROR]
[THIS MALI CMARP ERROR ALWAYS APPEARS DURING A GRAPHICS GLITCH WITH CACHEASBITMAP]

[NOTE: AFTER THIS POINT I MINIMIZE THE APP AND GO BACK TO THE HOME SCREEN]
[REOPEN THE APP AND THE GLITCH CORRECTS ITSELF]
[I'M ALSO TOGGLING STAGE QUALITY MEDIUM -> HIGH -> MEDIUM HERE]

09-17 16:12:51.042  1418  1431 I ECS_ECStateMachine: Received event: TOUCH_EVENT
09-17 16:12:51.050  1418  1431 D ECS_TimeoutManager: reset()
09-17 16:12:51.050  1418  1431 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:51.050  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:51.050  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:51.050  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:51.050  1418  1431 I ECS_ECStateMachine: ECS state changed from AWAKE to AWAKE with shouldEnableHDS: false
09-17 16:12:51.051  1418  1431 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.states.ECStateMachine.notifyTouchEvent:1121 com.amazon.knight.ecs.states.ECStateMachine.handleEventInternal:441 com.amazon.knight.ecs.states.ECStateMachine.handleEvent:393
09-17 16:12:51.052  1418  1431 I ECS_NightModeManager: Received event: TOUCH_EVENT
09-17 16:12:51.052  1418  1431 I ECS_ECService: Received event: TOUCH_EVENT
09-17 16:12:51.052  1418  1431 I ECS_ECStateMachine: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:51.052  1418  1431 I ECS_NightModeManager: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:51.052  1418  1431 I ECS_ECService: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:52.068   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:12:52.068   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:12:52.226  1418  1431 I ECS_ECStateMachine: Received event: TOUCH_EVENT
09-17 16:12:52.227  1418  1431 D ECS_TimeoutManager: reset()
09-17 16:12:52.227  1418  1431 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:52.227  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:52.227  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:52.227  1418  1431 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:52.227  1418  1431 I ECS_ECStateMachine: ECS state changed from AWAKE to AWAKE with shouldEnableHDS: false
09-17 16:12:52.227  1418  1431 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.states.ECStateMachine.notifyTouchEvent:1121 com.amazon.knight.ecs.states.ECStateMachine.handleEventInternal:441 com.amazon.knight.ecs.states.ECStateMachine.handleEvent:393
09-17 16:12:52.232  1418  1431 I ECS_NightModeManager: Received event: TOUCH_EVENT
09-17 16:12:52.232  1418  1431 I ECS_ECService: Received event: TOUCH_EVENT
09-17 16:12:52.232  1418  1431 I ECS_ECStateMachine: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:52.232  1418  1431 I ECS_NightModeManager: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:52.232  1418  1431 I ECS_ECService: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:52.248  1390  1977 I SPCH-SIM_AccountRegisteredCondition: isMet
09-17 16:12:52.249  1390  1977 I SPCH-SIM_SIMApplication: Alexa setting value = 1
09-17 16:12:52.249  1390  1977 I SPCH-SIM_SIMApplication: Alexa Disabled, Alexa setting value = 1
09-17 16:12:52.249  1390  1977 I SPCH-SIM_SIMApplication: Updating Alexa Availability Secure Settings Value to : 1
09-17 16:12:52.250  1390  1977 I SPCH-SIM_SpeechInteractionService: Account Registered Condition Check account (true) available (false)
09-17 16:12:52.250  1390  1977 I SPCH-SIM_SpeechInteractionService: Account Registered Condition Check Restarting in (60000) ms
09-17 16:12:53.747  1418  1430 I ECS_ECStateMachine: Received event: TOUCH_EVENT
09-17 16:12:53.747  1418  1430 D ECS_TimeoutManager: reset()
09-17 16:12:53.747  1418  1430 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:53.747  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:53.747  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:53.747  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:53.747  1418  1430 I ECS_ECStateMachine: ECS state changed from AWAKE to AWAKE with shouldEnableHDS: false
09-17 16:12:53.747  1418  1430 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.states.ECStateMachine.notifyTouchEvent:1121 com.amazon.knight.ecs.states.ECStateMachine.handleEventInternal:441 com.amazon.knight.ecs.states.ECStateMachine.handleEvent:393
09-17 16:12:53.748   727   727 W TelecomManager: Telecom Service not found.
09-17 16:12:53.770  1418  1430 I ECS_NightModeManager: Received event: TOUCH_EVENT
09-17 16:12:53.770  1418  1430 I ECS_ECService: Received event: TOUCH_EVENT
09-17 16:12:53.770  1418  1430 I ECS_ECStateMachine: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:53.770  1418  1430 I ECS_NightModeManager: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:53.770  1418  1430 I ECS_ECService: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:53.820   576   616 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.amazon.firelauncher/.Launcher (has extras)} from uid 1000 on display 0
09-17 16:12:53.851   576   586 E Sensors : handleToDriver handle(0)
09-17 16:12:53.851   576   586 D Accel   : setDelay: (handle=0, ns=66667000)
09-17 16:12:53.852   576   586 E Sensors : new setDelay handle(0),ns(66667000)m, error(0), index(2)
09-17 16:12:53.864   576   913 I PackageRecency: Queuing notification(s) to package for ActivityInfo{1a4df5a com.amazon.firelauncher.Launcher}
09-17 16:12:53.873   262   347 D AudioALSAHardware: +setParameters(): continuous_audio_mode=0
09-17 16:12:53.873   262   347 W AudioALSAHardware: setParameters(), still have param.size() = 1, remain param = "continuous_audio_mode=0"
09-17 16:12:53.873   262   347 D AudioALSAHardware: -setParameters(): continuous_audio_mode=0
09-17 16:12:53.873   576   670 E SELinux : avc:  denied  { log_internal_metric } for  scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:r:system_server:s0 tclass=amazon_policies permissive=0
09-17 16:12:53.907   262   646 D AudioALSAHardware: +setParameters(): continuous_audio_mode=0
09-17 16:12:53.907   262   646 W AudioALSAHardware: setParameters(), still have param.size() = 1, remain param = "continuous_audio_mode=0"
09-17 16:12:53.907   262   646 D AudioALSAHardware: -setParameters(): continuous_audio_mode=0
09-17 16:12:53.939  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.939  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.940  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.943  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.946  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.946  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.951  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.953  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.955  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.955  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.959  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.962  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.964  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.967  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.969  1460  1460 I F_C.ScreenOffReceiver: Removing listener
09-17 16:12:53.986  1460  1460 I F_C.Launcher: onCreate
09-17 16:12:54.006  1418  1431 I ECS_TimeoutManager: Task stack changed
09-17 16:12:54.007  1418  1431 D ECS_TimeoutManager: wasNewTaskAdded prev:2 current:2
09-17 16:12:54.007  1418  1431 D ECS_TimeoutManager: reset()
09-17 16:12:54.007  1418  1431 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:54.032  1460  1460 W ResourceType: Attempt to retrieve bag 0x0103003e which is invalid or in a cycle.
09-17 16:12:54.038   576   585 I art     : Background partial concurrent mark sweep GC freed 13182(717KB) AllocSpace objects, 0(0B) LOS objects, 19% free, 16MB/20MB, paused 2.230ms total 152.069ms
09-17 16:12:54.070   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:12:54.070   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:12:54.081  1418  1651 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.CloudPresenceNotifier.sendActivityIntent:295 com.amazon.knight.ecs.CloudPresenceNotifier.notifyPresenceToCloud:262 com.amazon.knight.ecs.CloudPresenceNotifier.-wrap0:-1
09-17 16:12:54.100  1460  1460 I F_C.SearchHostWidget: Init for hostID: 2000
09-17 16:12:54.100  1460  1460 I F_C.MonitoringSearchWid: Showing appWidget search bar
09-17 16:12:54.104  1460  1460 I F_C.PagedHomeController: setImageMemoryManager: com.amazon.firelauncher.images.MagazineImageMemoryManager@5a80b2b
09-17 16:12:54.106  3706  3706 I JobSchedulerService: Starting DeviceCallingAndroidService due to 3
09-17 16:12:54.106  3706  3706 I DeviceCallingServiceRes: Attempting to load DeviceCallingService implementation : com.amazon.comms.devicecalling.service.DeviceCallingAndroidService
09-17 16:12:54.106  3706  3706 W MediaInsightsPublisher: service config is already set
09-17 16:12:54.107  3838  3838 D MediaInsightsPublisher: TracePublisherService on StartCommand
09-17 16:12:54.110  3706  3706 I DeviceCallingAndroidSer: Not in MultiModalMode, we should not be processing these intents.
09-17 16:12:54.114   576   586 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:12:54.115  1460  1460 I F_C.Launcher: onStart
09-17 16:12:54.169  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.183  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.196  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.209  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.229  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.241  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.255  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.268  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.284  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.288  1460  1460 I F_C.PrefetchTrigger: Disabling
09-17 16:12:54.297  1460  1460 I F_C.Launcher: Received intent:android.intent.action.MAIN
09-17 16:12:54.300  1460  1460 I F_C.Launcher: onResume
09-17 16:12:54.354  1460  1616 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:54.420   727   838 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:54.444   727  2037 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:54.445   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 704 1280  img[704 1280]
09-17 16:12:54.462   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 704 1280  img[704 1280]
09-17 16:12:54.463   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 704 1280  img[704 1280]
09-17 16:12:54.505  1460  1460 I F_C.PagedHomeController: ViewPager laid out
09-17 16:12:54.506  1460  1460 I F_C.PagedHomeController: setImageMemoryManager: com.amazon.firelauncher.images.MagazineImageMemoryManager@5a80b2b
09-17 16:12:54.506  1460  1460 I F_C.ImageMemoryManager: setMainView: android.widget.FrameLayout{bf9e046 V.E...... ......ID 0,0-1280,736 #1020002 android:id/content}
09-17 16:12:54.513  1655  1655 D QSB.USearchAppWidgetService: Received event: com.amazon.kindle.unifiedSearch.action.APPWIDGET_UPDATE channel:Home magazine:Search widgetID: 8
09-17 16:12:54.513  1655  1655 D QSB.WeblabArcusUtil: Default hintText used as the user is not in Treatment:D or locale isnt under treatment:en_US
09-17 16:12:54.513  1655  1655 D QSB.USearchAppWidgetService: Not updating widget since the view state has not changed
09-17 16:12:54.515  1460  1460 E RecyclerView: No adapter attached; skipping layout
09-17 16:12:54.714  1460  1470 I art     : Background partial concurrent mark sweep GC freed 11819(692KB) AllocSpace objects, 4(6MB) LOS objects, 17% free, 18MB/22MB, paused 3.638ms total 159.769ms
09-17 16:12:54.729  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.729  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.730  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.730  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.731  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.731  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.731  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.732  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.732  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.733  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.733  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.733  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 85 85  img[85 85]
09-17 16:12:54.735  1460  1616 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 1280 214  img[1280 214]
09-17 16:12:54.745   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:54.752  1460  1460 I F_C.LauncherTutorialCon: Both tutorials have been shown, not showing tutorials
09-17 16:12:54.753  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.782   576   596 I ActivityManager: Displayed com.amazon.firelauncher/.Launcher: +917ms
09-17 16:12:54.806  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.806  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.833  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.879  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.879  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.904  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.913  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.913  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:54.914  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:54.959  1460  1470 I art     : Background partial concurrent mark sweep GC freed 71983(4MB) AllocSpace objects, 3(108KB) LOS objects, 21% free, 14MB/18MB, paused 2.434ms total 151.773ms
09-17 16:12:54.974  1460  1460 D android.widget.GridLayout: horizontal constraints: x7-x0>=1039, x7-x6<=142, x6-x5<=149, x5-x4<=149, x4-x3<=149, x3-x2<=149, x2-x1<=149, x1-x0<=149 are inconsistent; permanently removing: x7-x6<=142.
09-17 16:12:54.986  1460  1460 I F_C.ScreenOffReceiver: Adding listener
09-17 16:12:55.013  1460  1460 D android.widget.GridLayout: horizontal constraints: x9-x0>=1038, x9-x8<=0, x8-x7<=0, x7-x6<=0, x6-x5<=0, x5-x4<=0, x4-x3<=0, x3-x2<=0, x2-x1<=0, x1-x0<=116 are inconsistent; permanently removing: x9-x8<=0.
09-17 16:12:55.226  1460  1460 D android.widget.GridLayout: horizontal constraints: x1-x0>=176, x2-x1>=160, x2-x0<=335 are inconsistent; permanently removing: x2-x0<=335.
09-17 16:12:55.227  1460  1460 D android.widget.GridLayout: horizontal constraints: x1-x0>=176, x2-x1>=176, x2-x0<=351 are inconsistent; permanently removing: x2-x0<=351.
09-17 16:12:55.228  1460  1460 D android.widget.GridLayout: horizontal constraints: x1-x0>=176, x2-x1>=176, x2-x0<=351 are inconsistent; permanently removing: x2-x0<=351.
09-17 16:12:55.258  1460  1460 D android.widget.GridLayout: horizontal constraints: x7-x0>=1039, x7-x6<=0, x6-x5<=149, x5-x4<=149, x4-x3<=149, x3-x2<=149, x2-x1<=149, x1-x0<=149 are inconsistent; permanently removing: x7-x6<=0.
09-17 16:12:55.277  1460  1460 D android.widget.GridLayout: horizontal constraints: x7-x0>=1039, x7-x6<=0, x6-x5<=0, x5-x4<=0, x4-x3<=0, x3-x2<=0, x2-x1<=0, x1-x0<=149 are inconsistent; permanently removing: x7-x6<=0.
09-17 16:12:55.296  1460  1460 D android.widget.GridLayout: horizontal constraints: x5-x0>=1040, x5-x4<=176, x4-x3<=176, x3-x2<=335, x2-x1<=176, x1-x0<=176 are inconsistent; permanently removing: x5-x4<=176.
09-17 16:12:55.376  1460  1460 I F_C.GreetingMessageUpda: The current time is: Tue Sep 17 16:12:55 EDT 2019, the next update will occur in 1 hours and 47 minutes
09-17 16:12:55.376  1460  1460 I F_C.GreetingMessageUpda: update Content Description
09-17 16:12:55.380  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:55.381  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:55.381  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:12:55.395   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:55.412   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:56.072   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:12:56.072   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:12:56.251  3625  3625 I CommsContacts/a: Device is not in MultiModalMode
09-17 16:12:56.333  1655  1655 I QSB.PrewarmerService: Prewarmer service bind is invoked
09-17 16:12:56.335  1460  1460 I F_C.Launcher: Bound to SearchPrewarmer Service
09-17 16:12:56.351   576   684 I WifiDiagsUtil: event=RUN_TEST_CONTINUOUSLY
09-17 16:12:56.351   576   684 I WifiDiagsUtil: loggingPacketStats
09-17 16:12:56.353   576   684 I WifiManager: Wifi getConfiguredNetworks called by system
09-17 16:12:56.354   576   684 I WifiDiagsUtil: pinging ... localhost
09-17 16:12:56.357   576   684 I WifiDiagsUtil: event=pingsComplete, IP=xxx.xxx.xxx..., packetsSent=5, numFailed=0, packetLoss=0.0%, AvgTimeMs=0.18
09-17 16:12:56.357   576   684 I WifiDiagsUtil: pinging ... gateway
09-17 16:12:56.379   576   684 I WifiDiagsUtil: event=pingsComplete, IP=xxx.xxx.xxx..., packetsSent=5, numFailed=0, packetLoss=0.0%, AvgTimeMs=3.97
09-17 16:12:56.379   576   684 I WifiDiagsUtil: pinging ... dns1
09-17 16:12:56.386   576   684 I WifiDiagsUtil: event=pingsComplete, IP=xxx.xxx.xxx..., packetsSent=5, numFailed=0, packetLoss=0.0%, AvgTimeMs=1.08
09-17 16:12:56.387   576   684 I WifiDiagsUtil: event=preConfiguredDNSDetected, action=skipPingTest, nameserver=xxx.xxx.xxx...
09-17 16:12:56.387   576   684 I WifiDiagsUtil: event=noEntryFoundFor: net.dns3, action=skippingPingTest
09-17 16:12:56.387   576   684 I WifiDiagsUtil: event=runHttpConnTestAttempt, host=http://spectrum.s3.amazonaws.com/kindle-wifi/wifistub.html
09-17 16:12:56.518   576   684 I WifiDiagsUtil: event=runHttpConnTestSuccess, host=http://spectrum.s3.amazonaws.com/kindle-wifi/wifistub.html, latency=128
09-17 16:12:56.518   576   684 I WifiDiagsUtil: event=GOOD_CONNECTION
09-17 16:12:56.518   576   684 I WifiDiagsUtil: event=evaluatingCaptivePortal
09-17 16:12:56.609   576   684 I WifiDiagsUtil: Ping HOST=http://spectrum.s3.amazonaws.com/kindle-wifi/wifistub.html, result=Yes(1)
09-17 16:12:56.609   576   684 I WifiDiagsUtil: same network status
09-17 16:12:57.607  1418  1430 I ECS_ECStateMachine: Received event: TOUCH_EVENT
09-17 16:12:57.607  1418  1430 D ECS_TimeoutManager: reset()
09-17 16:12:57.607  1418  1430 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:57.607  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:57.607  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:57.607  1418  1430 I ECS_ECHDController: List of enabled criteria on HDS: [PRIVACY_MODE_ON, TABLET_MODE_ON]
09-17 16:12:57.607  1418  1430 I ECS_ECStateMachine: ECS state changed from AWAKE to AWAKE with shouldEnableHDS: false
09-17 16:12:57.608  1418  1430 W ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:921 android.content.ContextWrapper.sendBroadcast:426 com.amazon.knight.ecs.states.ECStateMachine.notifyTouchEvent:1121 com.amazon.knight.ecs.states.ECStateMachine.handleEventInternal:441 com.amazon.knight.ecs.states.ECStateMachine.handleEvent:393
09-17 16:12:57.610  1418  1430 I ECS_NightModeManager: Received event: TOUCH_EVENT
09-17 16:12:57.610  1418  1430 I ECS_ECService: Received event: TOUCH_EVENT
09-17 16:12:57.610  1418  1430 I ECS_ECStateMachine: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:57.611  1418  1430 I ECS_NightModeManager: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:57.611  1418  1430 I ECS_ECService: Received event: CLOUD_PRESENCE_INTERACTION
09-17 16:12:57.714  1460  1460 I F_C.ItemClickOperation: onClick hit for item:  [...]
09-17 16:12:57.716   576   829 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 cmp=air.com.flipline.papasscooperiahd/.AppEntry} from uid 10079 on display 0
09-17 16:12:57.727  1460  1460 I F_C.ItemClickOperation: Launched  [...]  with intent  [...]
09-17 16:12:57.758  1460  1460 I F_C.Launcher: onPause
09-17 16:12:57.762   576   913 I PackageRecency: Queuing notification(s) to package for ActivityInfo{4d8b057 air.com.flipline.papasscooperiahd.AppEntry}
09-17 16:12:57.769   262   645 D AudioALSAHardware: +setParameters(): continuous_audio_mode=0
09-17 16:12:57.770   262   645 W AudioALSAHardware: setParameters(), still have param.size() = 1, remain param = "continuous_audio_mode=0"
09-17 16:12:57.770   262   645 D AudioALSAHardware: -setParameters(): continuous_audio_mode=0
09-17 16:12:57.800   234   338 W hwcomposer: [JOB] (0) Timed out waiting for vsync...
09-17 16:12:57.831   576   903 E Sensors : handleToDriver handle(0)
09-17 16:12:57.832   576   903 D Accel   : setDelay: (handle=0, ns=66667000)
09-17 16:12:57.832   576   903 E Sensors : new setDelay handle(0),ns(66667000)m, error(0), index(2)
09-17 16:12:57.847   576   596 I ActivityManager: Displayed air.com.flipline.papasscooperiahd/.AppEntry: +85ms
09-17 16:12:57.864  1460  1616 D OpenGLRenderer: endAllActiveAnimators on 0xcc9f7380 (LayerDrawable) with handle 0xcccd81c0
09-17 16:12:57.873   727   838 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:57.877  1418  1430 I ECS_TimeoutManager: Task stack changed
09-17 16:12:57.877  1418  1430 D ECS_TimeoutManager: wasNewTaskAdded prev:2 current:2
09-17 16:12:57.877  1418  1430 D ECS_TimeoutManager: reset()
09-17 16:12:57.877  1418  1430 I ECS_TimeoutManager: ignoring reset - timeout manager has been disabled with reasons: [TABLET_MODE]
09-17 16:12:57.881   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 704 1280  img[704 1280]
09-17 16:12:57.889   727  2037 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:57.898   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 768 1280  img[768 1280]
09-17 16:12:57.914   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 768 1280  img[768 1280]
09-17 16:12:57.915   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 768 1280  img[768 1280]
09-17 16:12:57.929  6579  6579 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:57.977  6579  6579 E MALI    : gles_state_set_error_internal:69: [MALI] GLES ctx: 0xcf600008, error code:0x505
09-17 16:12:58.006  6579  6579 D         : #00 pc 0071e7a5  /system/vendor/lib/egl/libGLES_mali.so
09-17 16:12:58.006  6579  6579 D         : #01 pc 006ae4a0  /system/vendor/lib/egl/libGLES_mali.so
09-17 16:12:58.006  6579  6579 D MALI    : gles_state_set_error_internal:70: [MALI] GLES error info:execution failed
09-17 16:12:58.074  6579  6579 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:58.074   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:12:58.074   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:12:58.157   727   838 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:58.164   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 768 1280  img[768 1280]
09-17 16:12:58.173   727  2037 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
09-17 16:12:58.198   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.199   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.215   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.331   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.345  6579  6579 I AVC     : d5b13f70
09-17 16:12:58.348   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 1280 800  img[1280 800]
09-17 16:12:58.398   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.514   234   234 D MALI    : eglCreateImageKHR:513: [Crop] 0 0 800 1280  img[800 1280]
09-17 16:12:58.681  1460  1460 I F_C.Launcher: onStop
09-17 16:12:58.683  1460  1460 I F_C.PrefetchTrigger: Enabling
09-17 16:12:58.685  1460  1552 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:12:58.686   576   829 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:12:58.885   576   597 I PackageRecency: Matched blackListPattern for [com.amazon.kindle.cms/com.amazon.kindle.cms.MaintenanceService$PackageRecencyListener] on com.amazon.kindle/.*|com.amazon.venezia/.*|com.amazon.ags.app/.*|com.amazon.mp3/.*|com.amazon.kindle.otter.settings/.*|com.amazon.webapp/.*|com.audible.application.kindle/.*|com.amazon.avod/.*|com.amazon.firelauncher/.*
09-17 16:13:00.076   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:00.076   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:02.078   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:02.078   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:04.080   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:04.080   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:06.082   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:06.082   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:07.984  2163  2212 D AmazonCMS: MaintenanceService.onStartCommand
09-17 16:13:07.986  2163  2212 D AmazonCMS: CMS activity level changed, active: true
09-17 16:13:07.989  2163  2212 D AmazonCMS: Received intent: 'com.amazon.action.PACKAGE_RECENCY_NOTIFICATION'
09-17 16:13:07.993  2163  2212 D AmazonCMS: Reconciler created
09-17 16:13:08.031  2163  2171 W art     : Suspending all threads took: 10.502ms
09-17 16:13:08.035  2163  2212 E AmazonCMS: IO Exception while parsing xml
09-17 16:13:08.063  2163  2212 D AmazonCMS: SourcesManager: registering source 'com.amazon.kindle.cms.app_manager' for user 'amzn1.account.AF6CX3WKPJJDMILZYL3OBIQKY2CQ' in profile '0'
09-17 16:13:08.067  2163  2212 D AmazonCMS: Cards are enabled, initializing card producer
09-17 16:13:08.076  2163  2212 D AmazonCMS: SourcesManager: registering source 'com.amazon.kindle.cms.collection_manager' for user 'amzn1.account.AF6CX3WKPJJDMILZYL3OBIQKY2CQ' in profile '0'
09-17 16:13:08.077  2163  2212 D AmazonCMS: CMS activity level changed, active: false
09-17 16:13:08.082  2163  2212 D AmazonCMS: CollectionSyncManager: user (DID: amzn1.account.AF6CX3WKPJJDMILZYL3OBIQKY2CQ, Profile: 0, CMS UID: 3, Safe Mode: false) is not connected for DELTA_SYNC sync. Disconnecting and reconnecting.
09-17 16:13:08.084   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:08.084   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver: Exception applying overrides, returning baseline
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver: java.io.FileNotFoundException: arcus_configs/app_suppression/karnak.json
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at android.content.res.AssetManager.openAsset(Native Method)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at android.content.res.AssetManager.open(AssetManager.java:347)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at android.content.res.AssetManager.open(AssetManager.java:321)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.utility.FileUtils.getAssetFileContents(FileUtils.java:13)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.AssetJsonFile.value(AssetJsonFile.java:26)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.CachedJsonFile$1.call(CachedJsonFile.java:46)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.CachedJsonFile$1.call(CachedJsonFile.java:43)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.util.concurrent.FutureTask.run(FutureTask.java:237)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.CachedJsonFile.value(CachedJsonFile.java:53)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.SegmentSettingsOverride.apply(SegmentSettingsOverride.java:39)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.ConfigSettingsOverride.apply(ConfigSettingsOverride.java:65)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.firecard.arcus.AssetDefaultConfigurationProvider.getDefaultConfig(AssetDefaultConfigurationProvider.java:90)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.kindle.cms.arcus.ArcusRemoteConfiguration.initialize(ArcusRemoteConfiguration.java:116)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.kindle.cms.reconciler.ReconcilerWorker$1.run(ReconcilerWorker.java:153)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at com.amazon.kindle.cms.reconciler.ReconcilerThreadPool$12.run(ReconcilerThreadPool.java:351)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.util.concurrent.FutureTask.run(FutureTask.java:237)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
09-17 16:13:08.117  2163  7404 E F_C.SegmentSettingsOver:       at java.lang.Thread.run(Thread.java:761)
09-17 16:13:08.142  2163  2212 D AmazonCMS: SyncClient - Connecting as user (DID: amzn1.account.AF6CX3WKPJJDMILZYL3OBIQKY2CQ, Profile: 0, CMS UID: 3, Safe Mode: false)
09-17 16:13:08.145  2163  2212 D AmazonCMS: notified to profile 0 with com.amazon.kindle.cms.STARTUP, Bundle[{profile_id=0, version=2.1.0.10}]
09-17 16:13:08.233  2163  2281 I SendDatasetsSyncOp: Sending 0 dataset update for 'CloudCollections' namespace
09-17 16:13:08.281  2163  2286 I SendDatasetsSyncOp: Sending 0 dataset update for 'CloudCollections' namespace
09-17 16:13:08.331  2163  2307 I DCP     : [JsonCallExecutor][CallExecutor][72de5939-c18d-4158-bd40-6755f685b1e4][Auth]GET https://api.amazon.com/whispersync/v2/data/amzn1.account.XXXX/datasets/290edb00-f0db-44d3-8c87-b247ce4183c3/records?after=79  (attempt 1)
09-17 16:13:08.334  2163  7410 I com.amazon.dcp.framework.ConnectivityEnforcer: Network with type -1 is already connected
09-17 16:13:08.356  1355  1577 E ...ity.framework.a.a[0]: pid 2163 could not be found
09-17 16:13:08.371  2163  2212 D AmazonCMS: notified to profile 0 with com.amazon.kindle.cms.CONTENT_UPDATE, Bundle[{item_type=kindle.content.apps, profile_id=0, status=0, urgent_flag=1, version=2.1.0.10, last_access_date=1568751177769, location=0, item_id=259}]
09-17 16:13:08.470  2163  7412 I F_C.ProducerClientCompa: Producer com.amazon.kindle.cms.card.producer.NEWSSTAND at API version BrazilVersion(1.5).
09-17 16:13:08.471  2163  2212 D AmazonCMS: Read 1 card ids from the cache for producer com.amazon.kindle.cms.card.producer.NEWSSTAND in profile 0
09-17 16:13:08.474  2163  2212 D AmazonCMS: CardClient: Pushing 1 cards {NEWSSTAND_NEWSSTAND_LIBRARY} by producer com.amazon.kindle.cms.card.producer.NEWSSTAND
09-17 16:13:08.488  2163  7412 I F_C.ProducerClientCompa: Connected to ServerInfo(CDA Version: BrazilVersion(1.3.200380.0), Min. Producer: BrazilVersion(1.0), Delete All: true)
09-17 16:13:08.493  1460  1471 I F_C.CardProvider: CDA:CardProvider:bulkInsert(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.NEWSSTAND), contentValues:[(com.amazon.kindle.cms.card.producer.NEWSSTAND/-2115605341/1568751188464)][size=1])
09-17 16:13:08.501  2163  2307 D CRLSetManager: getInstance binder: android.os.BinderProxy@199bac7
09-17 16:13:08.510  1460  1471 I F_C.CardAgentSynchroniz: Throttling producer refresh
09-17 16:13:08.519  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.519  1460  1557 I F_C.DefaultConsumerClie: Acquiring ContentProviderClient
09-17 16:13:08.519  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.NEWSSTAND, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.530  1460  7413 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.531   576  1569 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.538  1460  1557 I F_C.CardDataSource: Card processing started for: NEWSSTAND (1 card(s))
09-17 16:13:08.544  1460  7413 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.545   576  1560 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.558  1460  1557 I F_C.CardDataSource: Card processing completed for: NEWSSTAND (1 card(s))
09-17 16:13:08.559  1460  1460 I F_C.CardDataSource: Updating cards in target: NEWSSTAND (1 card(s))
09-17 16:13:08.559  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target NEWSSTAND
09-17 16:13:08.567  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmsair.com.flipline.papasscooperiahd
09-17 16:13:08.574  1460  7414 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.574  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.NEWSSTAND, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.575  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.575  1460  4039 I F_C.DefaultConsumerClie: Acquiring ContentProviderClient
09-17 16:13:08.575  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.NEWSSTAND, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.576  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.585  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmscom.amazon.photos
09-17 16:13:08.598  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmscom.amazon.photos.importer
09-17 16:13:08.610  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmscom.amazon.windowshop
09-17 16:13:08.622  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmsair.com.flipline.papalouiepals
09-17 16:13:08.631  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_B00FZVZPKO$air.com.flipline.papasfreezeriahd
09-17 16:13:08.641  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmsair.com.flipline.papascupcakeriahd
09-17 16:13:08.646  2163  2307 I DCP     : [JsonCallExecutor][CallExecutor][72de5939-c18d-4158-bd40-6755f685b1e4][Auth]Received response code 200 OK. Total time = 315 ms. Handshake = 212 ms. Upload = 0 ms (0 bytes). Latency = 99 ms. Download = 3 ms (572 bytes).
09-17 16:13:08.651  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmsair.com.flipline.papashotdoggeriahd
09-17 16:13:08.661  2163  2212 D AmazonCMS: Creating continue card with id: FOR_YOU_cmscom.android.email
09-17 16:13:08.712  2163  7412 I F_C.ProducerClientCompa: Producer com.amazon.kindle.cms.card.producer.APPS at API version BrazilVersion(1.5).
09-17 16:13:08.712  2163  2212 D AmazonCMS: Read 9 card ids from the cache for producer com.amazon.kindle.cms.card.producer.APPS in profile 0
09-17 16:13:08.713  2163  2212 D AmazonCMS: CardClient: Pushing 9 cards {FOR_YOU_cmsair.com.flipline.papasscooperiahd, FOR_YOU_cmscom.amazon.photos, FOR_YOU_cmscom.amazon.photos.importer, FOR_YOU_cmscom.amazon.windowshop, FOR_YOU_cmsair.com.flipline.papalouiepals, FOR_YOU_B00FZVZPKO$air.com.flipline.papasfreezeriahd, FOR_YOU_cmsair.com.flipline.papascupcakeriahd, FOR_YOU_cmsair.com.flipline.papashotdoggeriahd, FOR_YOU_cmscom.android.email} by producer com.amazon.kindle.cms.card.producer.APPS
09-17 16:13:08.717  2163  7412 I F_C.ProducerClientCompa: Connected to ServerInfo(CDA Version: BrazilVersion(1.3.200380.0), Min. Producer: BrazilVersion(1.0), Delete All: true)
09-17 16:13:08.727  1460  3566 I F_C.CardProvider: CDA:CardProvider:bulkInsert(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS), contentValues:[(com.amazon.kindle.cms.card.producer.APPS/-1093850535/1568751188585), (com.amazon.kindle.cms.card.producer.APPS/23209707/1568751188597), (com.amazon.kindle.cms.card.producer.APPS/506629813/1568751188609), (com.amazon.kindle.cms.card.producer.APPS/826185808/1568751188622), (com.amazon.kindle.cms.card.producer.APPS/634034139/1568751188630), (com.amazon.kindle.cms.card.producer.APPS/-483802810/1568751188641), (com.amazon.kindle.cms.card.producer.APPS/711833848/1568751188651), (com.amazon.kindle.cms.card.producer.APPS/-1243343727/1568751188660), (com.amazon.kindle.cms.card.producer.APPS/-707417443/1568751188685)][size=9])
09-17 16:13:08.734  1460  3566 I F_C.CardAgentSynchroniz: Throttling producer refresh
09-17 16:13:08.753  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.753  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.755  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.760  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.760  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.762  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.762  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.762  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.763  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.764  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.764  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.766  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.766  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.766  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.767  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.768  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.768  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.776  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.776  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.777  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.778  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.779  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.780  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.781  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.782  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.782  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.783  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.785  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.785  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.786  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.788  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.788  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.792  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.793  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.793  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.793  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@be83ec
09-17 16:13:08.794  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@1d843b5
09-17 16:13:08.794  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.794  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.794  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.794  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.796  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.796  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.796  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.796  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@b42a4a
09-17 16:13:08.796  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@d4bdbb
09-17 16:13:08.796  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.796  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.796  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.796  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.798  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.798  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.798  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.798  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@605f2d8
09-17 16:13:08.798  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@b966631
09-17 16:13:08.800  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.800  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.801  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.802  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.802  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.803  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.805  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.805  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.806  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.807  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.807  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.808  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.809  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.809  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.809  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.809  1460  1557 I F_C.CardDataSource: Card processing started for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.811  1460  1557 I F_C.CardDataSource: Card processing completed for: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.823  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.823  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.824  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@d12a116
09-17 16:13:08.824  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@b077a97
09-17 16:13:08.824  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.824  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.833  2163  2598 I DCP     : [JsonCallExecutor][CallExecutor][d40b1776-9592-4388-a74a-a0bb21ed464c][Auth]GET https://api.amazon.com/whispersync/v2/data/amzn1.account.XXXX/datasets?after=541  (attempt 1)
09-17 16:13:08.835  2163  7417 I com.amazon.dcp.framework.ConnectivityEnforcer: Network with type -1 is already connected
09-17 16:13:08.837  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.837  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.837  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.837  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@b3a346d
09-17 16:13:08.837  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@d0fb8a2
09-17 16:13:08.839   576  1432 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.839  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.839  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.842  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.842  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.842  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@93f2933
09-17 16:13:08.843  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@ee444f0
09-17 16:13:08.843  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.843  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.853  2163  2212 D AmazonCMS: Performing collection sync type DELTA_SYNC for user (DID: amzn1.account.AF6CX3WKPJJDMILZYL3OBIQKY2CQ, Profile: 0, CMS UID: 3, Safe Mode: false)
09-17 16:13:08.854  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.854  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.854  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@5d2aa69
09-17 16:13:08.854  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@d4bcee
09-17 16:13:08.854  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.854  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.856  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.856  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.857  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.858  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.859   576  1432 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.864  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.864  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.864  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.864  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.864  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.865  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@8f5c095
09-17 16:13:08.865  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@98e95aa
09-17 16:13:08.865  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.865  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.866  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.867  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.867  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.867  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AsinRecencyRunnable@ecbb59b
09-17 16:13:08.868  1460  1460 I F_C.Debouncer: Debouncing com.amazon.firelauncher.recency.RecencyManager$AppUsageRunnable@ef3bd38
09-17 16:13:08.868  1460  1460 I F_C.CardDataSource: Updating cards in target: FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS (1 card(s))
09-17 16:13:08.868  1460  1460 I F_C.CardDataSource: Creating Card  [...]  in target FOR_YOU/com.amazon.firelauncher.launchercardproducer:CONTINUE/com.amazon.firelauncher.launchercardproducer:APPS
09-17 16:13:08.891  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.891  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.891  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.897  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.897  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.897  1460  1460 W F_C.ViewBuilderFactory: Null context found in ViewBuilderFactory
09-17 16:13:08.903  1355  1571 E ...ity.framework.a.a[0]: pid 2163 could not be found
09-17 16:13:08.912  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.913   576  1417 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.914  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.916  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.921  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.921  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.921  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.921  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.923  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.923   576   903 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.927  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.933  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.934   576  1550 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.936  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.936  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.936  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.936  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.938  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.939  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.943  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.944   576  6234 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.947  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.971  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.972  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.973   576  1433 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.973  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.973  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.974  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.975  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.977  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.978  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.979  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.979  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.979  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.980  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.982  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.983   576  1569 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:08.984  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.985  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.985  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.985  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.986  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.987  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:08.991  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:08.992  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:08.992  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:08.993  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:08.994  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:08.994  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:08.995   576   587 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:09.002  1460  7416 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:09.003  2163  2598 I DCP     : [JsonCallExecutor][CallExecutor][d40b1776-9592-4388-a74a-a0bb21ed464c][Auth]Received response code 200 OK. Total time = 170 ms. Handshake = 100 ms. Upload = 0 ms (0 bytes). Latency = 68 ms. Download = 0 ms (425 bytes).
09-17 16:13:09.010  1460  7416 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:09.011  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:09.011   576  1560 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:09.011  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:09.011  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:09.012  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:09.012  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:09.015  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:09.015  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:09.015  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:09.015  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:09.016  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:09.019  1460  7418 I F_C.DefaultConsumerClie: getCards
09-17 16:13:09.019  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:09.019  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:09.019  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.kindle.cms.card.producer.APPS, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:09.020  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:09.106  2163  2649 I SendDatasetsSyncOp: Sending 0 dataset update for 'CloudCollections' namespace
09-17 16:13:09.142  2163  2667 I SendDatasetsSyncOp: Sending 0 dataset update for 'CloudCollections.Items' namespace
09-17 16:13:09.870  1460  2341 I F_C.RecencyManager: Recency order has not changed
09-17 16:13:09.882  1460  2337 I F_C.RecencyManager: Notifying recency change for app_usage_key
09-17 16:13:09.888  1460  7380 I F_C.BaseCardProducerSer: Handling work for com.amazon.firelauncher.action.APP_USAGE
09-17 16:13:09.889  1460  7380 I F_C.LauncherNotificatio: Handling work for com.amazon.firelauncher.action.APP_USAGE
09-17 16:13:09.896  1460  7380 I F_C.AppRecency: Accessed content  [...]
09-17 16:13:09.896  1460  7380 I F_C.DefaultAppRecencyDa: Recording app  [...]  as accessed
09-17 16:13:09.903  1460  7380 I F_C.GamesAppsLibraryDec: Drawing cards
09-17 16:13:09.925  1460  7380 I F_C.BaseCardProducerSer: Pushing 2 cards for deck GAMESAPPS. Triggered by com.amazon.firelauncher.action.APP_USAGE
09-17 16:13:09.926  1460  7380 I F_C.ProducerClientCompa: Producer com.amazon.firelauncher.cmsfirecardproducer:GAMESAPPS at API version BrazilVersion(1.5).
09-17 16:13:09.927  1460  7380 I F_C.ProducerClientCompa: Connected to ServerInfo(CDA Version: BrazilVersion(1.3.200380.0), Min. Producer: BrazilVersion(1.0), Delete All: true)
09-17 16:13:09.941  1460  7380 I F_C.CardAgentSynchroniz: Throttling producer refresh
09-17 16:13:09.946  1460  7380 I F_C.CardProvider: CDA:CardProvider:delete(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer:GAMESAPPS), selection:null, selectionArgs: [...] )
09-17 16:13:09.947  1460  7380 I F_C.CardProvider: CDA:CardProvider:insert(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer:GAMESAPPS), contentValues:(com.amazon.firelauncher.cmsfirecardproducer/-489306989/1568751189921))
09-17 16:13:09.950  1460  7380 I F_C.CardProvider: CDA:CardProvider:insert(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer:GAMESAPPS), contentValues:(com.amazon.firelauncher.cmsfirecardproducer/895102831/1568751189925))
09-17 16:13:09.967  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:09.967  1460  1557 I F_C.DefaultConsumerClie: Acquiring ContentProviderClient
09-17 16:13:09.967  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:09.968  1460  1557 I F_C.CardDataSource: Card processing started for: GAMESAPPS (1 card(s))
09-17 16:13:09.970  1460  7419 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:09.971   576  1569 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:09.973  1460  1557 I F_C.CardDataSource: Card filtered, producer: com.amazon.firelauncher.cmsfirecardproducer, target: GAMESAPPS, filter: NONE
09-17 16:13:09.973  1460  1557 I F_C.CardDataSource: Card processing completed for: GAMESAPPS (0 card(s))
09-17 16:13:09.973  1460  1460 I F_C.CardDataSource: Updating cards in target: GAMESAPPS (0 card(s))
09-17 16:13:09.980  1460  1557 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:09.981  1460  1557 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:09.982  1460  1557 I F_C.CardDataSource: Card processing started for: APPSGAMES (1 card(s))
09-17 16:13:09.985  1460  1557 I F_C.CardDataSource: Card filtered, producer: com.amazon.firelauncher.cmsfirecardproducer, target: APPSGAMES, filter: NONE
09-17 16:13:09.985  1460  1557 I F_C.CardDataSource: Card processing completed for: APPSGAMES (0 card(s))
09-17 16:13:09.995  1460  7419 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:09.997   576   829 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:10.007  1460  1460 I F_C.CardDataSource: Updating cards in target: APPSGAMES (0 card(s))
09-17 16:13:10.011  1460  7420 I F_C.PrefetchTrigger: Handling intent to trigger image prefetcher
09-17 16:13:10.012   576   790 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:10.035  1460  7420 I F_C.PrefetchTrigger: Requesting sync for image prefetcher, expedited=false
09-17 16:13:10.035  1460  7421 I F_C.DefaultConsumerClie: getCards
09-17 16:13:10.036   576   587 W AccountManagerService: insertAccountIntoDatabase: Account {name=default_account, type=amazon.account}, skipping since the account already exists
09-17 16:13:10.037  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:10.037  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:10.037  1460  4039 I F_C.DefaultConsumerClie: Acquiring ContentProviderClient
09-17 16:13:10.037  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:10.038  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:10.048  1460  7421 I F_C.DefaultConsumerClie: getCards
09-17 16:13:10.048  1460  4039 I F_C.DefaultConsumerClie: Querying CDA: uri=ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), selection=null, selectionArgs= [...] , orderBy=null
09-17 16:13:10.048  1460  4039 I F_C.DefaultConsumerClie: Looking for local ContentProvider...
09-17 16:13:10.048  1460  4039 I F_C.CardProvider: CDA:CardProvider:query(ParsedUri(PRODUCER=com.amazon.firelauncher.cmsfirecardproducer, CARD= [...] ), projection:null, selection:null, selectionArgs: [...] , sortOrder:null)
09-17 16:13:10.049  1460  4039 I F_C.DefaultConsumerClie: 1 results
09-17 16:13:10.086   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:10.086   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
09-17 16:13:12.088   229   229 I wmt_launcher: fw log ctrl flag has been set
09-17 16:13:12.088   229   229 I wmt_launcher: fw dynamic ctrl flag has been set
ajwfrost commented 4 years ago

Thanks for the details! Definitely looks like there's an issue in the GPU that we're not then handling properly, we can investigate this and see if we can work around this to ensure it's drawn properly..

FliplineStudios commented 4 years ago

Hi Andrew, any chance you were able to diagnose this problem with cacheAsBitmap with AIR for a future fix? Been getting a lot more bug reports coming in (mainly users with Huawei devices) and just wanted to check in if this would ever be fixable. If you need any further details from us just let me know!

fix89 commented 4 years ago

Any update? I'm in alpha test with my app, and I found the same problem with an Honor 8

FliplineStudios commented 4 years ago

Any update on this? Definitely affecting more and more devices these days for our existing apps that rely on cacheAsBitmap. I sent over a test app to help with diagnosing it a while back, but if there's anything else I can do to help let me know!

FliplineStudios commented 4 years ago

Any progress on this issue? Since we'll soon need to update all of our legacy Android apps for 64-bit before Google's deadline, it would be helpful to know if anything is in the works for these errors, or if we should expect that it won't be pursued and we should stop using cacheAsBitmap and cacheAsBitmapMatrix in past and future apps. Thanks!

FliplineStudios commented 3 years ago

Just curious if there's been any progress with these cacheAsBitmap issues, as it's a problem that keeps getting worse over time with more and more new Huawei and other Android devices suffering from the same issue. Getting ready to finally update our legacy Android apps which are all affected by this problem, would definitely appreciate some info on if it's something that's fixable or if we should just assume cacheAsBitmap is deprecated and no longer viable for AIR. Thanks!

ajwfrost commented 3 years ago

@FliplineStudios sorry for the delay but we do now have a reproduction of this bug on an Honor 6X .. will try to enable some debugging into the OpenGL ES code to see if there are errors we can pick up to avoid the problem..

FliplineStudios commented 3 years ago

That's great news that you can reproduce it now! Hopefully you can find some clues with debugging, if there's anything I can do to help with test APKs or anything just let me know.

ajwfrost commented 3 years ago

@FliplineStudios so unfortunately we've found that there are no GL errors or anything going wrong that we can detect.. and having tried various approaches to try to trigger things to redraw or to flush the GL pipeline properly, the only thing that seems to work is to drop the rendering quality to "low". This basically removes the antialiasing, and when we do this, the images all seem to work.

We had been trying to set this up so that most of the display was rendered normally (medium quality is the default on Android I believe) and then to just drop to low quality for the objects that are being captured as cacheAsBitmap. This may be theoretically possible, but it's very complex to achieve and we risk invalidating the whole of the display list, due to the way in which this is handled.

My suggestions at this point would be: a) go with a 'low' quality setting (we forced this across the whole app, it didn't look particularly bad although I'm not perhaps the best judge of that plus it was only a 5" phone..) b) don't use cacheAsBitmap - I'm not sure whether you're able to draw to BitmapData instead perhaps, this looks like it uses a different mechanism.. c) potentially it may actually work if you set the property after it's been rendered without cacheAsBitmap .. wondering whether you could change your code so that the cacheAsBitmap properties are set in an exitFrame handler or similar, i.e. so we render the object with the normal GPU rendering first pass and then cache it next time..

I'm not sure whether you could detect if it's a Mali GPU and adjust the behaviour appropriately? we maybe need to add a property to the Capabilities class for this sort of thing...

We'll be looking at some of the other issues reported around GPU mode (e.g. #753 ) to see whether anything there provides more hints/information, but currently may have to admit defeat on this. We had wondered whether to 'fix' it by just disabling cache-as-bitmap under the hood if we detect this GPU and a medium-quality SWF, but I'd prefer not to do those kind of large hacks unless we have to!

thanks

FliplineStudios commented 3 years ago

@ajwfrost Thanks for the update on this, it's unfortunate there's not a relatively easy fix!

We've been updating our apps with just drawing those assets directly to BitmapData instead of using cacheAsBitmap, which does seem to function correctly though it's of course a bit of a different process, and a bit more complicated if those MovieClips ever change frames. That's an interesting idea with c) if we can delay the cacheAsBitmap call to see if that solves anything, we'll do some experiments with that ourselves.

Is there any chance that AIR is able to detect when the cacheAsBitmap fails like this on those GPUs, and throw an error that we can listen for (so our own app code can make some decisions about drawing to BitmapData on those devices or some other fallback system we implement)? Or is it just silently failing on the GPU, and AIR has no way to know when it has happened?

ajwfrost commented 3 years ago

Is there any chance that AIR is able to detect when the cacheAsBitmap fails like this on those GPUs, and throw an error that we can listen for ... Or is it just silently failing on the GPU, and AIR has no way to know when it has happened

This is the problem, yes - we aren't able to detect the failure via any OpenGL/EGL checks, so we won't know whether the rendering has worked properly or not. There is a possibility mentioned in #110:

We did found a workaround to test each texture for the color for a single pixel. If the pixel color at the specific location was 0x00000000 then we would know that the texture was broken and show an error message to the user. (This only works if you know that the textures should not have that color on that specific pixel).

But the performance penalty with reading back the texture pixels is going to be a bit crazy I'd have thought. Another alternative thought: might it be possible to switch to 'direct' mode rendering perhaps, unless there's a specific requirement for 'gpu' mode?

thanks

FliplineStudios commented 3 years ago

I was afraid that was the case! We've tried "direct" render mode before, but for our type of games using vector graphics and the classic display list, the "direct" performance was pretty poor and closer to what we'd get with "cpu" render mode, whereas with "gpu" render mode we can still achieve 30 fps on ancient/cheap devices. Oh well, I'll see if delaying the cacheAsBitmap call to an exitFrame or just delayed a frame will make any difference on those devices, or just keep working around it by drawing to BitmapData instead.

ged-mc commented 1 year ago

We ran into this cache-as-bitmap issue in our latest android release ( AIR 50-2-2-6 previously AIR 33-1-1-345 ). We use Flex-spark components. It affected several subscribers that we know of with: Lenovo TB-X606 tablets and Samsung SM-T220

The only "solution" that worked is: Compile an app version with cpu ( normally gpu ) This restored the invisible components with cache-as-bitmap but obviously performance is much worse. Release it as closed track beta trial in Google play with a version number higher that the general release Add the affected users' emails to the trial and ask them to switch off auto-update for our app.

Removing cache-as-bitmap is not an option because we have vector artwork everywhere. CPU rendermode for all would not be a good move either because of performance.

FliplineStudios commented 1 year ago

For our own apps we've had to just abandon cacheAsBitmap on GPU mode since it's so unreliable now, which is a shame because it was such a powerful feature. Especially for Android with the wide gap of performance across high-end and low-end devices, that's the platform where we could really use the benefits of cacheAsBitmap, and it's the one platform where it doesn't work correctly anymore.

And just to add to the issue, we've seen a similar issue affects anything that uses a 3D transform, where internally Flash/AIR would cache those graphics even without setting cacheAsBitmap (like with DisplayObject.rotationZ), so unfortunately those are also unusable on Android now too and face the same problems. (Update: On the affected devices, I believe the MovieClips just disappear and don't render at all when setting .rotationZ on them, rather than getting garbled).