appium / appium-espresso-driver

Espresso integration for Appium
Apache License 2.0
194 stars 75 forks source link

Server crash with OOM #340

Closed rajdeepv closed 5 years ago

rajdeepv commented 5 years ago

While trying Espresso on one of our app, on a screens which have a lot of elements in the hierarchy, finding by XPath brings down Espresso server with Out Of Memory. The Xpath was {:xpath=>"//*[@text='Loading...']"}.

Same thing happens when I try to get page source on that screen

--------- beginning of crash
12-11 16:36:04.147 28992 29515 E AndroidRuntime: FATAL EXCEPTION: NanoHttpd Request Processor (#20)
12-11 16:36:04.147 28992 29515 E AndroidRuntime: Process: com.bumble.app, PID: 28992
12-11 16:36:04.147 28992 29515 E AndroidRuntime: java.lang.OutOfMemoryError: Failed to allocate a 268501000 byte allocation with 6291456 free bytes and 179MB until OOM, max allowed footprint 153800280, growth limit 335544320
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.util.Arrays.copyOf(Arrays.java:3260)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:125)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:605)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.lang.StringBuffer.append(StringBuffer.java:367)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.io.StringWriter.write(StringWriter.java:94)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.flushBuffer(KXmlSerializer.java:80)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.append(KXmlSerializer.java:53)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.attribute(KXmlSerializer.java:496)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:172)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:179)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.toXMLString(SourceDocument.java:197)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.findViewsByXPath(SourceDocument.java:212)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.viewmatcher.WithXPath.withXPath(WithXPath.java:35)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.viewmatcher.WithXPath.withXPath(WithXPath.java:57)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.helpers.ViewFinder.findAllBy(ViewFinder.java:180)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.helpers.ViewFinder.findAllBy(ViewFinder.java:113)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.handlers.FindElements.handle(FindElements.java:48)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.handlers.FindElements.handle(FindElements.java:33)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.http.Router.route(Router.java:296)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at io.appium.espressoserver.lib.http.Server.serve(Server.java:68)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192)
12-11 16:36:04.147 28992 29515 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:764)
12-11 16:36:04.188  1373  1373 E SELinux : avc:  denied  { find } for interface=android.hardware.memtrack::IMemtrack pid=28992 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:hal_memtrack_hwservice:s0 tclass=hwservice_manager
12-11 16:36:04.188 28992 29515 E memtrack: Couldn't load memtrack module
12-11 16:36:04.189 28992 29515 W android.os.Debug: failed to get memory consumption info: -1
12-11 16:36:04.197 28992 29515 I Process : Sending signal. PID: 28992 SIG: 9
12-11 16:36:04.326  1700 12120 I WindowManager: WIN DEATH: Window{3882189 u0 com.bumble.app/com.bumble.app.ui.main.AppMainActivity}
12-11 16:36:04.328  1700 13524 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ LISTEN id=39, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&FOREGROUND] ], android.os.BinderProxy@56111c6)
12-11 16:36:04.328  1700  5090 I ActivityManager: Process com.bumble.app (pid 28992) has died: fore TOP
12-11 16:36:04.332  1700  5090 W ActivityManager: Force removing ActivityRecord{2eac9c7 u0 com.bumble.app/.ui.main.AppMainActivity t317}: app died, no saved state
12-11 16:36:04.334 29043 29043 I cr_ChildProcessService: Destroying ChildProcessService pid=29043
12-11 16:36:04.339 29043 29043 I /system/bin/webview_zygote32: System.exit called, status: 0
12-11 16:36:04.339 29043 29043 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
12-11 16:36:04.339  1700  1788 E ConnectivityService: RemoteException caught trying to send a callback msg for NetworkRequest [ LISTEN id=39, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&FOREGROUND] ]
12-11 16:36:04.352  1700  5090 W ActivityManager: Crash of app com.bumble.app running instrumentation ComponentInfo{io.appium.espressoserver.test/androidx.test.runner.AndroidJUnitRunner}
dpgraham commented 5 years ago

I'll look at this today. There's probably some work we can do to reduce the memory usage of the XML serializer.

mykola-mokhnach commented 5 years ago

@dpgraham I think the problem there is the same as it was for UIA2. We should simply limit the maximum depth of views hierarchy traversal. I'll prepare a hot fix soon

dpgraham commented 5 years ago

Sure. I've already started writing a test for this to reproduce it (using Robolectric) so once you get in the fix I can test it.

mykola-mokhnach commented 5 years ago

@rajdeepv Can you please test https://github.com/appium/appium-espresso-driver/pull/341 with your app?

rajdeepv commented 5 years ago

@mykola-mokhnach checked it, still same issue. I put a watch on depth and noticed that depth was never more than 11 in my case and therefore never got the warning log in the logcat about it.

mykola-mokhnach commented 5 years ago

@rajdeepv There might be multiple causes. Can you please attach the stacktrace you get with this PR being merged?

rajdeepv commented 5 years ago

@mykola-mokhnach below is stacktrace. It takes some time before this exception is thrown. I tried to see serialized XML, there seems to be sort of periodic repetition of views. I am attaching partial XML copied from the debugger window view_tree.txt

12-11 19:34:34.451 15096 15636 D appium  : Started processing GET request for '/session/bf03e9f9-61d0-472f-8454-cd0f8428a20d/source'
12-11 19:34:34.454 15096 15636 D appium  : Matched route definition: class io.appium.espressoserver.lib.http.RouteDefinition
12-11 19:34:34.458 15096 15636 D appium  : Matched route handler: class io.appium.espressoserver.lib.handlers.Source
12-11 19:34:34.478 15096 15636 D InputManagerEventInjectionStrategy: Creating injection strategy with input manager.
12-11 19:34:34.494 15096 15096 I ViewInteraction: Performing 'getting view in application' action on view is a root view.
12-11 19:34:34.587  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:34.617  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 2 lines
12-11 19:34:34.619  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:34.628  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:34.632  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:34.658  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 2 lines
12-11 19:34:34.660  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:34.666  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:35.294 15096 15107 I zygote64: Background concurrent copying GC freed 181290(5MB) AllocSpace objects, 1(1028KB) LOS objects, 27% free, 15MB/21MB, paused 12.551ms total 107.619ms
12-11 19:34:38.257  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:38.257  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:34:38.338  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:38.338  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:34:39.606  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:39.655  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:34:39.670  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:39.675  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:39.685  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:39.729  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:34:39.734  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:39.752  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:40.018 15096 15107 I zygote64: Background concurrent copying GC freed 241035(6MB) AllocSpace objects, 1(16MB) LOS objects, 11% free, 46MB/52MB, paused 8.228ms total 48.574ms
12-11 19:34:44.585  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:44.638  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:34:44.643  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:44.648  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:44.653  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:44.682  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:34:44.684  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:44.692  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:44.864 15096 15107 I zygote64: Background concurrent copying GC freed 150811(4MB) AllocSpace objects, 1(32MB) LOS objects, 7% free, 77MB/83MB, paused 15.219ms total 51.819ms
12-11 19:34:48.196  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:48.196  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:34:49.578  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:49.632  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:34:49.640  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:49.643 15096 15107 I zygote64: Background concurrent copying GC freed 269571(7MB) AllocSpace objects, 0(0B) LOS objects, 7% free, 78MB/84MB, paused 457us total 101.483ms
12-11 19:34:49.650  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:49.678  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:49.702  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:49.714  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:49.727  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:53.922 15096 15107 I zygote64: Background concurrent copying GC freed 258377(7MB) AllocSpace objects, 1(64MB) LOS objects, 4% free, 142MB/148MB, paused 28.990ms total 72.584ms
12-11 19:34:54.604  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:54.633  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:34:54.662  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:54.669  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:54.679  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:54.728  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:34:54.730  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:54.739  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:54.782 15096 15107 I zygote64: Background concurrent copying GC freed 272858(7MB) AllocSpace objects, 0(0B) LOS objects, 4% free, 142MB/148MB, paused 2.038ms total 121.278ms
12-11 19:34:59.563  1434  1461 D hwcomposer: hw_composer sent 105 syncs in 60s
12-11 19:34:59.612  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:59.670  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:34:59.675  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:59.685  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:59.686  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:59.725  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:34:59.737  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:34:59.739  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:34:59.745 15096 15107 I zygote64: Background concurrent copying GC freed 253849(7MB) AllocSpace objects, 0(0B) LOS objects, 4% free, 143MB/149MB, paused 362us total 188.952ms
12-11 19:34:59.769  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:59.769  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:34:59.793  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:59.795  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:34:59.821  1700  1716 E memtrack: Couldn't load memtrack module
12-11 19:34:59.821  1700  1716 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:35:00.033  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.072  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:35:00.084  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.093  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:00.095  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.140  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 2 lines
12-11 19:35:00.154  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.167  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:00.173  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.210  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:35:00.213  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:00.221  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:04.585  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.635  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 2 lines
12-11 19:35:04.637  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.643  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:04.648  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.654  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.659 15096 15107 I zygote64: Background concurrent copying GC freed 276502(7MB) AllocSpace objects, 0(0B) LOS objects, 4% free, 142MB/148MB, paused 353us total 108.978ms
12-11 19:35:04.693  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.703  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:04.715  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:05.751  1441  1441 I boot-pipe: done populating /dev/random
12-11 19:35:09.594  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:09.661  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 4 lines
12-11 19:35:09.678  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:09.680  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:09.706  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:09.712  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:09.722  1443  1525 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:12.728 15096 15636 I zygote64: Waiting for a blocking GC Alloc
12-11 19:35:12.772 15096 15636 I zygote64: WaitForGcToComplete blocked for 43.853ms for cause Alloc
12-11 19:35:12.772 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.772 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.821 15096 15636 I zygote64: Alloc concurrent copying GC freed 13694(433KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 140MB/146MB, paused 2.556ms total 49.092ms
12-11 19:35:12.821 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.862 15096 15636 I zygote64: Alloc concurrent copying GC freed 27714(881KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 139MB/145MB, paused 2.569ms total 40.881ms
12-11 19:35:12.862 15096 15636 I zygote64: Forcing collection of SoftReferences for 256MB allocation
12-11 19:35:12.863 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.920 15096 15636 I zygote64: Alloc concurrent copying GC freed 25581(1037KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 138MB/144MB, paused 3.248ms total 57.547ms
12-11 19:35:12.921 15096 15636 W zygote64: Throwing OutOfMemoryError "Failed to allocate a 268501000 byte allocation with 6291456 free bytes and 181MB until OOM, max allowed footprint 151777040, growth limit 335544320"
12-11 19:35:12.921 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.921 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.960 15096 15636 I zygote64: Alloc concurrent copying GC freed 4(16KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 138MB/144MB, paused 2.791ms total 39.148ms
12-11 19:35:12.960 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:12.998 15096 15636 I zygote64: Alloc concurrent copying GC freed 14(16KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 138MB/144MB, paused 2.078ms total 37.060ms
12-11 19:35:12.998 15096 15636 I zygote64: Forcing collection of SoftReferences for 256MB allocation
12-11 19:35:12.998 15096 15636 I zygote64: Starting a blocking GC Alloc
12-11 19:35:13.055 15096 15636 I zygote64: Alloc concurrent copying GC freed 40(17KB) AllocSpace objects, 0(0B) LOS objects, 4% free, 138MB/144MB, paused 2.962ms total 57.084ms
12-11 19:35:13.055 15096 15636 W zygote64: Throwing OutOfMemoryError "Failed to allocate a 268501000 byte allocation with 6291456 free bytes and 181MB until OOM, max allowed footprint 151775608, growth limit 335544320"
--------- beginning of crash
12-11 19:35:13.058 15096 15636 E AndroidRuntime: FATAL EXCEPTION: NanoHttpd Request Processor (#9)
12-11 19:35:13.058 15096 15636 E AndroidRuntime: Process: com.bumble.app, PID: 15096
12-11 19:35:13.058 15096 15636 E AndroidRuntime: java.lang.OutOfMemoryError: Failed to allocate a 268501000 byte allocation with 6291456 free bytes and 181MB until OOM, max allowed footprint 151775608, growth limit 335544320
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.util.Arrays.copyOf(Arrays.java:3260)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:125)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:605)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.lang.StringBuffer.append(StringBuffer.java:367)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.io.StringWriter.write(StringWriter.java:94)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.flushBuffer(KXmlSerializer.java:80)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.append(KXmlSerializer.java:53)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.writeEscaped(KXmlSerializer.java:165)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at org.kxml2.io.KXmlSerializer.attribute(KXmlSerializer.java:495)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.setAttribute(SourceDocument.java:85)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:152)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:186)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:186)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:186)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:186)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.serializeView(SourceDocument.java:186)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.model.SourceDocument.toXMLString(SourceDocument.java:208)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.handlers.Source.handle(Source.java:30)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.handlers.Source.handle(Source.java:25)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.http.Router.route(Router.java:299)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at io.appium.espressoserver.lib.http.Server.serve(Server.java:68)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at fi.iki.elonen.NanoHTTPD$HTTPSession.execute(NanoHTTPD.java:945)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at fi.iki.elonen.NanoHTTPD$ClientHandler.run(NanoHTTPD.java:192)
12-11 19:35:13.058 15096 15636 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:764)
12-11 19:35:13.133  1373  1373 E SELinux : avc:  denied  { find } for interface=android.hardware.memtrack::IMemtrack pid=15096 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:hal_memtrack_hwservice:s0 tclass=hwservice_manager
12-11 19:35:13.134 15096 15636 E memtrack: Couldn't load memtrack module
12-11 19:35:13.134 15096 15636 W android.os.Debug: failed to get memory consumption info: -1
12-11 19:35:13.185 15096 15636 I Process : Sending signal. PID: 15096 SIG: 9
12-11 19:35:13.299  1700 15214 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ LISTEN id=51, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&FOREGROUND] ], android.os.BinderProxy@53733dc)
12-11 19:35:13.300  1700 13524 I ActivityManager: Process com.bumble.app (pid 15096) has died: fore TOP
12-11 19:35:13.302  1700 13524 W ActivityManager: Force removing ActivityRecord{b727cfa u0 com.bumble.app/.ui.main.AppMainActivity t354}: app died, no saved state
12-11 19:35:13.302  1700  3643 I WindowManager: WIN DEATH: Window{91e7c9b u0 com.bumble.app/com.bumble.app.ui.main.AppMainActivity}
12-11 19:35:13.303 15154 15154 I cr_ChildProcessService: Destroying ChildProcessService pid=15154
12-11 19:35:13.334 15154 15154 I /system/bin/webview_zygote32: System.exit called, status: 0
12-11 19:35:13.337  1700  1788 E ConnectivityService: RemoteException caught trying to send a callback msg for NetworkRequest [ LISTEN id=51, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&FOREGROUND] ]
12-11 19:35:13.337 15154 15154 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
12-11 19:35:13.363  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.382  1700 13524 W ActivityManager: Crash of app com.bumble.app running instrumentation ComponentInfo{io.appium.espressoserver.test/androidx.test.runner.AndroidJUnitRunner}
12-11 19:35:13.389  1700 13524 I ActivityManager: Force stopping com.bumble.app appid=10198 user=0: finished inst
12-11 19:35:13.390  1700 15705 W Binder  : Outgoing transactions from this process must be FLAG_ONEWAY
12-11 19:35:13.390  1700 15705 W Binder  : java.lang.Throwable
12-11 19:35:13.390  1700 15705 W Binder  :  at android.os.BinderProxy.transact(Binder.java:736)
12-11 19:35:13.390  1700 15705 W Binder  :  at android.app.IInstrumentationWatcher$Stub$Proxy.instrumentationFinished(IInstrumentationWatcher.java:160)
12-11 19:35:13.390  1700 15705 W Binder  :  at com.android.server.am.InstrumentationReporter$MyThread.run(InstrumentationReporter.java:86)
12-11 19:35:13.406  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.406 15085 15085 D AndroidRuntime: Shutting down VM
12-11 19:35:13.412  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.438  1700 13524 I ActivityManager: Killing 15154:com.android.chrome:sandboxed_process0/u0a198i37 (adj 0): isolated not needed
12-11 19:35:13.439  1700  1719 W zygote64: failed to open /acct/uid_99037/pid_15154/cgroup.procs: No such file or directory
12-11 19:35:13.524  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.524  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.532  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.544  1700  2006 W zygote64: Long monitor contention with owner Binder:1700_1B (13524) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1642) waiters=0 in void com.android.server.am.ActivityManagerService.serviceDoneExecuting(android.os.IBinder, int, int, int) for 239ms
12-11 19:35:13.566  1700  1720 E KernelCpuSpeedReader: Failed to read cpu-freq: /sys/devices/system/cpu/cpu0/cpufreq/stats/time_in_state (No such file or directory)
12-11 19:35:13.571  1700 17251 W zygote64: Long monitor contention with owner Binder:1700_1B (13524) at void com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied()(ActivityManagerService.java:1642) waiters=2 in android.content.IIntentSender com.android.server.am.ActivityManagerService.getIntentSender(int, java.lang.String, android.os.IBinder, java.lang.String, int, android.content.Intent[], java.lang.String[], int, android.os.Bundle, int) for 226ms
12-11 19:35:13.572  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.599  1700  1717 W ActivityManager: Error shutting down UiAutomationConnection
12-11 19:35:13.603  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.610  2316  2814 D EGL_emulation: eglMakeCurrent: 0xdee4b6a0: ver 3 0 (tinfo 0xdee7e9c0)
12-11 19:35:13.612  1700  1724 W ActivityManager: setHasOverlayUi called on unknown pid: 15096
12-11 19:35:13.634  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.692  1700  1718 W Looper  : Dispatch took 354ms on android.ui, h=Handler (com.android.server.am.ActivityManagerService$UiHandler) {58931d5} cb=null msg=53
12-11 19:35:13.703  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:35:13.760  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.767  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:13.768  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.774  1443  1443 D SurfaceFlinger: duplicate layer name: changing com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity to com.google.android.apps.nexuslauncher/com.google.android.apps.nexuslauncher.NexusLauncherActivity#1
12-11 19:35:13.783  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.798  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.798  1443  1470 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:13.810  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.832  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.915  1443  1474 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:13.920  1433  1433 E hw-IPCThreadState: binder thread pool (1 threads) starved for 110 ms
12-11 19:35:13.920  1433  1433 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 2289664
12-11 19:35:13.952  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:13.978  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 2 lines
12-11 19:35:14.013  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.021  2316  2316 W SessionLifecycleManager: Handover failed. Creating new session controller.
12-11 19:35:14.025  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.026  2316  2316 I OptInState: There is a new client and it does not support opt-in. Dropping request.
12-11 19:35:14.029  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.036  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.043  4796  4834 D EGL_emulation: eglMakeCurrent: 0x799c10a424a0: ver 3 0 (tinfo 0x799c04cc68c0)
12-11 19:35:14.127  1443  1729 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.132  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.140  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.176  2316 14843 W LocationOracle: No location history returned by ContextManager
12-11 19:35:14.192  2316  2316 I MicroDetectionWorker: #updateMicroDetector [detectionMode: [mDetectionMode: [1]]]
12-11 19:35:14.192  2316  2316 I MicroDetectionWorker: #startMicroDetector [speakerMode: 0]
12-11 19:35:14.192  2316  2316 I AudioController: Using mInputStreamFactoryBuilder
12-11 19:35:14.205  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.207  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.209  2316  2316 I MicroDetectionWorker: onReady
12-11 19:35:14.211  2316 14843 I MicroRecognitionRunner: Starting detection.
12-11 19:35:14.212  2316 15246 I MicrophoneInputStream: mic_starting com.google.android.apps.gsa.staticplugins.aa.c@b57bea4
12-11 19:35:14.277  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.277  1534 15728 I AudioFlinger: AudioFlinger's thread 0xe4683980 tid=15728 ready to run
12-11 19:35:14.312  1534  8631 E AudioFlinger: not enough memory for AudioTrack size=131296
12-11 19:35:14.312  1534  8631 D MemoryDealer:   AudioTrack (0xe8c192d0, size=4194304)
12-11 19:35:14.312  1534  8631 D MemoryDealer:     0: 0xe8c192e0 | 0x00000000 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     1: 0xe8c19300 | 0x000200E0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     2: 0xe8c19480 | 0x000401C0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     3: 0xe87fc2c0 | 0x000602A0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     4: 0xe87fc340 | 0x00080380 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     5: 0xe87fc770 | 0x000A0460 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     6: 0xe87fca40 | 0x000C0540 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     7: 0xe87fcbf0 | 0x000E0620 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     8: 0xe87fcd80 | 0x00100700 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:     9: 0xe87fcf00 | 0x001207E0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    10: 0xe6e6c090 | 0x001408C0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    11: 0xe6e6c270 | 0x001609A0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    12: 0xe6e6c3d0 | 0x00180A80 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    13: 0xe6e6c5f0 | 0x001A0B60 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    14: 0xe6e6c740 | 0x001C0C40 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    15: 0xe6e6c8e0 | 0x001E0D20 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    16: 0xe8c19640 | 0x00200E00 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    17: 0xe6e6cc00 | 0x00220EE0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    18: 0xe8c19ac0 | 0x00240FC0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:    19: 0xe8c19c50 | 0x002610A0 | 0x000200E0 | A
12-11 19:35:14.312  1534  8631 D MemoryDealer:
12-11 19:35:14.312  1534  8631 E AudioFlinger: createRecordTrack_l() initCheck failed -12; no control block?
12-11 19:35:14.313  2316 15246 E AudioRecord: AudioFlinger could not create record track, status: -12
12-11 19:35:14.323  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.327  2316 15246 E AudioRecord-JNI: Error creating AudioRecord instance: initialization check failed with status -12.
12-11 19:35:14.327  2316 15246 E android.media.AudioRecord: Error code -20 when initializing native AudioRecord object.
12-11 19:35:14.327  2316 15246 I MicrophoneInputStream: mic_started com.google.android.apps.gsa.staticplugins.aa.c@b57bea4
12-11 19:35:14.329  1443  1729 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.331  2316 15246 E ActivityThread: Failed to find provider info for com.google.android.apps.gsa.testing.ui.audio.recorded
12-11 19:35:14.339  2316 15246 I MicrophoneInputStream: mic_close com.google.android.apps.gsa.staticplugins.aa.c@b57bea4
12-11 19:35:14.343  2316 14843 I MicroRecognitionRunner: Detection finished
12-11 19:35:14.344  2316 14843 W ErrorReporter: reportError [type: 211, code: 524300]: Error reading from input stream
12-11 19:35:14.348  2316  2903 I MicroRecognitionRunner: Stopping hotword detection.
12-11 19:35:14.350  2316 14843 W ErrorProcessor: onFatalError, processing error from engine(4)
12-11 19:35:14.350  2316 14843 W ErrorProcessor: com.google.android.apps.gsa.shared.speech.b.g: Error reading from input stream
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.staticplugins.recognizer.j.a.a(SourceFile:28)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.staticplugins.recognizer.j.b.run(SourceFile:15)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.shared.util.concurrent.a.ax.run(SourceFile:14)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.shared.util.concurrent.a.bl.run(SourceFile:4)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.shared.util.concurrent.a.bl.run(SourceFile:4)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.lang.Thread.run(Thread.java:764)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.shared.util.concurrent.a.ai.run(SourceFile:6)
12-11 19:35:14.350  2316 14843 W ErrorProcessor: Caused by: com.google.android.apps.gsa.shared.exception.GsaIOException: Error code: 393238 | Buffer overflow, no available space.
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.speech.audio.Tee.f(SourceFile:103)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.speech.audio.au.read(SourceFile:2)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at java.io.InputStream.read(InputStream.java:101)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.speech.audio.ao.run(SourceFile:18)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    at com.google.android.apps.gsa.speech.audio.an.run(SourceFile:2)
12-11 19:35:14.350  2316 14843 W ErrorProcessor:    ... 9 more
12-11 19:35:14.351  2316 14843 I AudioController: internalShutdown
12-11 19:35:14.368  2316  2316 I MicroDetectionWorker: onReady
12-11 19:35:14.369  2316  2316 I MicroDetector: Keeping mic open: false
12-11 19:35:14.369  2316 14844 I DeviceStateChecker: DeviceStateChecker cancelled
12-11 19:35:14.369  2316  2316 I MicroDetectionWorker: #onError(false)
12-11 19:35:14.440  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.445  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:35:14.453  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.458  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.470  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.525  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:35:14.538  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.548  4796  4834 W OpenGLRenderer: Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer...
12-11 19:35:14.553  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.571  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.645  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 3 lines
12-11 19:35:14.652  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.659  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.668  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.713  1443  1443 I chatty  : uid=1000(system) /system/bin/surfaceflinger identical 1 line
12-11 19:35:14.718  1443  1443 D EGL_emulation: eglMakeCurrent: 0x79557f647280: ver 3 0 (tinfo 0x79557f62e840)
12-11 19:35:14.750  1443  2034 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
12-11 19:35:14.756  2268  2268 I GeofencerStateMachine: removeGeofences: removeRequest=RemoveGeofencingRequest[REMOVE_BY_PENDING_INTENT pendingIntent=PendingIntent[creatorPackage=com.google.android.gms], packageName=null]
12-11 19:35:14.805  2268  2268 I GeofencerStateMachine: removeGeofences: removeRequest=RemoveGeofencingRequest[REMOVE_BY_PENDING_INTENT pendingIntent=PendingIntent[creatorPackage=com.google.android.gms], packageName=null]
12-11 19:35:14.845  2268 15735 I PlaceInferenceEngine: [anon] Changed inference mode: 0
12-11 19:35:14.914  2268 15735 I Places  : ?: PlacesBleScanner start() with priority 2
12-11 19:35:14.915  2268 15735 I PlaceInferenceEngine: [anon] Changed inference mode: 1
12-11 19:35:14.970  2268 15735 I Places  : Converted 0 out of 0 WiFi scans
12-11 19:35:14.983  2268  2268 E BeaconBle: Missing BluetoothAdapter
12-11 19:35:14.983  2268  2268 I BeaconBle: BLE 'KK+' software access layer enabled
12-11 19:35:15.047  2268  2268 I BeaconBle: Client requested scan, settings=BleSettings [scanMode=ZERO_POWER, callbackType=ALL_MATCHES, reportDelayMillis=0, 1 filters, 0 clients, callingClientName=Places]
12-11 19:35:15.050  2268  2268 I BeaconBle: Scan : No clients left, canceling alarm.
12-11 19:35:15.051  2268  2268 E BeaconBle: Scan couldn't start for Places
12-11 19:35:15.051  2268  2268 W Places  : BLE failure while scanning - code 5
12-11 19:35:15.059  2268  9902 I PlaceInferenceEngine: No beacon scan available - ignoring candidates.
12-11 19:35:15.143  2268  2279 I zygote64: Background concurrent copying GC freed 91090(5MB) AllocSpace objects, 11(808KB) LOS objects, 36% free, 10MB/16MB, paused 1.676ms total 219.246ms
12-11 19:35:15.162  2268  9902 W ctxmgr  : [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):PlacesProducer, vrsn=12521000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2268). Was: 3 for 18, account#-517948760#
mykola-mokhnach commented 5 years ago

Perhaps the generated XML is really big. What if you add android:largeHeap to the espresso manifest?

mykola-mokhnach commented 5 years ago

I'll try to rewrite xml generator, so it does not cache xml output in memory, but on file system

mykola-mokhnach commented 5 years ago

Please try https://github.com/appium/appium-espresso-driver/pull/344

rajdeepv commented 5 years ago

I will try it on my app tomorrow in the office. But just tried with a small app with two nested views as below:

<?xml version="1.0" encoding="utf-8"?>
<RelativeLayout xmlns:android="http://schemas.android.com/apk/res/android"
    xmlns:tools="http://schemas.android.com/tools"
    android:id="@+id/activity_receive_message"
    android:layout_width="match_parent"
    android:layout_height="match_parent"
    android:paddingBottom="@dimen/activity_vertical_margin"
    android:paddingLeft="@dimen/activity_horizontal_margin"
    android:paddingRight="@dimen/activity_horizontal_margin"
    android:paddingTop="@dimen/activity_vertical_margin"
    tools:context="com.hfad.messanger.ReceiveMessageActivity">

    <LinearLayout
        android:id="@+id/foo"
        android:layout_width="297dp"
        android:layout_height="253dp"
        android:layout_alignParentTop="true"
        android:layout_centerHorizontal="true"
        android:layout_marginTop="31dp"
        android:orientation="vertical">

        <FrameLayout
            android:id="@+id/bar"
            android:layout_width="match_parent"
            android:layout_height="match_parent">

        </FrameLayout>
    </LinearLayout>

</RelativeLayout>

On doing @driver.page I get source XML which has view nodes with id foo and bar repeated multiple times. There seems to be some strange thing going on with recursion which is resulting in repeated serialization of the same view again and again and making XML unusually long. This is probably the reason why it is taking too much memory and almost 30 seconds in parsing (before failing with OOM) with my app. Just to prove this hypothesis, I tried a hack by making sure view is serialized only once, which worked.

if (depth < MAX_TRAVERSE_DEPTH) {
            // Visit the children and build them too
            for (View childView : breadthFirstViewTraversal(view)) {
                if (!view.equals(childView) && !serializedViews.contains(childView)) {
                    serializedViews.add(childView);
                    serializeView(childView, depth + 1);
                }
            }
        }
rajdeepv commented 5 years ago

@mykola-mokhnach, just tried my app with #344 . This time the serialization was just endless. I waited for 3 minutes before cancelling it However, with the hack I mentioned above, it worked on my app and the serialization took only 148ms.

mykola-mokhnach commented 5 years ago

Thanks for the hint. There is maybe an issue in the traversal algorithm from androidx package. I have reverted to the previous implementation, which should work properly though.

rajdeepv commented 5 years ago

@mykola-mokhnach It is working fine with the latest changes in #344. Thanks

mykola-mokhnach commented 5 years ago

Published the fix in 1.5.0