search

geeks-r-us / anbox-playstore-installer

Install script that automates installation of googles playstore in anbox
MIT License
656 stars 155 forks source link

Google Play not responding #12

Closed RikudouSage closed 5 years ago

RikudouSage commented 5 years ago

Whenever I click anywhere inside opened Google Play app (e.g. the Sign In button), it freezes for a while and then crashes.

Logcat output (I don't know if everything is relevant, but it's output after I click on Sign In):

09-21 13:37:20.678   112   216 E TaskPersister: File error accessing recents directory (directory doesn't exist?).
09-21 13:37:24.746   112   145 I InputDispatcher: Application is not responding: Window{319f7a0 u0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity}.  It has been 5004.0ms since event, 5003.8ms since wait started.  Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 49.  Wait queue head age: 5505.2ms.
09-21 13:37:24.753   112   145 I WindowManager: Input event dispatching timed out sending to com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity.  Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 49.  Wait queue head age: 5505.2ms.
09-21 13:37:24.764   112   126 I Process : Sending signal. PID: 3262 SIG: 3
09-21 13:37:24.764  3262  3269 I art     : Thread[3,tid=3269,WaitingInMainSignalCatcherLoop,Thread*=0x7fd319e96400,peer=0x12c62b80,"Signal Catcher"]: reacting to signal 3
09-21 13:37:24.764  3262  3269 I art     : 
09-21 13:37:24.810  3262  3269 I art     : Wrote stack traces to '/data/anr/traces.txt'
09-21 13:37:24.810   112   126 I Process : Sending signal. PID: 112 SIG: 3
09-21 13:37:24.811   112   116 I art     : Thread[2,tid=116,WaitingInMainSignalCatcherLoop,Thread*=0x7fd31240d000,peer=0x12c010d0,"Signal Catcher"]: reacting to signal 3
09-21 13:37:24.811   112   116 I art     : 
09-21 13:37:24.868   112   116 I art     : Wrote stack traces to '/data/anr/traces.txt'
09-21 13:37:24.868   112   126 I Process : Sending signal. PID: 292 SIG: 3
09-21 13:37:24.868   292   298 I art     : Thread[3,tid=298,WaitingInMainSignalCatcherLoop,Thread*=0x7fd319e96400,peer=0x12c00820,"Signal Catcher"]: reacting to signal 3
09-21 13:37:24.868   292   298 I art     : 
09-21 13:37:24.879   292   298 I art     : Wrote stack traces to '/data/anr/traces.txt'
09-21 13:37:24.879   112   126 I Process : Sending signal. PID: 232 SIG: 3
09-21 13:37:24.879   232   251 I art     : Thread[3,tid=251,WaitingInMainSignalCatcherLoop,Thread*=0x7fd319e96400,peer=0x12c005e0,"Signal Catcher"]: reacting to signal 3
09-21 13:37:24.879   232   251 I art     : 
09-21 13:37:24.892   232   251 I art     : Wrote stack traces to '/data/anr/traces.txt'
09-21 13:37:24.893     9     9 W         : debuggerd: handling request: pid=28 uid=1000 gid=1003 tid=28
09-21 13:37:24.951     9     9 W         : debuggerd: resuming target 28
09-21 13:37:24.951     9     9 W         : debuggerd: handling request: pid=31 uid=1041 gid=1005 tid=31
09-21 13:37:24.951     8     8 W         : debuggerd: handling request: pid=31 uid=1041 gid=1005 tid=31
09-21 13:37:24.988     8     8 W         : debuggerd: resuming target 31
09-21 13:37:24.988     9     9 W         : debuggerd: handling request: pid=32 uid=1047 gid=1005 tid=32
09-21 13:37:24.988     8     8 W         : debuggerd: handling request: pid=32 uid=1047 gid=1005 tid=32
09-21 13:37:25.005     8     8 W         : debuggerd: resuming target 32
09-21 13:37:25.006     9     9 W         : debuggerd: handling request: pid=33 uid=1019 gid=1019 tid=33
09-21 13:37:25.006     8     8 W         : debuggerd: handling request: pid=33 uid=1019 gid=1019 tid=33
09-21 13:37:25.023     8     8 W         : debuggerd: resuming target 33
09-21 13:37:25.023     9     9 W         : debuggerd: handling request: pid=36 uid=1046 gid=1006 tid=36
09-21 13:37:25.023     8     8 W         : debuggerd: handling request: pid=36 uid=1046 gid=1006 tid=36
09-21 13:37:25.035     8     8 W         : debuggerd: resuming target 36
09-21 13:37:25.036     9     9 W         : debuggerd: handling request: pid=37 uid=1013 gid=1031 tid=37
09-21 13:37:25.036     8     8 W         : debuggerd: handling request: pid=37 uid=1013 gid=1031 tid=37
09-21 13:37:25.052     8     8 W         : debuggerd: resuming target 37
09-21 13:37:25.052     9     9 W         : debuggerd: handling request: pid=38 uid=1040 gid=1026 tid=38
09-21 13:37:25.052     8     8 W         : debuggerd: handling request: pid=38 uid=1040 gid=1026 tid=38
09-21 13:37:25.074     8     8 W         : debuggerd: resuming target 38
09-21 13:37:25.074     9     9 W         : debuggerd: handling request: pid=39 uid=1013 gid=1005 tid=39
09-21 13:37:25.074     8     8 W         : debuggerd: handling request: pid=39 uid=1013 gid=1005 tid=39
09-21 13:37:25.095     8     8 W         : debuggerd: resuming target 39
09-21 13:37:25.096     9     9 W         : debuggerd: handling request: pid=218 uid=1023 gid=1023 tid=218
09-21 13:37:25.111     9     9 W         : debuggerd: resuming target 218
09-21 13:37:25.627   112   126 E ActivityManager: ANR in com.android.vending (com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity)
09-21 13:37:25.627   112   126 E ActivityManager: PID: 3262
09-21 13:37:25.627   112   126 E ActivityManager: Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 49.  Wait queue head age: 5505.2ms.)
09-21 13:37:25.627   112   126 E ActivityManager: Load: 0.87 / 1.71 / 1.28
09-21 13:37:25.627   112   126 E ActivityManager: CPU usage from 18685ms to 0ms ago (2018-09-21 13:37:06.071 to 2018-09-21 13:37:24.757):
09-21 13:37:25.627   112   126 E ActivityManager:   2.4% 112/system_server: 1.3% user + 1% kernel / faults: 3315 minor 2 major
09-21 13:37:25.627   112   126 E ActivityManager:   0.8% 28/surfaceflinger: 0.5% user + 0.3% kernel
09-21 13:37:25.627   112   126 E ActivityManager:   0% 53/adbd: 0% user + 0% kernel / faults: 251 minor 8 major
09-21 13:37:25.627   112   126 E ActivityManager:   0.4% 456/org.anbox.appmgr: 0.3% user + 0.1% kernel / faults: 91 minor 2 major
09-21 13:37:25.627   112   126 E ActivityManager:   0.3% 7/logd: 0% user + 0.3% kernel / faults: 18 minor 1 major
09-21 13:37:25.627   112   126 E ActivityManager:   0.2% 2790/com.google.android.gms: 0.2% user + 0% kernel / faults: 735 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0.2% 2806/com.google.android.gms.persistent: 0.2% user + 0% kernel / faults: 748 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0.1% 232/com.android.systemui: 0.1% user + 0% kernel / faults: 51 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0.1% 545/com.google.process.gapps: 0.1% user + 0% kernel / faults: 344 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0% 292/com.android.phone: 0% user + 0% kernel / faults: 91 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0% 9/debuggerd64: 0% user + 0% kernel / faults: 108 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0% 25/logcat: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager:   0% 26/lmkd: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager:   0% 27/servicemanager: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager:   0% 29/zygote64: 0% user + 0% kernel / faults: 310 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0% 38/media.extractor: 0% user + 0% kernel / faults: 63 minor
09-21 13:37:25.627   112   126 E ActivityManager:   0% 45/logcat: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager:   0% 608/android.process.media: 0% user + 0% kernel / faults: 197 minor
09-21 13:37:25.627   112   126 E ActivityManager:  +0% 3255/logcat: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager:  +0% 3262/com.android.vending: 0% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager: 18% TOTAL: 9.9% user + 7% kernel + 1.4% iowait + 0% softirq
09-21 13:37:25.627   112   126 E ActivityManager: CPU usage from 365ms to 867ms later (2018-09-21 13:37:25.122 to 2018-09-21 13:37:25.624):
09-21 13:37:25.627   112   126 E ActivityManager:   3.9% 112/system_server: 1.9% user + 1.9% kernel / faults: 26 minor
09-21 13:37:25.627   112   126 E ActivityManager:     3.9% 122/HeapTaskDaemon: 3.9% user + 0% kernel
09-21 13:37:25.627   112   126 E ActivityManager: 27% TOTAL: 23% user + 3.9% kernel
09-21 13:37:25.627   112   127 W ActivityManager:   Force finishing activity com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity
09-21 13:37:25.632   112   127 W ActivityManager:   Force finishing activity com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity
09-21 13:37:25.632   112   127 W ActivityManager: Duplicate finish request for ActivityRecord{9196a22 u0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity t16 f}
09-21 13:37:25.632   112   127 I ActivityManager: Killing 3262:com.android.vending/u0a24 (adj 0): user request after error
09-21 13:37:25.638   456   456 D ViewRootImpl[AppViewActivity]: updatePointerIcon called with position out of bounds
09-21 13:37:25.673   112   145 W InputDispatcher: channel '319f7a0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0xd
09-21 13:37:25.673   112   840 D GraphicsStats: Buffer count: 3
09-21 13:37:25.673   112   817 I WindowManager: WIN DEATH: Window{319f7a0 u0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity}
09-21 13:37:25.673   112   324 D ActivityManager: cleanUpApplicationRecord -- 3262
09-21 13:37:25.673   112   324 W ActivityManager: Scheduling restart of crashed service com.android.vending/com.google.android.finsky.scheduler.JobSchedulerEngine$PhoneskyJobSchedulerJobService in 1000ms
09-21 13:37:25.674   112   145 E InputDispatcher: channel '319f7a0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
09-21 13:37:25.674   112   817 W InputDispatcher: Attempted to unregister already unregistered input channel '319f7a0 com.android.vending/com.google.android.finsky.unauthenticated.UnauthenticatedMainActivity (server)'
09-21 13:37:25.675   112   324 I AnboxPlatformServiceProxy: Task removed id=16
09-21 13:37:28.678   112   216 E TaskPersister: File error accessing recents directory (directory doesn't exist?).
castlec commented 5 years ago

I'm seeing the same behavior. Logcat follows.

--------- beginning of system
10-11 17:13:41.854   111   372 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 pkg=com.android.vending cmp=com.android.vending/.AssetBrowserActivity} from uid 10000 on display 0
--------- beginning of main
10-11 17:13:41.864    41    94 I MediaPlayerService: MediaPlayerService::getOMX
10-11 17:13:41.865   111  2932 I OMXClient: MuxOMX ctor
10-11 17:13:41.865   111  2932 E ACodec  : Unable to instantiate a decoder for type 'audio/vorbis' with err 0xfffffffe.
10-11 17:13:41.866   111  2932 E ACodec  : signalError(omxError 0xfffffffe, internalError -2)
10-11 17:13:41.866   111  2932 E MediaCodec: Codec reported err 0xfffffffe, actionCode 0, while in state 1
10-11 17:13:41.867   111  2930 E SoundPool: Unable to load sample
10-11 17:13:41.871   111   166 W AudioService: onLoadSoundEffects(), Error -2147483648 while loading samples
10-11 17:13:41.872   111   260 I ActivityManager: Start proc 2933:com.android.vending/u0a50 for activity com.android.vending/.AssetBrowserActivity
10-11 17:13:41.872  2933  2933 W art     : Unexpected CPU variant for X86 using defaults: x86_64
10-11 17:13:41.876    41    41 I MediaPlayerService: MediaPlayerService::getOMX
10-11 17:13:41.877   111  2943 I OMXClient: MuxOMX ctor
10-11 17:13:41.877   111  2943 E ACodec  : Unable to instantiate a decoder for type 'audio/vorbis' with err 0xfffffffe.
10-11 17:13:41.877   111  2943 E ACodec  : signalError(omxError 0xfffffffe, internalError -2)
10-11 17:13:41.878   111  2943 E MediaCodec: Codec reported err 0xfffffffe, actionCode 0, while in state 1
10-11 17:13:41.878   111  2930 E SoundPool: Unable to load sample
10-11 17:13:41.898  2933  2933 I art     : Starting a blocking GC AddRemoveAppImageSpace
10-11 17:13:41.899  2933  2933 W System  : ClassLoader referenced unknown path: /system/priv-app/Phonesky/lib/x86_64
10-11 17:13:42.059  2933  2956 I Finsky  : [176] com.google.android.finsky.dn.a.l.a(5): Started reading experiment flags from file [cQT_5lyWGrZr7c_s4E7WwRixWFM].
10-11 17:13:42.059  2933  2955 I Finsky  : [175] com.google.android.finsky.dn.a.l.a(5): Started reading experiment flags from file [SKocQA9EQQFTb-1gQsc5WsjVhGA].
10-11 17:13:42.062  2933  2955 I Finsky  : [175] com.google.android.finsky.dn.a.l.a(13): Finished reading experiment flags from file [SKocQA9EQQFTb-1gQsc5WsjVhGA].
10-11 17:13:42.062  2933  2956 I Finsky  : [176] com.google.android.finsky.dn.a.l.a(13): Finished reading experiment flags from file [cQT_5lyWGrZr7c_s4E7WwRixWFM].
10-11 17:13:42.096  2933  2933 I Finsky  : [1] com.google.android.finsky.wear.br.a(11): Component class com.google.android.finsky.wear.WearSupportService enabled via PackageManager.
10-11 17:13:42.097  2933  2933 I Finsky  : [1] com.google.android.finsky.wear.br.a(11): Component class com.google.android.finsky.wear.WearChangeListenerService enabled via PackageManager.
10-11 17:13:42.097  2933  2933 I Finsky  : [1] com.google.android.finsky.application.impl.c.b(502): Not a unicorn device
10-11 17:13:42.100  2933  2933 W Settings: Setting download_manager_max_bytes_over_mobile has moved from android.provider.Settings.Secure to android.provider.Settings.Global.
10-11 17:13:42.101  2933  2933 W Settings: Setting download_manager_recommended_max_bytes_over_mobile has moved from android.provider.Settings.Secure to android.provider.Settings.Global.
10-11 17:13:42.123  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.ba.<init>(18): Resetting scheduler db
10-11 17:13:42.125  2933  2933 I Finsky  : [1] com.google.android.finsky.hygiene.impl.e.a(33): Scheduling NO_RECENT_SUCCESS in onApplicationCreate
10-11 17:13:42.133  2933  2979 I Finsky  : [198] com.google.android.finsky.library.a.f.j(52): Loaded library for account: [t7UZSw47TsBHzQLjcl_BxFdAz18]
10-11 17:13:42.166  2933  2933 I Finsky  : [1] com.google.android.finsky.installer.a.r.<init>(15): Not checking if recovering from paused session because experiment is off
10-11 17:13:42.170  2933  2979 I Finsky  : [198] com.google.android.finsky.library.a.f.j(76): Finished loading 1 libraries.
10-11 17:13:42.217  2933  2933 I Finsky  : [1] com.google.android.finsky.verifier.impl.dh.b(96): Setup app restrictions monitor
10-11 17:13:42.217  2933  2933 I Finsky  : [1] com.google.android.finsky.verifier.impl.en.a(16): Device wide unknown source restriction is changed.
10-11 17:13:42.238  2933  2933 W Finsky  : [1] com.google.android.finsky.f.af.a(35): Null bundle, which breaks event chain!. Creating a new logging context.
10-11 17:13:42.273  2933  2938 I art     : Do partial code cache collection, code=30KB, data=24KB
10-11 17:13:42.273  2933  2938 I art     : After code cache collection, code=29KB, data=24KB
10-11 17:13:42.273  2933  2938 I art     : Increasing code cache capacity to 128KB
10-11 17:13:42.281  2933  2933 I ViewConfigCompat: Could not find method getScaledScrollFactor() on ViewConfiguration
10-11 17:13:42.421  2933  2933 D         : HostConnection::get() New Host Connection established 0x7f3cab1fde00, tid 2933
10-11 17:13:42.431  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.av.a(9): Resetting scheduler db stage 2
10-11 17:13:42.431  2933  2984 I Finsky  : [203] com.google.android.finsky.verifier.impl.ay.a(5): Restoring notifications
10-11 17:13:42.432  2933  2933 I Finsky  : [1] com.google.android.finsky.installer.a.ah.a(475): Installer kick - no action, not running yet
10-11 17:13:42.434  2933  2938 I art     : Do partial code cache collection, code=50KB, data=53KB
10-11 17:13:42.435  2933  2938 I art     : After code cache collection, code=48KB, data=52KB
10-11 17:13:42.435  2933  2938 I art     : Increasing code cache capacity to 256KB
10-11 17:13:42.437  2933  2938 I art     : Compiler allocated 5MB to compile com.caverock.androidsvg.ao com.caverock.androidsvg.da.m(java.lang.String)
10-11 17:13:42.441  2933  2933 I Finsky  : [1] com.google.android.finsky.selfupdate.f.a(86): Skipping DFE self-update. Local Version [81141600] >= Server Version [-1]
10-11 17:13:42.476  2933  2988 D         : HostConnection::get() New Host Connection established 0x7f3cab1fdd40, tid 2988
10-11 17:13:42.511  2933  2988 I OpenGLRenderer: Initialized EGL, version 1.4
10-11 17:13:42.511  2933  2988 D OpenGLRenderer: Swap behavior 1
10-11 17:13:42.678   111   132 I ActivityManager: Displayed com.android.vending/.AssetBrowserActivity: +816ms
10-11 17:13:42.734  2933  2933 I Finsky  : [1] com.google.android.finsky.verifier.impl.ay.c(32): Done restoring notifications
10-11 17:13:42.737  2933  2933 I Finsky  : [1] com.google.android.finsky.splitinstallservice.ck.a(10): Connecting InstallListener to SplitInstallService broadcaster...
10-11 17:13:42.739  2933  2933 W Finsky  : [1] com.google.android.finsky.f.af.a(35): Null bundle, which breaks event chain!. Creating a new logging context.
10-11 17:13:42.771  1857  1857 I MobileDataPlan: [1] MobileDataPlanApiChimeraService.<init>: Service is created.
10-11 17:13:42.787  2933  2933 I Finsky  : [1] com.google.android.finsky.bq.a.c.a(37): FamilyOptions=10111=>[1, 4]
10-11 17:13:42.795  1857  1869 I MobileDataPlan: Creating clearcut logger with com.google.android.gms.mobiledataplan.service.MobileDataPlanApiChimeraService@4e77fb7
10-11 17:13:42.798  1857  1869 I MobileDataPlan: [134] MobileDataPlanApiChimeraService.a: onGetService success for google package com.android.vending.
10-11 17:13:42.860  2933  2997 I PrimesTesting: GserviceFlagsSupplier.get()
10-11 17:13:42.894  2933  2938 I art     : Do full code cache collection, code=125KB, data=117KB
10-11 17:13:42.894  2933  2938 I art     : Waiting for a blocking GC JitCodeCache
10-11 17:13:42.904  2933  2938 I art     : WaitForGcToComplete blocked for 9.700ms for cause JitCodeCache
10-11 17:13:42.904  2933  2938 I art     : Starting a blocking GC JitCodeCache
10-11 17:13:42.904  2933  2938 I art     : After code cache collection, code=88KB, data=69KB
10-11 17:13:42.946  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.JobSchedulerEngine.a(103): Cancelling existing job with id: 9000
10-11 17:13:42.947  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.JobSchedulerEngine.a(15): Scheduling immediate wakeup job with id: 9000
10-11 17:13:43.002  2933  2971 D NetworkSecurityConfig: No Network Security Config specified, using platform default
10-11 17:13:43.005  2933  2938 I art     : Do partial code cache collection, code=96KB, data=105KB
10-11 17:13:43.005  2933  2938 I art     : After code cache collection, code=95KB, data=105KB
10-11 17:13:43.005  2933  2938 I art     : Increasing code cache capacity to 512KB
10-11 17:13:43.006  2933  2938 I art     : Compiler allocated 5MB to compile void com.google.android.finsky.playcard.p.a(com.google.android.play.layout.d, com.google.android.finsky.dfemodel.Document, int, java.lang.String, com.google.android.finsky.navigationmanager.c, boolean, com.google.android.finsky.playcardview.base.u, com.google.android.finsky.f.aq, com.google.android.finsky.installqueue.s, boolean, int, boolean, boolean, com.google.android.finsky.f.af, boolean, boolean, boolean, com.google.android.finsky.do.c.g)
10-11 17:13:43.018  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.JobSchedulerEngine$PhoneskyJobSchedulerJobService.onStartJob(7): onJobSchedulerWakeup with jobId 9000
10-11 17:13:43.019  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.v.a(39): Scheduling fallback in 43200000 (absolute: 2086031812)
10-11 17:13:43.019  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.v.a(39): Scheduling fallback in 64800000 (absolute: 2107631813)
10-11 17:13:43.067  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.ac.handleMessage(16): DeviceState: DeviceState{currentTime=1539278023030, isCharging=true, isIdle=false, netAny=true, netNotRoaming=true, netUnmetered=true}
10-11 17:13:43.127  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.ba.a(64): Jobs in database: 1-1337 2-48879 10-11 10-26 10-39 12-1 
10-11 17:13:43.191  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.x.a(58): Running job: 1-1337
10-11 17:13:43.200  2933  2933 I Finsky  : [1] com.google.android.finsky.hygiene.impl.o.a(45): Beginning daily hygiene, foreground = false, reason = 15
10-11 17:13:43.205  2933  2933 I Finsky  : [1] com.google.android.finsky.cb.a.b(54): Probe [t7UZSw47TsBHzQLjcl_BxFdAz18] for hygiene pass
10-11 17:13:43.208  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.x.a(99): RunningQueue size: 1, PendingQueue size: 4
10-11 17:13:43.208  2933  2933 I Finsky  : [1] com.google.android.finsky.scheduler.x.a(108): Running queue: 1-1337 
10-11 17:13:43.280  2933  2985 D PhenotypeDbHelper: Enabled write-ahead logging
10-11 17:13:43.284  2933  2985 D HeterodyneSyncer: retaining: onyxrook@gmail.com
10-11 17:13:43.284  2933  2985 D HeterodyneSyncer: retaining committed user: onyxrook@gmail.com
10-11 17:13:43.285  2933  2985 D HeterodyneSyncer: retaining committed user: 
10-11 17:13:43.285  2933  2985 E XXX     : Going to delete [com.google.android.finsky.regular, , 81141600]
10-11 17:13:43.286  2933  2985 E XXX     : Going to delete [com.google.android.finsky.regular, onyxrook@gmail.com, 81141600]
10-11 17:13:43.286  2933  2985 E XXX     : Going to delete [com.google.android.finsky.stable, , 81141600]
10-11 17:13:43.286  2933  2985 E XXX     : Going to delete [com.google.android.finsky.stable, onyxrook@gmail.com, 81141600]
10-11 17:13:43.311  2933  2985 D HeterodyneSyncer: Heterodyne Request: # com.google.f.a.o@9c1fa67b
10-11 17:13:43.323  2933  2985 D ApacheHttpTransport: Contacting Heterodyne at https://www.googleapis.com/experimentsandconfigs/v1/getExperimentsAndConfigs
10-11 17:13:43.387  2933  2938 I art     : Compiler allocated 5MB to compile void com.caverock.androidsvg.da.startElement(java.lang.String, java.lang.String, java.lang.String, org.xml.sax.Attributes)
10-11 17:13:43.428  2933  2938 I art     : Do full code cache collection, code=227KB, data=240KB
10-11 17:13:43.428  2933  2938 I art     : Starting a blocking GC JitCodeCache
10-11 17:13:43.428  2933  2938 I art     : After code cache collection, code=217KB, data=176KB
10-11 17:13:43.521  2933  2985 I RequestAddCookies: Cookie store not available in HTTP context
10-11 17:13:43.640  2933  2985 I ResponseProcessCookies: Cookie store not available in HTTP context
10-11 17:13:43.644  2933  2985 D HeterodyneSyncer: Heterodyne Response: # com.google.f.a.u@559909a7
10-11 17:13:43.644  2933  2985 D HeterodyneSyncer: 5: 1538643955
10-11 17:13:43.644  2933  2985 D HeterodyneSyncer: Heterodyne response: # com.google.f.a.u@559909a7
10-11 17:13:43.644  2933  2985 D HeterodyneSyncer: 5: 1538643955
10-11 17:13:43.646  2933  2985 D HeterodyneSyncer: update last fetch to 1539276900
10-11 17:13:43.646  2933  2985 D HeterodyneSyncer: No change response
10-11 17:13:43.658  2933  2985 D HeterodyneConfigVersion: clearing HeterodyneConfigVersionCache
10-11 17:13:43.667  2933  2985 D HeterodyneSyncer: Heterodyne Request: # com.google.f.a.o@d41bbac5
10-11 17:13:43.670  2933  2985 D ApacheHttpTransport: Contacting Heterodyne at https://www.googleapis.com/experimentsandconfigs/v1/getExperimentsAndConfigs
10-11 17:13:43.670  2933  2985 I RequestAddCookies: Cookie store not available in HTTP context
10-11 17:13:43.783  2933  2985 I ResponseProcessCookies: Cookie store not available in HTTP context
10-11 17:13:43.784  2933  2985 D HeterodyneSyncer: Heterodyne Response: # com.google.f.a.u@66970154
10-11 17:13:43.784  2933  2985 D HeterodyneSyncer: 5: 1538643955
10-11 17:13:43.784  2933  2985 D HeterodyneSyncer: Heterodyne response: # com.google.f.a.u@66970154
10-11 17:13:43.784  2933  2985 D HeterodyneSyncer: 5: 1538643955
10-11 17:13:43.785  2933  2985 D HeterodyneSyncer: update last fetch to 1539276900
10-11 17:13:43.786  2933  2985 D HeterodyneSyncer: No change response
10-11 17:13:43.789  2933  2985 D HeterodyneConfigVersion: clearing HeterodyneConfigVersionCache
10-11 17:13:43.793  2933  2985 E Finsky  : [204] com.google.android.finsky.as.c.a(25): Unable to build selector: /storage/emulated/0/Download/marketenvs.csv (No such file or directory)
10-11 17:13:43.798  2933  2984 I Finsky  : [203] com.google.android.finsky.dn.a.a.a.b(29): Triggered update for experiment package com.google.android.finsky.regular.
10-11 17:13:43.832  2933  2984 D GetConfigurationSnapsho: getFullConfigurations
10-11 17:13:43.839  2933  2984 D GetConfigurationSnapsho: byFlagStorageType, addSet = Flag(AutoUpdate__enable_auto_update_settings_dialog_v2, true, 2, 0), Flag(DeviceSetup__pai_sim_workaround, false, 2, 0), Flag(DynamicSplits__dynamic_split_download_size_threshold, -1, 1, 0), Flag(DynamicSplits__dynamic_split_download_size_threshold_metered, 10485760, 1, 0), Flag(DynamicSplits__dynamic_split_download_size_threshold_unmetered, 10485760, 1, 0), Flag(DynamicSplits__dynamic_split_package_controller_pre_L, '+com.facebook.katana,com.facebook.samples.modularity,com.facebook.lite,com.facebook.orca,com.instagram.android', 4, 0), Flag(Everglades__enable_everglades, false, 2, 0), Flag(ExperimentFramework__enable_heterodyne_periodic_sync, false, 2, 0), Flag(ExperimentFramework__enable_heterodyne_periodic_sync_logging, false, 2, 0), Flag(ExperimentFramework__heterodyne_periodic_sync_cycle_ms, 43200000, 1, 0), Flag(ExperimentFramework__heterodyne_periodic_sync_deadline_ms, 64800000, 1, 0), Flag(ExperimentFramework__reset_stale_experiments_status_on_clear_cache_callback, true, 2, 0), Flag(GooglePlayProtect__enable_per_source_installation_consent, false, 2, 0), Flag(GooglePlayProtect__enable_psic_uninstallation_dialog, false, 2, 0), Flag(GooglePlayProtect__migrate_to_verifier_clearcut_log, false, 2, 0), Flag(InstantAppsAccountManagement__enable_sync_instant_apps_account_with_phonesky_account, false, 2, 0), Flag(LiveOps__enable_live_ops_module, false, 2, 0), Flag(LiveOps__enable_single_app_live_ops_deep_link, false, 2, 0), Flag(NetworkRequestMigration__migrate_add_delete_review_to_cronet, false, 2, 0), Flag(NetworkRequestMigration__migrate_searchsuggest_to_cronet, false, 2, 0), Flag(OfflineGames__enable_offline_games, false, 2, 0), Flag(Phenotype__enable_cache_clearing_ps_exp, true, 2, 0), Flag(PreregAds__enable_all_prereg_traffic_to_pgs, true, 2, 0), Flag(PromotionCampaignDetailsPage__CdpClientControlledTerms, false, 2, 0), Flag(QaQualify__uds_env_indicator, 'PROD', 4, 0), Flag(RequestQos__enable_latency_tolerant_qos, false, 2, 0), Flag(SaturnV__delay_decompress_ms, 0, 1, 0), Flag(SaturnV__delay_installation_ms, 0, 1, 0), Flag(ScionReporting__enable_scion_subscription_reporting, false, 2, 0), Flag(TestColorTheme__color_label, 'blue', 4, 0), Flag(TestColorTheme__title_bar_color, -16776961, 1, 0), Flag(TestColorTheme__transition_delay, 10.0, 3, 0), Flag(TestColorTheme__transparent_background, false, 2, 0), Flag(TestConfig__backend_urls, '', 5, 0), Flag(TestFeatureAndroidId__test_bool_flag, false, 2, 0), Flag(UserLanguages__go_async_in_locale_changed_receiver, true, 2, 0), Flag(UserLanguages__language_change_log_broadcast_events, true, 2, 0), Flag(UserLanguages__no_op_flag_that_does_nothing_and_client_does_not_use, false, 2, 0), Flag(UserLanguages__number_of_languages_to_record, 5, 1, 0), Flag(UserLanguages__only_kill_phonesky_on_language_change_if_in_background, true, 2, 0), Flag(UserLanguages__report_user_languages, false, 2, 0), Flag(UserLanguages__send_user_languages, true, 2, 0), Flag(UserLanguages__update_splits_on_language_change, true, 2, 0), Flag(UserLanguages__user_language_change_foreground_timeout_millis, 10000, 1, 0), Flag(ZeroPrefixRecentSearchSuggestion__zero_prefix_recent_search_suggestion_count, 2, 1, 0)
10-11 17:13:43.840  2933  2984 D GetConfigurationSnapsho: byFlagStorageType, deleteSet = 
10-11 17:13:43.841  2933  2984 I Finsky  : [203] com.google.android.finsky.dn.a.a.a.b(62): Already at the latest configurations for experiment package com.google.android.finsky.regular.
10-11 17:13:43.841  2933  2981 I Finsky  : [200] com.google.android.finsky.dn.a.a.a.b(29): Triggered update for experiment package com.google.android.finsky.stable.
10-11 17:13:43.847  2933  2981 D GetConfigurationSnapsho: getFullConfigurations
10-11 17:13:43.849  2933  2981 D GetConfigurationSnapsho: byFlagStorageType, addSet = Flag(D30DeveloperPage__enable_d30_developer_page_redesign, false, 2, 0), Flag(NetworkOptimizations__enable_dns_cache_warmup, true, 2, 0), Flag(NetworkOptimizations__enable_dns_cache_warmup_logging, true, 2, 0), Flag(NetworkOptimizations__enable_quic_connection_options, true, 2, 0), Flag(NetworkOptimizations__enable_quic_idle_connection_timeout, true, 2, 0), Flag(NetworkOptimizations__enable_quic_server_configs_to_store, false, 2, 0), Flag(NetworkOptimizations__enable_stale_dns, true, 2, 0), Flag(NetworkOptimizations__migrate_quic_sessions_on_network_change, false, 2, 0), Flag(NetworkOptimizations__race_cert_verification, false, 2, 0), Flag(TestFeatureAndroidId__test_bool_flag, false, 2, 0), Flag(TestNetwork__use_dfe_v2, false, 2, 0), Flag(TopCharts__enforce_peeking_on_inline_top_charts, false, 2, 0)
10-11 17:13:43.849  2933  2981 D GetConfigurationSnapsho: byFlagStorageType, deleteSet = 
10-11 17:13:43.850  2933  2981 I Finsky  : [200] com.google.android.finsky.dn.a.a.a.b(62): Already at the latest configurations for experiment package com.google.android.finsky.stable.
10-11 17:13:44.204  2933  2933 I Finsky  : [1] com.google.android.finsky.hygiene.g.a(2): Account synced successfully.
10-11 17:13:44.459  2933  2938 I art     : Do partial code cache collection, code=224KB, data=215KB
10-11 17:13:44.459  2933  2938 I art     : After code cache collection, code=224KB, data=215KB
10-11 17:13:44.459  2933  2938 I art     : Increasing code cache capacity to 1024KB
10-11 17:13:44.460  2933  2938 I art     : Compiler allocated 4MB to compile void com.google.android.finsky.playcard.p.a(com.google.android.finsky.dfemodel.Document, com.google.android.play.layout.d, boolean)
10-11 17:13:50.081   111   144 I InputDispatcher: Application is not responding: Window{3c2f999 u0 com.android.vending/com.android.vending.AssetBrowserActivity}.  It has been 5005.1ms since event, 5005.0ms since wait started.  Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 26.  Wait queue head age: 5533.4ms.
10-11 17:13:50.083   111   144 I WindowManager: Input event dispatching timed out sending to com.android.vending/com.android.vending.AssetBrowserActivity.  Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 26.  Wait queue head age: 5533.4ms.
10-11 17:13:50.085   111   125 I Process : Sending signal. PID: 2933 SIG: 3
10-11 17:13:50.085  2933  2939 I art     : Thread[3,tid=2939,WaitingInMainSignalCatcherLoop,Thread*=0x7f3cc4e96400,peer=0x12c368b0,"Signal Catcher"]: reacting to signal 3
10-11 17:13:50.085  2933  2939 I art     : 
10-11 17:13:50.112  2933  2939 I art     : Wrote stack traces to '/data/anr/traces.txt'
10-11 17:13:50.112   111   125 I Process : Sending signal. PID: 111 SIG: 3
10-11 17:13:50.112   111   115 I art     : Thread[2,tid=115,WaitingInMainSignalCatcherLoop,Thread*=0x7f3cbd60d000,peer=0x12c010d0,"Signal Catcher"]: reacting to signal 3
10-11 17:13:50.112   111   115 I art     : 
10-11 17:13:50.163   111   115 I art     : Wrote stack traces to '/data/anr/traces.txt'
10-11 17:13:50.163   111   125 I Process : Sending signal. PID: 265 SIG: 3
10-11 17:13:50.163   265   271 I art     : Thread[3,tid=271,WaitingInMainSignalCatcherLoop,Thread*=0x7f3cc4e96400,peer=0x12c00820,"Signal Catcher"]: reacting to signal 3
10-11 17:13:50.163   265   271 I art     : 
10-11 17:13:50.176   265   271 I art     : Wrote stack traces to '/data/anr/traces.txt'
10-11 17:13:50.176   111   125 I Process : Sending signal. PID: 183 SIG: 3
10-11 17:13:50.176   183   195 I art     : Thread[3,tid=195,WaitingInMainSignalCatcherLoop,Thread*=0x7f3cc4e96400,peer=0x12c00310,"Signal Catcher"]: reacting to signal 3
10-11 17:13:50.176   183   195 I art     : 
10-11 17:13:50.188   183   195 I art     : Wrote stack traces to '/data/anr/traces.txt'
10-11 17:13:50.189     9     9 W         : debuggerd: handling request: pid=29 uid=1000 gid=1003 tid=29
10-11 17:13:50.232     9     9 W         : debuggerd: resuming target 29
10-11 17:13:50.232     9     9 W         : debuggerd: handling request: pid=33 uid=1041 gid=1005 tid=33
10-11 17:13:50.232     8     8 W         : debuggerd: handling request: pid=33 uid=1041 gid=1005 tid=33
10-11 17:13:50.260     8     8 W         : debuggerd: resuming target 33
10-11 17:13:50.260     9     9 W         : debuggerd: handling request: pid=34 uid=1047 gid=1005 tid=34
10-11 17:13:50.260     8     8 W         : debuggerd: handling request: pid=34 uid=1047 gid=1005 tid=34
10-11 17:13:50.273     8     8 W         : debuggerd: resuming target 34
10-11 17:13:50.274     9     9 W         : debuggerd: handling request: pid=35 uid=1019 gid=1019 tid=35
10-11 17:13:50.274     8     8 W         : debuggerd: handling request: pid=35 uid=1019 gid=1019 tid=35
10-11 17:13:50.284     8     8 W         : debuggerd: resuming target 35
10-11 17:13:50.285     9     9 W         : debuggerd: handling request: pid=38 uid=1046 gid=1006 tid=38
10-11 17:13:50.285     8     8 W         : debuggerd: handling request: pid=38 uid=1046 gid=1006 tid=38
10-11 17:13:50.294     8     8 W         : debuggerd: resuming target 38
10-11 17:13:50.294     9     9 W         : debuggerd: handling request: pid=39 uid=1013 gid=1031 tid=39
10-11 17:13:50.294     8     8 W         : debuggerd: handling request: pid=39 uid=1013 gid=1031 tid=39
10-11 17:13:50.305     8     8 W         : debuggerd: resuming target 39
10-11 17:13:50.305     9     9 W         : debuggerd: handling request: pid=40 uid=1040 gid=1026 tid=40
10-11 17:13:50.305     8     8 W         : debuggerd: handling request: pid=40 uid=1040 gid=1026 tid=40
10-11 17:13:50.320     8     8 W         : debuggerd: resuming target 40
10-11 17:13:50.321     9     9 W         : debuggerd: handling request: pid=41 uid=1013 gid=1005 tid=41
10-11 17:13:50.321     8     8 W         : debuggerd: handling request: pid=41 uid=1013 gid=1005 tid=41
10-11 17:13:50.333     8     8 W         : debuggerd: resuming target 41
10-11 17:13:50.333     9     9 W         : debuggerd: handling request: pid=188 uid=1023 gid=1023 tid=188
10-11 17:13:50.342     9     9 W         : debuggerd: resuming target 188
10-11 17:13:50.858   111   125 E ActivityManager: ANR in com.android.vending (com.android.vending/.AssetBrowserActivity)
10-11 17:13:50.858   111   125 E ActivityManager: PID: 2933
10-11 17:13:50.858   111   125 E ActivityManager: Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 26.  Wait queue head age: 5533.4ms.)
10-11 17:13:50.858   111   125 E ActivityManager: Load: 2.04 / 1.73 / 1.65
10-11 17:13:50.858   111   125 E ActivityManager: CPU usage from 70840ms to 0ms ago (2018-10-11 17:12:39.243 to 2018-10-11 17:13:50.084):
10-11 17:13:50.858   111   125 E ActivityManager:   0.4% 111/system_server: 0.2% user + 0.1% kernel / faults: 1567 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0.3% 29/surfaceflinger: 0.1% user + 0.2% kernel / faults: 1 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0.2% 1756/com.google.android.gms.persistent: 0.1% user + 0% kernel / faults: 1020 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0.1% 358/org.anbox.appmgr: 0.1% user + 0% kernel / faults: 4 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0.1% 1857/com.google.android.gms: 0% user + 0% kernel / faults: 1315 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 55/adbd: 0% user + 0% kernel / faults: 161 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 7/logd: 0% user + 0% kernel / faults: 6 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 569/com.google.process.gapps: 0% user + 0% kernel / faults: 262 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 42/netd: 0% user + 0% kernel / faults: 95 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 26/logcat: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:   0% 27/lmkd: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:   0% 28/servicemanager: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:   0% 30/zygote64: 0% user + 0% kernel / faults: 152 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 40/media.extractor: 0% user + 0% kernel / faults: 32 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 41/mediaserver: 0% user + 0% kernel / faults: 3 minor
10-11 17:13:50.858   111   125 E ActivityManager:   0% 48/logcat: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:   0% 265/com.android.phone: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:   0% 422/android.process.media: 0% user + 0% kernel / faults: 342 minor
10-11 17:13:50.858   111   125 E ActivityManager:  +0% 2927/logcat: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager:  +0% 2933/com.android.vending: 0% user + 0% kernel
10-11 17:13:50.858   111   125 E ActivityManager: 13% TOTAL: 9% user + 2.5% kernel + 1.9% iowait + 0.2% softirq
10-11 17:13:50.858   111   125 E ActivityManager: CPU usage from 273ms to 774ms later (2018-10-11 17:13:50.356 to 2018-10-11 17:13:50.857):
10-11 17:13:50.858   111   125 E ActivityManager: 30% TOTAL: 25% user + 4.4% kernel + 0.4% softirq
10-11 17:13:50.859   111   126 W ActivityManager:   Force finishing activity com.android.vending/.AssetBrowserActivity
10-11 17:13:50.860   111   126 W ActivityManager:   Force finishing activity com.android.vending/.AssetBrowserActivity
10-11 17:13:50.860   111   126 W ActivityManager: Duplicate finish request for ActivityRecord{ae4d480 u0 com.android.vending/.AssetBrowserActivity t8 f}
10-11 17:13:50.860   111   126 I ActivityManager: Killing 2933:com.android.vending/u0a50 (adj 0): user request after error
10-11 17:13:50.905   111   144 W InputDispatcher: channel '3c2f999 com.android.vending/com.android.vending.AssetBrowserActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0xd
10-11 17:13:50.905   111   144 E InputDispatcher: channel '3c2f999 com.android.vending/com.android.vending.AssetBrowserActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
10-11 17:13:50.905   111   920 D GraphicsStats: Buffer count: 4
10-11 17:13:50.905   111  2348 I WindowManager: WIN DEATH: Window{3c2f999 u0 com.android.vending/com.android.vending.AssetBrowserActivity}
10-11 17:13:50.905   111  2348 W InputDispatcher: Attempted to unregister already unregistered input channel '3c2f999 com.android.vending/com.android.vending.AssetBrowserActivity (server)'
10-11 17:13:50.905   111   373 D ActivityManager: cleanUpApplicationRecord -- 2933
10-11 17:13:50.906   111   373 W ActivityManager: Scheduling restart of crashed service com.android.vending/com.google.android.finsky.scheduler.JobSchedulerEngine$PhoneskyJobSchedulerJobService in 1000ms
10-11 17:13:50.906  1857  1857 I MobileDataPlan: [1] MobileDataPlanApiChimeraService.onDestroy: Service is being destroyed.
10-11 17:13:50.907   111   373 I AnboxPlatformServiceProxy: Task removed id=8
castlec commented 5 years ago

Attaching output of traces.txt traces.txt

logix2 commented 5 years ago

The same thing happens for me using the latest Anbox on Ubuntu 18.10.

logix2 commented 5 years ago

It looks like this was happening because the script downloaded an old version of open-gapps. The fix is to modify it to download a newer version (modify the OPENGAPPS_RELEASEDATE value with a more recent date which you can get from here: https://github.com/opengapps/x86_64/releases/). I also updated my article on Linux Uprising with this info: https://www.linuxuprising.com/2018/07/anbox-how-to-install-google-play-store.html.

Now it works: https://i.imgur.com/H48JFiG.jpg

castlec commented 5 years ago

I have confirmed your diagnosis. How were you able to identify it?

On Thu, Nov 29, 2018 at 11:39 AM logix2 notifications@github.com wrote:

It looks like this was happening because the script downloaded an old version of open-gapps. The fix is to modify it to download a newer version (modify the OPENGAPPS_RELEASEDATE value with a more recent date which you can get from here: https://github.com/opengapps/x86_64/releases/). I also updated my article on Linux Uprising with this info: https://www.linuxuprising.com/2018/07/anbox-how-to-install-google-play-store.html .

Now it works: https://i.imgur.com/H48JFiG.jpg

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/geeks-r-us/anbox-playstore-installer/issues/12#issuecomment-442903515, or mute the thread https://github.com/notifications/unsubscribe-auth/AAfFC9ZABa2oXtGOk08LlZhEtf5D0PYaks5u0A20gaJpZM4W0LTu .

geeks-r-us commented 5 years ago

fixed with d384d60 whicht updates to newest gapps