Closed Bug 979552 Opened 11 years ago Closed 9 years ago

Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders | Automation Error: Missing end of test marker (process crashed?)

Categories

(Firefox for Android Graveyard :: Testing, defect)

x86_64
Linux
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WONTFIX

People

(Reporter: gbrown, Assigned: gbrown)

References

Details

Attachments

(1 file)

Very much like bug 975155... https://tbpl.mozilla.org/php/getParsedLog.php?id=35600530&tree=Ash&full=1#error7 09:07:59 INFO - 0 INFO SimpleTest START 09:07:59 INFO - 1 INFO TEST-START | testSettingsMenuItems 09:07:59 INFO - 2 INFO TEST-PASS | testSettingsMenuItems | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready 09:07:59 INFO - EventExpecter: no longer listening for Gecko:Ready 09:07:59 INFO - waitForText timeout on ^Settings$ 09:07:59 INFO - waitForText timeout on Enter Search 09:07:59 INFO - 3 INFO TEST-PASS | testSettingsMenuItems | Browser toolbar URL stayed the same - about:home should equal about:home 09:07:59 INFO - INFO | automation.py | Application ran for: 0:02:05.432812 09:07:59 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmplLfBh5pidlog 09:07:59 INFO - /data/anr/traces.txt not found 09:07:59 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected! 09:07:59 INFO - runtests.py | Running tests: end. 09:07:59 INFO - Mochi-Remote ERROR | Automation Error: Missing end of test marker (process crashed?) 09:07:59 INFO - 03-04 08:59:43.263 W/GeckoGLController( 1551): GLController::serverSurfaceChanged(1024, 743) 09:07:59 INFO - 03-04 08:59:43.287 W/GeckoGLController( 1551): GLController::resumeCompositor(1024, 743) and mCompositorCreated=true 09:07:59 INFO - 03-04 08:59:43.373 W/GeckoGLController( 1551): done GLController::resumeCompositor 09:07:59 INFO - 03-04 08:59:43.443 W/GeckoGLController( 1551): GLController::updateCompositor with mCompositorCreated=true 09:07:59 INFO - 03-04 08:59:43.443 W/GeckoGLController( 1551): GLController::resumeCompositor(1024, 743) and mCompositorCreated=true 09:07:59 INFO - 03-04 08:59:44.993 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:46.114 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:47.223 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:49.303 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:49.723 W/ActivityManager( 65): Launch timeout has expired, giving up wake lock! 09:07:59 INFO - 03-04 08:59:50.113 W/ActivityManager( 65): Activity idle timeout for HistoryRecord{40649c40 org.mozilla.fennec/org.mozilla.gecko.preferences.GeckoPreferences} 09:07:59 INFO - 03-04 08:59:52.243 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:53.033 W/ActivityManager( 65): Activity idle timeout for HistoryRecord{40721998 org.mozilla.fennec/.App} 09:07:59 INFO - 03-04 08:59:53.263 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:54.263 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:55.263 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 08:59:57.273 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:01.293 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:02.293 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:03.383 I/Robocop ( 1551): waitForText timeout on Enter Search 09:07:59 INFO - 03-04 09:00:03.903 I/Robocop ( 1551): 3 INFO TEST-PASS | testSettingsMenuItems | Browser toolbar URL stayed the same - about:home should equal about:home 09:07:59 INFO - 03-04 09:00:05.293 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:05.533 E/GeckoConsole( 1551): 1393952405532 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:05.533 I/Gecko ( 1551): 1393952405532 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:05.573 E/GeckoConsole( 1551): 1393952405574 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:05.573 I/Gecko ( 1551): 1393952405574 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:05.605 E/GeckoConsole( 1551): 1393952405608 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:05.605 I/Gecko ( 1551): 1393952405608 addons.updates WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 09:07:59 INFO - 03-04 09:00:09.300 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:12.293 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:13.303 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:16.293 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:17.314 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:21.310 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:23.303 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:25.321 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:29.324 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:30.323 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:33.324 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:33.915 W/WindowManager( 65): Input event injection timed out. 09:07:59 INFO - 03-04 09:00:34.323 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:37.333 W/SharedBufferStack( 1551): waitForCondition(LockCondition) timed out (identity=55, status=0). CPU may be pegged. trying again. 09:07:59 INFO - 03-04 09:00:38.923 I/InputDispatcher( 65): Application is not responding: AppWindowToken{40725cd0 token=HistoryRecord{40721998 org.mozilla.fennec/.App}} - Window{40616d90 org.mozilla.fennec/org.mozilla.fennec.App paused=false}. 5005.7ms since event, 5002.8ms since wait started 09:07:59 INFO - 03-04 09:00:38.923 I/WindowManager( 65): Input event dispatching timed out sending to org.mozilla.fennec/org.mozilla.fennec.App 09:07:59 INFO - 03-04 09:00:38.933 D/AndroidRuntime( 1542): Shutting down VM 09:07:59 INFO - 03-04 09:00:38.953 I/ActivityManager( 65): Force stopping package org.mozilla.fennec uid=10017 09:07:59 INFO - 03-04 09:00:38.953 I/Process ( 65): Sending signal. PID: 1598 SIG: 9
Blocks: 967704
All of these look similar and fail with "CPU may be pegged".
Summary: Frequent Android 2.3 testSettingsMenuItems | Automation Error: Missing end of test marker (process crashed?) → Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders, testSettingsMenuItems, testTitleBox | Automation Error: Missing end of test marker (process crashed?)
Summary: Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders, testSettingsMenuItems, testTitleBox | Automation Error: Missing end of test marker (process crashed?) → Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders, testImportFromAndroid, testSettingsMenuItems, testTitleBar | Automation Error: Missing end of test marker (process crashed?)
Whiteboard: [leave open] [test disabled on Android 2.3]
Blocks: 979921
No longer blocks: 967704
Verified that this still happens, if skipped tests are enabled: https://tbpl.mozilla.org/php/getParsedLog.php?id=41585120&tree=Ash&full=1#error4 00:57:33 INFO - 1 INFO TEST-START | testBookmarkFolders 00:57:33 INFO - 2 INFO TEST-PASS | testBookmarkFolders | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready 00:57:33 INFO - EventExpecter: no longer listening for Gecko:Ready 00:57:33 INFO - 3 INFO TEST-PASS | testBookmarkFolders | Generating a random Guid for the bookmark - We could not generate a Guid for the bookmark 00:57:33 INFO - 4 INFO TEST-PASS | testBookmarkFolders | Inserted at: - content://org.mozilla.fennec.db.browser/bookmarks/10?profile=default&sync=true 00:57:33 INFO - 5 INFO TEST-PASS | testBookmarkFolders | waiting for urlbar text to gain focus - urlbar text gained focus 00:57:33 INFO - 6 INFO TEST-PASS | testBookmarkFolders | Checking that the correct tab is displayed - The BOOKMARKS tab is displayed 00:57:33 INFO - 7 INFO TEST-PASS | testBookmarkFolders | waiting for urlbar text to gain focus - urlbar text gained focus 00:57:33 INFO - 8 INFO TEST-PASS | testBookmarkFolders | Checking that the correct tab is displayed - The BOOKMARKS tab is displayed 00:57:33 INFO - 00:57:33 WARNING - TEST-UNEXPECTED-FAIL | testBookmarkFolders | application timed out after 330 seconds with no output 00:57:33 INFO - INFO | automation.py | Application ran for: 0:10:45.986804 00:57:33 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpDVIZ7Cpidlog 00:57:33 INFO - /data/anr/traces.txt not found 00:57:33 INFO - Stopping web server 00:57:33 INFO - Stopping web socket server 00:57:33 INFO - Stopping ssltunnel 00:57:33 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected! 00:57:33 INFO - runtests.py | Running tests: end. 00:57:33 INFO - Mochi-Remote ERROR | runTests() exited with code 2 00:57:33 INFO - Mochi-Remote ERROR | Automation Error: Missing end of test marker (process crashed?) 00:57:33 INFO - Mochi-Remote INFO | 00:57:33 INFO - 06-12 00:30:03.264 I/Gecko ( 1776): 1402533003271 addons.update-checker WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 00:57:33 INFO - 06-12 00:30:04.773 W/SharedBufferStack( 1776): waitForCondition(LockCondition) timed out (identity=75, status=0). CPU may be pegged. trying again. 00:57:33 INFO - 06-12 00:30:06.782 W/SharedBufferStack( 1776): waitForCondition(LockCondition) timed out (identity=75, status=0). CPU may be pegged. trying again. 00:57:33 INFO - 06-12 00:30:07.784 W/SharedBufferStack( 1776): waitForCondition(LockCondition) timed out (identity=75, status=0). CPU may be pegged. trying again. 00:57:33 INFO - 06-12 00:30:08.783 W/SharedBufferStack( 1776): waitForCondition(LockCondition) timed out (identity=75, status=0). CPU may be pegged. trying again.
testBookmarkFolders calls getInstrumentation.waitForIdleSync() around the time the application crashes - related?
Assignee: snorp → michael.l.comella
Status: NEW → ASSIGNED
I removed the `getInstrumentation().waitForIdleSync()` calls, as per comment 5, and all tests besides testImportFromAndroid appear to work now. These calls did not seem necessary, but I don't entirely know their intended purpose. try: https://tbpl.mozilla.org/?tree=Try&rev=8d8f7a6e2c40
Attachment #8441766 - Flags: review?(gbrown)
Comment on attachment 8441766 [details] [diff] [review] Remove getInstrumentation().waitForIdleSync calls and re-enable tests. Review of attachment 8441766 [details] [diff] [review]: ----------------------------------------------------------------- I do not like those waitForIdleSync calls and don't know what they are for either. They may be sleep() calls in disguise! I don't mind removing them. Unfortunately, the tests are still crashing in your try run -- silently. In the first Android 2.3 rc1, https://tbpl.mozilla.org/php/getParsedLog.php?id=41844309&tree=Try&full=1, both testAddSearchEngine and testBookmarkFolders crashed, even though rc1 is green on tbpl. :(
Attachment #8441766 - Flags: review?(gbrown) → feedback+
Some interesting lines in testAddSearchEngine: 22:23:39 INFO - 06-16 22:02:32.036 W/SharedBufferStack( 645): waitForCondition(LockCondition) timed out (identity=24, status=0). CPU may be pegged. trying again. 22:23:39 INFO - 06-16 22:02:55.165 E/GeckoConsole( 645): 1402956175174 addons.update-checker WARN Request failed: http://10.0.2.2:8854/extensions-dummy/updateBackgroundURL - 404: Not Found 22:23:39 INFO - 06-16 22:02:59.967 W/WindowManager( 64): Input event injection timed out. 22:23:39 INFO - 06-16 22:03:04.986 I/InputDispatcher( 64): Application is not responding: Window{406c15d0 org.mozilla.fennec/org.mozilla.fennec.App paused=false}. 35021.9ms since event, 5008.8ms since wait started 22:23:39 INFO - 06-16 22:03:04.986 I/WindowManager( 64): Input event dispatching timed out sending to org.mozilla.fennec/org.mozilla.fennec.App The failure appears to be here: https://mxr.mozilla.org/mozilla-central/source/mobile/android/base/tests/testAddSearchEngine.java?rev=523e67cf4b9e#72
testBookmarkFolders appears to die in the same location as before, with waitForIdleSync. testTitleBar appears not to have run, and the other tests also failed. :\
Not actively working on this.
Assignee: michael.l.comella → nobody
Status: ASSIGNED → NEW
Bug 1058027 sounds like it deals with similar issues in real 2.3 devices but the fix did not resolve any test failures.
Some of these tests have been deleted.
Summary: Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders, testImportFromAndroid, testSettingsMenuItems, testTitleBar | Automation Error: Missing end of test marker (process crashed?) → Frequent Android 2.3 testAddSearchEngine, testBookmarkFolders | Automation Error: Missing end of test marker (process crashed?)
Whiteboard: [leave open] [test disabled on Android 2.3] → [test disabled on Android 2.3]
Android 2.3 is no longer supported in Firefox 48+. Test manifests were updated in bug 1251013.
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WONTFIX
Whiteboard: [test disabled on Android 2.3]
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: