Closed
Bug 975155
Opened 11 years ago
Closed 9 years ago
Frequent Android 2.3 testFindInPage | Automation Error: Missing end of test marker (process crashed?)
Categories
(Firefox for Android Graveyard :: Testing, defect, P5)
Tracking
(fennec+)
RESOLVED
WONTFIX
Tracking | Status | |
---|---|---|
fennec | + | --- |
People
(Reporter: gbrown, Assigned: snorp)
References
Details
Robocop's testFindInPage usually fails on the Android 2.3 emulator. The test ends suddenly, leaving no crash dump.
https://tbpl.mozilla.org/php/getParsedLog.php?id=34518484&tree=Ash&full=1#error17
16:00:20 INFO - 1 INFO TEST-START | testFindInPage
16:00:20 INFO - 2 INFO TEST-PASS | testFindInPage | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
16:00:20 INFO - EventExpecter: no longer listening for Gecko:Ready
16:00:20 INFO - 3 INFO TEST-PASS | testFindInPage | waiting for urlbar text to gain focus - urlbar text gained focus
16:00:20 INFO - 4 INFO TEST-PASS | testFindInPage | URL typed properly - http://mochi.test:8888/tests/robocop/robocop_text_page.html should equal http://mochi.test:8888/tests/robocop/robocop_text_page.html
16:00:20 INFO - 5 INFO TEST-PASS | testFindInPage | Given message occurred for registered event: {"errorType":"","bgColor":"transparent","type":"DOMContentLoaded","tabID":0} - DOMContentLoaded should equal DOMContentLoaded
16:00:20 INFO - EventExpecter: no longer listening for DOMContentLoaded
16:00:20 INFO - PaintExpecter: no longer listening for events
16:00:20 INFO - waitForText timeout on ^Find in Page$
16:00:20 INFO - 6 INFO TEST-PASS | testFindInPage | Looking for the next search match button in the Find in Page UI - Found the next match button
16:00:20 INFO - INFO | automation.py | Application ran for: 0:02:59.888737
16:00:20 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpLlyMgjpidlog
16:00:20 INFO - /data/anr/traces.txt not found
16:00:20 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected!
16:00:20 INFO - runtests.py | Running tests: end.
16:00:20 INFO - Mochi-Remote ERROR | Automation Error: Missing end of test marker (process crashed?)
Logcat provides some explanation:
16:00:20 INFO - 02-11 15:48:08.422 I/Robocop ( 2517): 6 INFO TEST-PASS | testFindInPage | Looking for the next search match button in the Find in Page UI - Found the next match button
...all is well so far. "Find in Page" has just been selected, and Robocop can see views in the Find in Page dialog.
16:00:20 INFO - 02-11 15:48:08.883 W/GeckoGLController( 2517): GLController::serverSurfaceChanged(1024, 695)
16:00:20 INFO - 02-11 15:48:08.883 D/GeckoLayerClient( 2517): Window-size changed to (1024,695)
16:00:20 INFO - 02-11 15:48:08.883 W/GeckoGLController( 2517): GLController::resumeCompositor(1024, 695) and mCompositorCreated=true
16:00:20 INFO - 02-11 15:48:09.581 W/GeckoGLController( 2517): done GLController::resumeCompositor
16:00:20 INFO - 02-11 15:48:09.583 W/GeckoGLController( 2517): GLController::serverSurfaceChanged(1024, 695)
We see the window size has been adjusted for "Find in Page", and now things go downhilll...
16:00:20 INFO - 02-11 15:48:09.634 D/Robocop ( 2517): Received drawFinished notification
16:00:20 INFO - 02-11 15:48:10.052 I/InputQueue-JNI( 2517): Sending finished signal for input channel '406219f0 AtchDlg:org.mozilla.fennec/org.mozilla.fennec.App (client)' since it is being unregistered while an input message is still in progress.
16:00:20 INFO - 02-11 15:48:10.182 W/GeckoGLController( 2517): GLController::updateCompositor with mCompositorCreated=true
16:00:20 INFO - 02-11 15:48:10.182 W/GeckoGLController( 2517): GLController::resumeCompositor(1024, 695) and mCompositorCreated=true
16:00:20 INFO - 02-11 15:48:10.610 D/Robocop ( 2517): Received drawFinished notification
16:00:20 INFO - 02-11 15:48:12.012 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:15.227 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:16.222 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:19.232 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:21.233 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:22.232 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:23.246 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:27.242 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:29.283 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:30.292 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:31.297 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:35.297 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:39.298 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:40.113 W/WindowManager( 65): Input event injection timed out.
16:00:20 INFO - 02-11 15:48:43.296 W/SharedBufferStack( 2517): waitForCondition(LockCondition) timed out (identity=114, status=0). CPU may be pegged. trying again.
16:00:20 INFO - 02-11 15:48:45.122 I/InputDispatcher( 65): Application is not responding: AppWindowToken{40821170 token=HistoryRecord{406224b0 org.mozilla.fennec/.App}} - Window{4072f098 org.mozilla.fennec/org.mozilla.fennec.App paused=false}. 36183.4ms since event, 5000.6ms since wait started
16:00:20 INFO - 02-11 15:48:45.122 I/WindowManager( 65): Input event dispatching timed out sending to org.mozilla.fennec/org.mozilla.fennec.App
16:00:20 INFO - 02-11 15:48:45.132 D/AndroidRuntime( 2508): Shutting down VM
16:00:20 INFO - 02-11 15:48:45.161 I/ActivityManager( 65): Force stopping package org.mozilla.fennec uid=10017
16:00:20 INFO - 02-11 15:48:45.162 I/Process ( 65): Sending signal. PID: 2563 SIG: 9
16:00:20 INFO - 02-11 15:48:45.225 I/Process ( 65): Sending signal. PID: 2517 SIG: 9
16:00:20 INFO - 02-11 15:48:45.242 I/AndroidRuntime( 2508): NOTE: attach of thread 'Binder Thread #3' failed
16:00:20 INFO - 02-11 15:48:45.384 D/jdwp ( 2508): adbd disconnected
16:00:20 INFO - 02-11 15:48:45.513 W/WindowManager( 65): Input event injection timed out.
16:00:20 INFO - 02-11 15:48:46.194 W/WindowManager( 65): Rebuild removed 4 windows but added 2
16:00:20 INFO - 02-11 15:48:46.478 E/InputDispatcher( 65): channel '4072f098 org.mozilla.fennec/org.mozilla.fennec.App (server)' ~ Consumer closed input channel or an error occurred. events=0x8
16:00:20 INFO - 02-11 15:48:46.478 E/InputDispatcher( 65): channel '4072f098 org.mozilla.fennec/org.mozilla.fennec.App (server)' ~ Channel is unrecoverably broken and will be disposed!
16:00:20 INFO - 02-11 15:48:46.595 I/WindowManager( 65): WIN DEATH: Window{4072f098 org.mozilla.fennec/org.mozilla.fennec.App paused=false}
16:00:20 INFO - 02-11 15:48:46.636 I/WindowManager( 65): WIN DEATH: Window{4073bc20 SurfaceView paused=false}
I have reproduced "CPU may be pegged" locally on an emulator with the same AVD/images, even with a much-simplified test -- it seems to happen as soon as Robocop brings up the Find in Page dialog.
These seem relevant, but I don't see a known solution:
http://stackoverflow.com/questions/10199231/android-freeze-in-opengles-cpu-may-be-pegged-trying-again
http://stackoverflow.com/questions/8458404/android-cpu-may-be-pegged-bug
Reporter | ||
Comment 2•11 years ago
|
||
I reproduced this problem locally on an emulator with the same AVD, without Robocop or any test infra -- just opened Fennec, opened a page, selected MENU > More > Find in Page -- Fennec became unresponsive within 5 seconds.
I cannot reproduce on any of my devices.
Reporter | ||
Updated•11 years ago
|
Assignee: nobody → snorp
Flags: needinfo?(snorp)
Reporter | ||
Comment 3•11 years ago
|
||
Disabled on Android 2.3 only: https://hg.mozilla.org/integration/mozilla-inbound/rev/011b9055dfec
Whiteboard: [leave open] [test disabled on Android 2.3]
Comment 4•11 years ago
|
||
Assignee | ||
Comment 5•11 years ago
|
||
Looks like we frequently get stuck in eglSwapBuffers(), presumably when the surface gets resized/recreated.
#0 0xafd0c738 in __futex_syscall3 () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libc.so
#1 0xafd11374 in __pthread_cond_timedwait_relative () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libc.so
#2 0xac7116b6 in android::SharedBufferBase::waitForCondition(android::SharedBufferBase::ConditionBase const&) ()
from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libsurfaceflinger_client.so
#3 0xac71172e in android::SharedBufferClient::lock(int) () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libsurfaceflinger_client.so
#4 0xac7126e8 in android::Surface::lockBuffer(android_native_buffer_t*) () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libsurfaceflinger_client.so
#5 0xac71272e in android::Surface::lockBuffer(ANativeWindow*, android_native_buffer_t*) () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libsurfaceflinger_client.so
#6 0x80406dd2 in egl_window_surface_t::swapBuffers() () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libEGL_emulation.so
#7 0x804071fa in eglSwapBuffers () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libEGL_emulation.so
#8 0xabe037b8 in eglSwapBuffers () from /Users/snorp/source/jimdb-arm/lib/emulator-5554/system/lib/libEGL.so
#9 0x4dd3e550 in fSwapBuffers (surface=<optimized out>, dpy=<optimized out>, this=0x4f416d48 <mozilla::gl::sEGLLibrary>) at /Users/snorp/source/gecko-dev/gfx/gl/GLLibraryEGL.h:283
#10 mozilla::gl::GLContextEGL::SwapBuffers (this=<optimized out>) at /Users/snorp/source/gecko-dev/gfx/gl/GLContextProviderEGL.cpp:467
#11 0x4ddacd8a in mozilla::layers::CompositorOGL::EndFrame (this=0x555f4f80) at /Users/snorp/source/gecko-dev/gfx/layers/opengl/CompositorOGL.cpp:1189
#12 0x4dda2c40 in mozilla::layers::LayerManagerComposite::Render (this=0x555e7a60) at /Users/snorp/source/gecko-dev/gfx/layers/composite/LayerManagerComposite.cpp:519
#13 0x4dda2db6 in EndTransaction (aFlags=<optimized out>, this=0x555e7a60, aCallback=<optimized out>, aCallbackData=<optimized out>)
at /Users/snorp/source/gecko-dev/gfx/layers/composite/LayerManagerComposite.cpp:244
#14 mozilla::layers::LayerManagerComposite::EndTransaction (this=0x555e7a60, aCallback=<optimized out>, aCallbackData=<optimized out>, aFlags=<optimized out>)
at /Users/snorp/source/gecko-dev/gfx/layers/composite/LayerManagerComposite.cpp:200
#15 0x4dd9ad2e in mozilla::layers::LayerManagerComposite::EndEmptyTransaction (this=<optimized out>, aFlags=<optimized out>)
at /Users/snorp/source/gecko-dev/gfx/layers/composite/LayerManagerComposite.cpp:195
#16 0x4dda35ac in mozilla::layers::CompositorParent::CompositeToTarget (this=0x555caa00, aTarget=0x0) at /Users/snorp/source/gecko-dev/gfx/layers/ipc/CompositorParent.cpp:666
#17 0x4dda4ade in DispatchToMethod<mozilla::layers::CompositorParent, void (mozilla::layers::CompositorParent::*)()> (method=
(void (mozilla::layers::CompositorParent::*)(mozilla::layers::CompositorParent * const)) 0x4dda36bb <mozilla::layers::CompositorParent::Composite()>, obj=<optimized out>, arg=...)
Assignee | ||
Updated•11 years ago
|
tracking-fennec: --- → ?
Updated•11 years ago
|
tracking-fennec: ? → 31+
Reporter | ||
Comment 6•11 years ago
|
||
There are other problems with testFindInPage on other Android platforms, so we're disabling it everywhere. Bug 1015395 may make significant changes to the test.
Depends on: 1015395
Comment 7•11 years ago
|
||
Might be related to bug 971355 comment 24, which is an Android bug that should have been fixed around 2.3.3. (The test image is 2.3.7 AFAICT)
Comment 8•10 years ago
|
||
Looking at libsurfaceflinger_client.so from the 2.3 image, the Android bug is fixed so that can't be it.
Updated•10 years ago
|
tracking-fennec: 31+ → +
Reporter | ||
Comment 10•9 years ago
|
||
Android 2.3 is no longer supported in Firefox 48+.
Test manifests were updated in bug 1251013.
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WONTFIX
Whiteboard: [leave open] [test disabled on Android 2.3]
Updated•4 years ago
|
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in
before you can comment on or make changes to this bug.
Description
•