Closed Bug 832052 Opened 11 years ago Closed 8 years ago

Only broken pandas hit testAllPagesTab,testAboutPage,testSearchSuggestions,testPasswordProvider | blockForEvent timeout: Gecko:Ready trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"

Categories

(Infrastructure & Operations Graveyard :: CIDuty, task)

Product:
Infrastructure & Operations Graveyard
Component:
CIDuty
Platform:
ARM
Android
Type:
task
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WONTFIX

People

(Reporter: philor, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3303] [badslave][leave open][panda])

Attachments

(1 file)

setup_nss_functions_logging.patch
1.47 KB, patch
glandium
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=18903648&tree=Mozilla-Inbound
Android Tegra 250 mozilla-inbound opt test robocop on 2013-01-17 14:06:13 PST for push d9f4929d5738
slave: tegra-115

2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:16:55.388 I/Robocop ( 1741): 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:16:55.408 I/Robocop ( 1741): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:16:55.408 I/Robocop ( 1741): 3 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:16:57.051 I/TestRunner( 1741): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testHistoryTab | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
01-17 14:17:52.018 I/Robocop ( 1841): 2 INFO TEST-UNEXPECTED-FAIL | testHistoryTab | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
01-17 14:17:53.748 I/TestRunner( 1841): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testHistoryTab | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:19:33.509 I/Robocop ( 2054): 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:19:33.528 I/Robocop ( 2054): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:19:33.528 I/Robocop ( 2054): 3 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:19:34.608 I/TestRunner( 2054): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarksTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:21:10.828 I/Robocop ( 2154): 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:21:10.858 I/Robocop ( 2154): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:21:10.858 I/Robocop ( 2154): 3 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:21:11.898 I/TestRunner( 2154): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebar | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:22:48.098 I/Robocop ( 2242): 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:22:48.108 I/Robocop ( 2242): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:22:48.108 I/Robocop ( 2242): 3 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:22:49.148 I/TestRunner( 2242): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAwesomebarSwipes | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:24:25.648 I/Robocop ( 2397): 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:24:25.668 I/Robocop ( 2397): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:24:25.678 I/Robocop ( 2397): 3 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:24:26.708 I/TestRunner( 2397): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmark | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:26:02.878 I/Robocop ( 2485): 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:26:02.908 I/Robocop ( 2485): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:26:02.908 I/Robocop ( 2485): 3 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:26:03.949 I/TestRunner( 2485): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testLoad | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:27:53.498 I/Robocop ( 2642): 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:27:53.508 I/Robocop ( 2642): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:27:53.508 I/Robocop ( 2642): 3 INFO TEST-UNEXPECTED-FAIL | testLoad | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:27:54.539 I/TestRunner( 2642): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testLoad | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testLoad | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testNewTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:29:31.088 I/Robocop ( 2794): 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:29:31.118 I/Robocop ( 2794): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:29:31.128 I/Robocop ( 2794): 3 INFO TEST-UNEXPECTED-FAIL | testNewTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:29:32.168 I/TestRunner( 2794): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testNewTab | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testNewTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:31:08.278 I/Robocop ( 2879): 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:31:08.308 I/Robocop ( 2879): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:31:08.308 I/Robocop ( 2879): 3 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:31:09.338 I/TestRunner( 2879): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPanCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:32:45.568 I/Robocop ( 2972): 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:32:45.588 I/Robocop ( 2972): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:32:45.588 I/Robocop ( 2972): 3 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:32:46.638 I/TestRunner( 2972): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testFlingCorrectness | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testOverscroll | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
01-17 14:33:06.688 I/Robocop ( 3058): 2 INFO TEST-UNEXPECTED-FAIL | testOverscroll | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
01-17 14:33:07.788 I/TestRunner( 3058): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testOverscroll | Exception caught - java.lang.SecurityException: Injecting to another application requires INJECT_EVENTS permission
2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:34:44.848 I/Robocop ( 3242): 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:34:44.868 I/Robocop ( 3242): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:34:44.868 I/Robocop ( 3242): 3 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:34:45.918 I/TestRunner( 3242): junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAxisLocking | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
3 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
Automation Error: No crash directory (/mnt/sdcard/tests/profile/minidumps/) found on remote device
01-17 14:36:22.178 I/Robocop ( 3330): 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:36:22.198 I/Robocop ( 3330): junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
01-17 14:36:22.198 I/Robocop ( 3330): 3 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready
First 100 of 179 failures shown.
Blocks: tegra-115
Component: General → Release Engineering: Machine Management
Product: Firefox for Android → mozilla.org
QA Contact: armenzg
Summary: Intermittent testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc. etc. etc. → Only tegra-115 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
Whiteboard: [buildduty][badslave]
Version: Trunk → other
(See also everything from bug 790102 comment 54 on)
I've gracefulled the tegra and will run stop_cp.sh once the last build has completed.
ripping off buildduty tag, as buildduty tracks the parent tegra-115 problem tracking bug
Whiteboard: [buildduty][badslave] → [badslave]
(In reply to TinderboxPushlog Robot from comment #10)
> Gijs
> https://tbpl.mozilla.org/php/getParsedLog.php?id=22371932&tree=Fx-Team
> slave: tegra-103
> 
> talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready
> [browser_output.txt]'

So apparently (judging by the 5 comments below this one) this is now (since 4/25) hitting the tegra-103 instead of the 115. New bug?
Summary: Only tegra-115 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only tegra-103/115 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
Fortunately, it went just great the last time we had an "every reimaged tegra is broken" thing.
Summary: Only tegra-103/115 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only tegra-103/115/315 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
And there I was wondering why 236 only hit it once.
Summary: Only tegra-103/115/315 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only tegra-103/115/236/315 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
The infection is spreading....
Summary: Only tegra-103/115/236/315 hits testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only broken tegras hit testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
The robocop test is failing because it is waiting for Gecko:Ready. It looks like Gecko:Ready is never sent, and actually, normal browser startup is stalled or aborted quietly. For example, all the normal GeckoLibLoad messages are curiously absent.

Even the launch ActivityManager messages are different in these logs. 

Normal:

05-06 11:15:57.630 I/ActivityManager( 1020): Force stopping package org.mozilla.fennec uid=10033
05-06 11:15:57.640 I/ActivityManager( 1020): Start proc org.mozilla.fennec for added application org.mozilla.fennec: pid=3479 uid=10033 gids={3003, 1015, 1006}
05-06 11:15:57.808 I/ActivityManager( 1020): Starting activity: Intent { act=android.intent.action.MAIN flg=0x10000000 cmp=org.mozilla.fennec/.App (has extras) }

Logs from these failures:

05-06 06:54:09.390 I/ActivityManager( 1020): Force stopping package org.mozilla.fennec uid=10033
05-06 06:54:09.400 I/ActivityManager( 1020): Start proc org.mozilla.fennec for added application org.mozilla.fennec: pid=1785 uid=10033 gids={3003, 1015, 1006}
Ok, so having done some checks between successful runs and bad runs, I have found the following data:

* com.android.phone is NOT running on the system on bad runs.
* A device that has a bad run, does not seem to have a good run after it has already failed.
* No pointedly wrong packages are installed.

To take the case of tegra-315, which I'm staring at now:

Last good job before first failed of this scope:

* Try, Armv6 crashtest2
** https://tbpl.mozilla.org/php/getParsedLog.php?id=22527643&tree=Try&full=1
** Had com.android.phone running as late as the reboot step.

First bad:

* inbound trobocheck
** https://tbpl.mozilla.org/php/getParsedLog.php?id=22528442&tree=Mozilla-Inbound&full=1 
** Did not have com.android.phone running, and crashes mentioning it present within log.

Next device run, also bad:

* inbound trobopan
** https://tbpl.mozilla.org/php/getParsedLog.php?id=22529687&tree=Mozilla-Inbound&full=1
** Same deal with com.android.phone

Next device run, actually good (but not this job):

* Try, Armv6 crashtest3
** https://tbpl.mozilla.org/php/getParsedLog.php?id=22530463&tree=Try&full=1
** logcat at this point shows:
*** |05-03 05:22:19.271 W/ActivityManager( 1020): Process com.android.phone has crashed too many times: killing!|
** That is in addition to com.android.phone not running, and same crash stack in logs.

--------

Conclusion, *something* in trobo occassionally breaks devices, and persists across cleanup/reboot. We need to figure out what!
:kats wrote trobocheck/pan, but he's away for a while. :(
(In reply to Justin Wood (:Callek) from comment #45)
> Conclusion, *something* in trobo occassionally breaks devices, and persists
> across cleanup/reboot. We need to figure out what!

But the inbound trobocheck log has a phone crash during the installApp.py step:

05-02 17:47:09.256 E/AndroidRuntime( 1216): FATAL EXCEPTION: main
05-02 17:47:09.256 E/AndroidRuntime( 1216): java.lang.NoSuchFieldError: 
05-02 17:47:09.256 E/AndroidRuntime( 1216): 	at com.android.phone.BluetoothHandsfree.<init>(BluetoothHandsfree.java:116)
05-02 17:47:09.256 E/AndroidRuntime( 1216): 	at com.android.phone.PhoneApp.onCreate(PhoneApp.java:413)

Doesn't that suggest that something happened after the crashtest and before the actual trobocheck test -- during the reboot or test setup?
(In reply to Geoff Brown [:gbrown] from comment #47)
> (In reply to Justin Wood (:Callek) from comment #45)
> > Conclusion, *something* in trobo occassionally breaks devices, and persists
> > across cleanup/reboot. We need to figure out what!
> 
> But the inbound trobocheck log has a phone crash during the installApp.py
> step:
> 
> 05-02 17:47:09.256 E/AndroidRuntime( 1216): FATAL EXCEPTION: main
> 05-02 17:47:09.256 E/AndroidRuntime( 1216): java.lang.NoSuchFieldError: 
> 05-02 17:47:09.256 E/AndroidRuntime( 1216): 	at
> com.android.phone.BluetoothHandsfree.<init>(BluetoothHandsfree.java:116)
> 05-02 17:47:09.256 E/AndroidRuntime( 1216): 	at
> com.android.phone.PhoneApp.onCreate(PhoneApp.java:413)
> 
> Doesn't that suggest that something happened after the crashtest and before
> the actual trobocheck test -- during the reboot or test setup?

Of course trobocheck installs more than just what crashtest installs, e.g. robocop itself. Which comes with it new permissions and reactions to system stuff.
we should also look at:
tegra-262
tegra-236
tegra-166
tegra-152
tegra-045
tegra-038
(In reply to Joel Maher (:jmaher) from comment #49)
> we should also look at:
> tegra-262
> tegra-166
> tegra-152
> tegra-045
> tegra-038

What made you pick these out of the bunch, none of which are listed in this bug anywhere

> tegra-236

This one however is listed.
(In reply to Justin Wood (:Callek) from comment #50)
> (In reply to Joel Maher (:jmaher) from comment #49)
> > we should also look at:

Ok, per IRC this was a "does it have com.android.phone running?"

> > tegra-262

yes

> > tegra-166

yes

> > tegra-152

yes

> > tegra-045

-- unable to connect --

> > tegra-038

yes

> > tegra-236


yes ?!?!?!????!!!
(In reply to TinderboxPushlog Robot from comment #51)
> philor
> https://tbpl.mozilla.org/php/getParsedLog.php?id=22664291&tree=Mozilla-
> Release
> Android Tegra 250 mozilla-release talos remote-trobocheck on 2013-05-06
> 20:05:28
> slave: tegra-072
> 
> talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready
> [browser_output.txt]'

This one (properly, heh) does NOT have com.android.phone running, and does have the |05-06 21:51:19.336 W/ActivityManager( 1020): Process com.android.phone has crashed too many times: killing!| message
https://tbpl.mozilla.org/php/getParsedLog.php?id=22696402&tree=Mozilla-Inbound
Summary: Only broken tegras hit testAllPagesTab | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only broken tegras hit testAllPagesTab,testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
:blassey -- See comment 45 especially for background. Do you have any ideas for how to proceed?
Flags: needinfo?(blassey.bugs)
So, if I read this correctly once this starts happening, the board fails permanently  even after reboot. Is that correct?

Also, having com.android.phone not running is indicative of this problem. Is that also correct?

Does reimaging the board fix it? If so, is that a feasible solution? The watcher could look for com.android.phone and if it isn't present take itself out of the pool and raise its hand to be reimaged. Given that we have five (?) boards currently out of service I'm assuming this doesn't happen terribly often. Maybe once a week we can reimage what has gone down?
Flags: needinfo?(blassey.bugs)
https://tbpl.mozilla.org/php/getParsedLog.php?id=22800289&tree=Mozilla-Inbound
Summary: Only broken tegras hit testAllPagesTab,testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only broken tegras hit testAllPagesTab,testAboutPage,testSearchSuggestions | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
https://tbpl.mozilla.org/php/getParsedLog.php?id=22804677&tree=Mozilla-Inbound
Summary: Only broken tegras hit testAllPagesTab,testAboutPage,testSearchSuggestions | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready etc., trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only broken tegras hit testAllPagesTab,testAboutPage,testSearchSuggestions,testPasswordProvider | blockForEvent timeout: Gecko:Ready trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
(In reply to Brad Lassey [:blassey] from comment #86)
> So, if I read this correctly once this starts happening, the board fails
> permanently  even after reboot. Is that correct?

Correct, but only these tests. non trobocheck* or trobopan tests still pass [in their normal frequency]

> Also, having com.android.phone not running is indicative of this problem. Is
> that also correct?

Yes

> Does reimaging the board fix it?

Unsure, but we suspect so (at this point)

> If so, is that a feasible solution? 

Yes and no, its a possible fix, however reimages of tegra boards is a VERY manual process all around, 10 minutes or so per board for releng (round trip time), aprox 20 minutes of work per board for DCOps (I `think`, could be longer)

>The watcher could look for com.android.phone and if it isn't present take itself out of the pool and raise its hand to be reimaged.

We could make our verify.py script catch this and take it out of the pool. (so we can know why its out, com.mozilla.watcher taking itself out wouldn't let us know why)

> Given that we have five (?) boards currently out of service I'm assuming this doesn't happen terribly often. Maybe once a week we can reimage what has gone down?

Seven i think right now, what caused me to look closer here is that we had 1, a few weeks ago, then 2, then 3, .. and so on, all within a matter of 2-3 weeks. Its common enough to not just chock up to "bad board" and with a fault like this I wish we could identify what was going on.
Blocks: 722166
Blocks: 872371
Blocks: 872372
Blocks: 872374
Blocks: tegra-315
Blocks: tegra-072
Blocks: tegra-051
Blocks: tegra-103
Blocks: tegra-236
Blocks: 872458
Component: Release Engineering: Machine Management → Release Engineering: Platform Support
QA Contact: armenzg → coop
Product: mozilla.org → Release Engineering
No longer blocks: tegra-236
Both comment 128 and comment 129 have:

12-14 09:20:20.325 E/GeckoLibLoad( 2893): Throw
12-14 09:20:20.365 E/GeckoLibLoad( 2893): Load nss done
12-14 09:20:20.365 W/dalvikvm( 2893): threadid=12: thread exiting with uncaught exception (group=0x4001d848)
12-14 09:20:20.365 E/GeckoAppShell( 2893): >>> REPORTING UNCAUGHT EXCEPTION FROM THREAD 14 ("Gecko")
12-14 09:20:20.365 E/GeckoAppShell( 2893): java.lang.Exception: Error loading nss libraries
12-14 09:20:20.365 E/GeckoAppShell( 2893): 	at org.mozilla.gecko.mozglue.GeckoLoader.loadNSSLibsNative(Native Method)
12-14 09:20:20.365 E/GeckoAppShell( 2893): 	at org.mozilla.gecko.mozglue.GeckoLoader.loadNSSLibs(GeckoLoader.java:236)
12-14 09:20:20.365 E/GeckoAppShell( 2893): 	at org.mozilla.gecko.GeckoThread.initGeckoEnvironment(GeckoThread.java:116)
12-14 09:20:20.365 E/GeckoAppShell( 2893): 	at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:168)
12-14 09:20:20.365 E/GeckoAppShell( 2893): Main thread stack:
12-14 09:20:20.365 E/GeckoAppShell( 2893): java.lang.Object.wait(Native Method)
12-14 09:20:20.365 E/GeckoAppShell( 2893): java.lang.Object.wait(Object.java:326)
12-14 09:20:20.365 E/GeckoAppShell( 2893): android.os.MessageQueue.next(MessageQueue.java:142)
12-14 09:20:20.365 E/GeckoAppShell( 2893): android.os.Looper.loop(Looper.java:110)
12-14 09:20:20.365 E/GeckoAppShell( 2893): android.app.ActivityThread.main(ActivityThread.java:4627)
12-14 09:20:20.365 E/GeckoAppShell( 2893): java.lang.reflect.Method.invokeNative(Native Method)
12-14 09:20:20.365 E/GeckoAppShell( 2893): java.lang.reflect.Method.invoke(Method.java:521)
12-14 09:20:20.365 E/GeckoAppShell( 2893): com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)
12-14 09:20:20.365 E/GeckoAppShell( 2893): com.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)
12-14 09:20:20.365 E/GeckoAppShell( 2893): dalvik.system.NativeStart.main(Native Method)
:blassey -- any ideas? ^^
Flags: needinfo?(blassey.bugs)
See Also: → 951404
That exception is thrown here [1], which happens when loadNSSLibs() returns a failure code. That can happen in a few places, 4 of which have log statements [2,3,4 & 5]. I think the thing to do may be to add logging to the other places where it can fail.

Glandium, any thoughts?


[1] https://mxr.mozilla.org/mozilla-central/source/mozglue/android/APKOpen.cpp#357
[2] https://mxr.mozilla.org/mozilla-central/source/mozglue/android/APKOpen.cpp#284
[3] https://mxr.mozilla.org/mozilla-central/source/mozglue/android/APKOpen.cpp#290
[4] https://mxr.mozilla.org/mozilla-central/source/mozglue/android/APKOpen.cpp#285
[5] https://mxr.mozilla.org/mozilla-central/source/mozglue/android/NSSBridge.cpp#54
Flags: needinfo?(blassey.bugs) → needinfo?(mh+mozilla)
Comment on attachment 8349133 [details] [diff] [review]
setup_nss_functions_logging.patch

Review of attachment 8349133 [details] [diff] [review]:
-----------------------------------------------------------------

::: mozglue/android/NSSBridge.cpp
@@ +54,4 @@
>      return FAILURE;
>    }
>  #define GETFUNC(name) f_ ## name = (name ## _t) (uintptr_t) __wrap_dlsym(nss_handle, #name); \
> +  if (!f_ ##name) { LOG( "missing " #name);  return FAILURE; }

Make that LOG("Missing %s", name)
Attachment #8349133 - Flags: review?(mh+mozilla) → review+
Whiteboard: [badslave] → [badslave][leave open]
Flags: needinfo?(mh+mozilla)
See Also: → 957185
Depends on: 959254
No longer blocks: tegra-051
No longer blocks: tegra-072
No longer blocks: tegra-103
No longer blocks: tegra-115
Whiteboard: [badslave][leave open] → [badslave][leave open][tegra]
Summary: Only broken tegras hit testAllPagesTab,testAboutPage,testSearchSuggestions,testPasswordProvider | blockForEvent timeout: Gecko:Ready trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'" → Only broken pandas hit testAllPagesTab,testAboutPage,testSearchSuggestions,testPasswordProvider | blockForEvent timeout: Gecko:Ready trobocheck, trobopan "talosError: 'GeckoEventExpecter: blockForEvent timeout: Gecko:Ready [browser_output.txt]'"
Whiteboard: [badslave][leave open][tegra] → [badslave][leave open][panda]
Whiteboard: [badslave][leave open][panda] → [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3294] [badslave][leave open][panda]
Whiteboard: [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3294] [badslave][leave open][panda] → [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3299] [badslave][leave open][panda]
Whiteboard: [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3299] [badslave][leave open][panda] → [kanban:engops:https://mozilla.kanbanize.com/ctrl_board/6/3303] [badslave][leave open][panda]
lol, pandas.
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → WONTFIX
Component: Platform Support → Buildduty
Product: Release Engineering → Infrastructure & Operations
Product: Infrastructure & Operations → Infrastructure & Operations Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: