Closed Bug 1167565 Opened 10 years ago Closed 4 years ago

Intermittent PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?)

Categories

(Firefox for Android Graveyard :: General, defect, P2)

Product:
Firefox for Android Graveyard
Component:
General
Platform:
ARM
Android
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: RyanVM, Unassigned)

References

Details

(Keywords: crash, intermittent-failure, regression, Whiteboard: [priority:medium][stockwell unknown])

+++ This bug was initially created as a clone of Bug #1161150 +++ 05:15:32 INFO - SimpleTest START 05:15:32 INFO - TEST-START | testUITelemetry 05:15:32 INFO - TEST-PASS | testUITelemetry | Robocop tests need the test device screen to be powered on. - 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready 05:15:32 INFO - EventExpecter: no longer listening for Gecko:Ready 05:15:32 INFO - EventExpecter: no longer listening for Gecko:Ready 05:15:32 INFO - Registered listener for Robocop:JS 05:15:32 INFO - Loading JavaScript test from http://mochi.test:8888/tests/robocop/robocop_javascript.html?slug=1432293755119&path=testUITelemetry.js 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 1 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 1 pending 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 2 pending 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | testUITelemetry.js | Starting test_enabled","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - testUITelemetry.js | Starting test_enabled 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [getObserver : 65] true == true\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [getObserver : 65] true == true 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [test_enabled : 75] true == true\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [test_enabled : 75] true == true 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [test_enabled : 76] true == true\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [test_enabled : 76] true == true 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 3 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 3 pending 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 3 finished\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 3 finished 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 finished\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 2 finished 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 2 pending 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | testUITelemetry.js | Starting test_telemetry_events","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - testUITelemetry.js | Starting test_telemetry_events 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [getObserver : 65] true == true\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [getObserver : 65] true == true 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 0 == 0\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 0 == 0 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_2 == _test_method_2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_2 == _test_method_2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_3.1 == _test_event_3.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_3.1 == _test_event_3.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 2 == 2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 2 == 2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] foobarextras == foobarextras\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] foobarextras == foobarextras 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] session == session\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] session == session 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 52] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 52] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 53] _test_reason_1 == _test_reason_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 53] _test_reason_1 == _test_reason_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_4.1 == _test_event_4.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_4.1 == _test_event_4.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] barextras == barextras\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] barextras == barextras 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] session == session\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] session == session 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 52] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 52] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 53] _test_reason_2 == _test_reason_2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 53] _test_reason_2 == _test_reason_2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] == \n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] == 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 0 == 0\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 0 == 0 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 0 == 0\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 0 == 0 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_2.1 == _test_event_2.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_2 == _test_method_2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_2 == _test_method_2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_3.1 == _test_event_3.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_3.1 == _test_event_3.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 2 == 2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 2 == 2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] foobarextras == foobarextras\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] foobarextras == foobarextras 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] session == session\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] session == session 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 52] _test_session_started_twice.1 == _test_session_started_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 52] _test_session_started_twice.1 == _test_session_started_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 53] _test_reason_1 == _test_reason_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 53] _test_reason_1 == _test_reason_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_4.1 == _test_event_4.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_4.1 == _test_event_4.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] _test_method_1 == _test_method_1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] _test_method_1 == _test_method_1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 1 == 1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 1 == 1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 32] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] barextras == barextras\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] barextras == barextras 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] session == session\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] session == session 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 52] _test_session_stopped_twice.1 == _test_session_stopped_twice.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 52] _test_session_stopped_twice.1 == _test_session_stopped_twice.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 53] _test_reason_2 == _test_reason_2\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 53] _test_reason_2 == _test_reason_2 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 41] event == event\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 41] event == event 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 45] _test_event_1.1 == _test_event_1.1 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 46] == \n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 46] == 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_array_eq : 30] 0 == 0\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_array_eq : 30] 0 == 0 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-PASS | testUITelemetry.js | [do_check_measurement_eq : 48] undefined == undefined\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - TEST-PASS | testUITelemetry | testUITelemetry.js - [do_check_measurement_eq : 48] undefined == undefined 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 3 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 3 pending 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 3 finished\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 3 finished 05:15:32 INFO - TEST-PASS | testUITelemetry | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 finished\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 05:15:32 INFO - (xpcshell/head.js) | test 2 finished 05:15:32 INFO - INFO | automation.py | Application ran for: 0:01:46.911194 05:15:32 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpzWV2dvpidlog 05:15:32 INFO - Contents of /data/anr/traces.txt: 05:15:32 INFO - 05:15:32 INFO - 05:15:32 INFO - Stopping web server 05:15:32 INFO - Stopping web socket server 05:15:32 INFO - Stopping ssltunnel 05:15:32 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected! 05:15:32 INFO - runtests.py | Running tests: end. 05:15:32 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?)
In both comment 1 and comment 2, I see pico and quicksearchbox starting at the time of the crash: 00:33:40 INFO - 05-21 23:41:23.310 I/DEBUG ( 35): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 00000000 00:33:40 INFO - 05-21 23:41:23.350 I/ActivityManager( 283): Start proc com.svox.pico for broadcast com.svox.pico/.VoiceDataInstallerReceiver: pid=853 uid=10011 gids={50011, 1015, 1028} 00:33:40 INFO - 05-21 23:41:24.181 I/ActivityManager( 283): Start proc com.android.quicksearchbox for broadcast com.android.quicksearchbox/.CorporaUpdateReceiver: pid=866 uid=10027 gids={50027, 3003, 1028} :mcomella -- I hope you don't think I'm picking on you, but since these crashes look a little similar to bug 1161150, and since they started around the time you re-landed bug 1137483, and since they mention com.android.quicksearchbox (is that related in any way to 1137483?), I have to ask: Do you think there might be a connection to bug 1137483?
Flags: needinfo?(michael.l.comella)
com.android.quicksearchbox isn't related to my feature (in fact, I call my feature "search engine bar" and have dropped the quick). Note: iirc, the intermittent in bug 1161150 affected 2.3 and testInputUrlBar. This one affects 4.3 (notably both are emulators) and affects testUITelemetry. I see this in both failures: 00:33:40 INFO - 05-21 23:41:21.981 D/Robocop ( 776): received event Robocop:JS 00:33:40 INFO - 05-21 23:41:21.991 D/Robocop ( 776): unblocked on expecter for Robocop:JS 00:33:40 INFO - 05-21 23:41:22.001 I/Robocop ( 776): {"action":"log","message":"(xpcshell\/head.js) | test 2 finished","time":1432276882000,"pid":null,"level":"info","source":"robocop","thread":null} So it seems we finish, but then we crash. In one failure, I also see: 00:33:40 INFO - 05-21 23:41:21.981 E/ ( 399): RS Message thread exiting. ... (the messages above) 00:33:40 INFO - 05-21 23:41:22.230 E/RenderScript( 399): rsAssert failed: !mTypes.size(), in frameworks/rs/rsType.cpp at 59 00:33:40 INFO - 05-21 23:41:22.260 E/RenderScript( 399): rsAssert failed: !mElements.size(), in frameworks/rs/rsElement.cpp at 375 00:33:40 INFO - 05-21 23:41:23.181 F/libc ( 776): Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1), thread 795 (Gecko) So I wonder if this is related. bug 1137483 could be related in so much that we added a View that could change the interactions around telemetry (e.g. we forget to close a telemetry session when exiting via this search method; but there are no expected changes that would affect the test), but there's no obvious connection.
Flags: needinfo?(michael.l.comella)
(In reply to Treeherder Robot from comment #12) > log: > https://treeherder.mozilla.org/logviewer.html#?repo=mozilla- > central&job_id=1573814 > repository: mozilla-central > start_time: 2015-05-29T15:08:40 > who: wkocher[at]mozilla[dot]com > machine: tst-linux64-spot-1142 > buildname: Android 4.3 armv7 API 11+ mozilla-central opt test robocop-4 > revision: 164a9a5ab7c9 This crash is unlike all the others here: 15:41:32 INFO - 05-29 15:40:20.258 E/GeckoLinker( 1768): Error opening /data/app/o: No such file or directory 15:41:32 INFO - 05-29 15:40:20.258 E/GeckoLibLoad( 1768): Throw 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): Exception starting favicon cache. Corrupt resources? 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): java.lang.IllegalArgumentException: Invalid path or invalid zip 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.mozglue.NativeZip.getZip(Native Method) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.mozglue.NativeZip.<init>(NativeZip.java:23) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.util.GeckoJarReader.getZipFile(GeckoJarReader.java:103) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.util.GeckoJarReader.getBitmapDrawable(GeckoJarReader.java:47) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.util.GeckoJarReader.getBitmap(GeckoJarReader.java:35) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.favicons.Favicons.loadBrandingBitmap(Favicons.java:497) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.favicons.Favicons.initializeWithContext(Favicons.java:478) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.GeckoApp.onCreate(GeckoApp.java:1184) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at org.mozilla.gecko.BrowserApp.onCreate(BrowserApp.java:691) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.Activity.performCreate(Activity.java:5133) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2175) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2261) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.ActivityThread.access$600(ActivityThread.java:141) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1256) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.os.Handler.dispatchMessage(Handler.java:99) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.os.Looper.loop(Looper.java:137) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at android.app.ActivityThread.main(ActivityThread.java:5103) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at java.lang.reflect.Method.invokeNative(Native Method) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at java.lang.reflect.Method.invoke(Method.java:525) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) 15:41:32 INFO - 05-29 15:40:20.309 E/GeckoApp( 1768): at dalvik.system.NativeStart.main(Native Method) 15:41:32 INFO - 05-29 15:40:20.348 D/GeckoScreenOrientation( 1768): updating to new orientation PORTRAIT_PRIMARY 15:41:32 INFO - 05-29 15:40:20.368 D/GeckoLoader( 1768): Gecko environment env0: MOZ_CRASHREPORTER=1 15:41:32 INFO - 05-29 15:40:20.368 D/GeckoLoader( 1768): env1: XPCOM_DEBUG_BREAK=stack 15:41:32 INFO - 05-29 15:40:20.388 D/GeckoLoader( 1768): env2: R_LOG_VERBOSE=1 15:41:32 INFO - 05-29 15:40:20.388 D/GeckoLoader( 1768): env3: DISABLE_UNSAFE_CPOW_WARNINGS=1 15:41:32 INFO - 05-29 15:40:20.399 D/GeckoLoader( 1768): env4: MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 15:41:32 INFO - 05-29 15:40:20.399 D/GeckoLoader( 1768): env5: R_LOG_DESTINATION=stderr 15:41:32 INFO - 05-29 15:40:20.408 D/GeckoLoader( 1768): env6: MOZ_CRASHREPORTER_NO_REPORT=1 15:41:32 INFO - 05-29 15:40:20.408 D/GeckoLoader( 1768): env7: NSPR_LOG_FILE=/sdcard/tests/nspr/nspr-testGeckoRequest.log 15:41:32 INFO - 05-29 15:40:20.428 D/GeckoLoader( 1768): env8: R_LOG_LEVEL=6 15:41:32 INFO - 05-29 15:40:20.428 D/GeckoLoader( 1768): env9: null 15:41:32 INFO - 05-29 15:40:20.448 W/ContextImpl( 1768): Unable to create external files directory 15:41:32 INFO - 05-29 15:40:20.468 W/ContextImpl( 1768): Unable to create cache directory /data/data/or 15:41:32 INFO - 05-29 15:40:20.498 W/dalvikvm( 1768): threadid=13: thread exiting with uncaught exception (group=0x414c8700) 15:41:32 INFO - 05-29 15:40:20.508 E/GeckoCrashHandler( 1768): >>> REPORTING UNCAUGHT EXCEPTION FROM THREAD 85 ("Gecko") 15:41:32 INFO - 05-29 15:40:20.508 E/GeckoCrashHandler( 1768): java.lang.NullPointerException 15:41:32 INFO - 05-29 15:40:20.508 E/GeckoCrashHandler( 1768): at org.mozilla.gecko.mozglue.GeckoLoader.setupGeckoEnvironment(GeckoLoader.java:161) 15:41:32 INFO - 05-29 15:40:20.508 E/GeckoCrashHandler( 1768): at org.mozilla.gecko.GeckoThread.initGeckoEnvironment(GeckoThread.java:111) 15:41:32 INFO - 05-29 15:40:20.508 E/GeckoCrashHandler( 1768): at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:167) 15:41:32 INFO - 05-29 15:40:20.518 E/GeckoCrashHandler( 1768): Main thread (1) stack: 15:41:32 INFO - 05-29 15:40:20.538 E/GeckoCrashHandler( 1768): dalvik.system.DexPathList.findClass(DexPathList.java:312) 15:41:32 INFO - 05-29 15:40:20.548 E/GeckoCrashHandler( 1768): dalvik.system.BaseDexClassLoader.findClass(BaseDexClassLoader.java:51) 15:41:32 INFO - 05-29 15:40:20.548 E/GeckoCrashHandler( 1768): java.lang.ClassLoader.loadClass(ClassLoader.java:501) 15:41:32 INFO - 05-29 15:40:20.558 E/GeckoCrashHandler( 1768): java.lang.ClassLoader.loadClass(ClassLoader.java:461) 15:41:32 INFO - 05-29 15:40:20.558 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.createView(LayoutInflater.java:559) 15:41:32 INFO - 05-29 15:40:20.568 E/GeckoCrashHandler( 1768): com.android.internal.policy.impl.PhoneLayoutInflater.onCreateView(PhoneLayoutInflater.java:56) 15:41:32 INFO - 05-29 15:40:20.578 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.onCreateView(LayoutInflater.java:669) 15:41:32 INFO - 05-29 15:40:20.588 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:694) 15:41:32 INFO - 05-29 15:40:20.608 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.rInflate(LayoutInflater.java:755) 15:41:32 INFO - 05-29 15:40:20.608 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.inflate(LayoutInflater.java:492) 15:41:32 INFO - 05-29 15:40:20.608 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.inflate(LayoutInflater.java:397) 15:41:32 INFO - 05-29 15:40:20.608 E/GeckoCrashHandler( 1768): android.view.LayoutInflater.inflate(LayoutInflater.java:353) 15:41:32 INFO - 05-29 15:40:20.631 E/GeckoCrashHandler( 1768): com.android.internal.policy.impl.PhoneWindow.generateLayout(PhoneWindow.java:2823) 15:41:32 INFO - 05-29 15:40:20.631 E/GeckoCrashHandler( 1768): com.android.internal.policy.impl.PhoneWindow.installDecor(PhoneWindow.java:2886) 15:41:32 INFO - 05-29 15:40:20.639 E/GeckoCrashHandler( 1768): com.android.internal.policy.impl.PhoneWindow.setContentView(PhoneWindow.java:263) 15:41:32 INFO - 05-29 15:40:20.639 E/GeckoCrashHandler( 1768): android.app.Activity.setContentView(Activity.java:1895) 15:41:32 INFO - 05-29 15:40:20.639 E/GeckoCrashHandler( 1768): org.mozilla.gecko.GeckoApp.onCreate(GeckoApp.java:1275) 15:41:32 INFO - 05-29 15:40:20.648 E/GeckoCrashHandler( 1768): org.mozilla.gecko.BrowserApp.onCreate(BrowserApp.java:691) 15:41:32 INFO - 05-29 15:40:20.668 E/GeckoCrashHandler( 1768): android.app.Activity.performCreate(Activity.java:5133) 15:41:32 INFO - 05-29 15:40:20.668 E/GeckoCrashHandler( 1768): android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087) 15:41:32 INFO - 05-29 15:40:20.678 E/GeckoCrashHandler( 1768): android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2175) 15:41:32 INFO - 05-29 15:40:20.678 E/GeckoCrashHandler( 1768): android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2261) 15:41:32 INFO - 05-29 15:40:20.678 E/GeckoCrashHandler( 1768): android.app.ActivityThread.access$600(ActivityThread.java:141) 15:41:32 INFO - 05-29 15:40:20.688 E/GeckoCrashHandler( 1768): android.app.ActivityThread$H.handleMessage(ActivityThread.java:1256) 15:41:32 INFO - 05-29 15:40:20.688 E/GeckoCrashHandler( 1768): android.os.Handler.dispatchMessage(Handler.java:99) 15:41:32 INFO - 05-29 15:40:20.688 E/GeckoCrashHandler( 1768): android.os.Looper.loop(Looper.java:137) 15:41:32 INFO - 05-29 15:40:20.699 E/GeckoCrashHandler( 1768): android.app.ActivityThread.main(ActivityThread.java:5103) 15:41:32 INFO - 05-29 15:40:20.699 E/GeckoCrashHandler( 1768): java.lang.reflect.Method.invokeNative(Native Method) 15:41:32 INFO - 05-29 15:40:20.699 E/GeckoCrashHandler( 1768): java.lang.reflect.Method.invoke(Method.java:525) 15:41:32 INFO - 05-29 15:40:20.709 E/GeckoCrashHandler( 1768): com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) 15:41:32 INFO - 05-29 15:40:20.719 E/GeckoCrashHandler( 1768): com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) 15:41:32 INFO - 05-29 15:40:20.719 E/GeckoCrashHandler( 1768): dalvik.system.NativeStart.main(Native Method) I'm not too concerned since this is the only such failure I've seen. Any interest :jchen?
Flags: needinfo?(nchen)
:liuche -- Comments 54 and 55 are from the newly re-enabled testSettingsMenuItems.
Flags: needinfo?(liuche)
I see testSettingsMenuItems was disabled again in bug 1175996.
Flags: needinfo?(liuche)
I haven't noticed any more crashes like Comment 15.
Flags: needinfo?(nchen)
Most recent failures are during testUITelemetry; OOM is suspect. 17:41:47 INFO - 07-06 17:40:23.167 I/Robocop ( 797): {"message":"Robocop:JS should equal Robocop:JS","time":1436229623154,"source":"robocop","status":"PASS","test":"testUITelemetry","thread":null,"subtest":"Given message occurred for registered event: {\"message\":\"\\nTEST-INFO | (xpcshell\\\/head.js) | test 2 finished\\n\",\"innerType\":\"progress\",\"type\":\"Robocop:JS\"}","action":"test_status","pid":null} 17:41:47 INFO - 07-06 17:40:23.167 D/Robocop ( 797): received event Robocop:JS 17:41:47 INFO - 07-06 17:40:23.177 D/Robocop ( 797): unblocked on expecter for Robocop:JS 17:41:47 INFO - 07-06 17:40:23.187 I/Robocop ( 797): {"action":"log","message":"(xpcshell\/head.js) | test 2 finished","time":1436229623183,"pid":null,"level":"info","source":"robocop","thread":null} 17:41:47 INFO - 07-06 17:40:23.457 D/GeckoMemoryMonitor( 797): onTrimMemory() notification received with level 15 17:41:47 INFO - 07-06 17:40:23.457 D/GeckoMemoryMonitor( 797): increasing memory pressure to 4 17:41:47 INFO - 07-06 17:40:24.787 F/libc ( 797): Fatal signal 11 (SIGSEGV) at 0x1e6bfff0 (code=1), thread 816 (Gecko)
This is a low-frequency startup crash affecting robocop tests. Often the minidump is missing; when the minidump is obtained, the crash report looks like: http://ftp.mozilla.org/pub/mozilla.org/mobile/tinderbox-builds/mozilla-inbound-android-api-11/1445310458/mozilla-inbound_ubuntu64_vm_armv7_mobile_test-robocop-1-bm123-tests1-linux64-build571.txt.gz 20:59:42 WARNING - PROCESS-CRASH | testBrowserSearchVisibility | application crashed [@ dalvik-jit-code-cache (deleted) + 0x210ba] 20:59:42 INFO - Crash dump filename: /tmp/tmpH7Lt51/5f8c73d3-3100-a5c3-58f92c75-0535161c.dmp 20:59:42 INFO - Operating system: Android 20:59:42 INFO - 0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l generic/sdk/generic:4.3.1/JLS36I/eng.gbrown.20150308.182649:eng/test-keys 20:59:42 INFO - CPU: arm 20:59:42 INFO - ARMv0 20:59:42 INFO - 0 CPUs 20:59:42 INFO - Crash reason: SIGSEGV 20:59:42 INFO - Crash address: 0x9ec1f9a7 20:59:42 INFO - Process uptime: not available 20:59:42 INFO - Thread 0 (crashed) 20:59:42 INFO - 0 dalvik-jit-code-cache (deleted) + 0x210ba 20:59:42 INFO - r0 = 0x527b9117 r1 = 0x527b9117 r2 = 0x527b9117 r3 = 0x00000000 20:59:42 INFO - r4 = 0xefb2f7de r5 = 0x4c4668ac r6 = 0x2a00d090 r7 = 0x4c466890 20:59:42 INFO - r8 = 0x4085bdc0 r9 = 0x00000008 r10 = 0x4c466898 r12 = 0x2a1ebc9c 20:59:42 INFO - fp = 0x419746b0 sp = 0xbebee758 lr = 0x00000000 pc = 0x527b90ba 20:59:42 INFO - Found by: given as instruction pointer in context 20:59:42 INFO - 1 libdvm.so + 0x2de9a 20:59:42 INFO - sp = 0xbebee764 pc = 0x4086be9c 20:59:42 INFO - Found by: stack scanning 20:59:42 INFO - 2 dalvik-LinearAlloc (deleted) + 0xa79b6 20:59:42 INFO - sp = 0xbebee778 pc = 0x4c50e9b8 20:59:42 INFO - Found by: stack scanning 20:59:42 INFO - 3 dalvik-heap (deleted) + 0x290c52 20:59:42 INFO - sp = 0xbebee77c pc = 0x41745c54 20:59:42 INFO - Found by: stack scanning :jchen -- Any interest?
Flags: needinfo?(nchen)
Flags: needinfo?(nchen)
Depends on: 1236194
:snorp -- This bug collects an assortment of crashes, typically robocop startup crashes lately. In some recent logs, I notice something like: http://archive.mozilla.org/pub/mobile/tinderbox-builds/mozilla-inbound-android-api-15/1457637864/mozilla-inbound_ubuntu64_vm_armv7_mobile_test-robocop-1-bm115-tests1-linux64-build117.txt.gz 12:37:07 INFO - 03-10 12:36:27.041 W/google-breakpad( 2766): ExceptionHandler::GenerateDump cloned child 12:37:07 INFO - 03-10 12:36:27.041 W/google-breakpad( 2766): 2807d:)@ z�[�SӾhTӾ����z�[�Q�R�2�R 12:37:07 INFO - 03-10 12:36:27.073 W/google-breakpad( 2807): ExceptionHandler::WaitForContinueSignal waiting for continue signal... 12:37:07 INFO - 03-10 12:36:27.073 W/google-breakpad( 2766): 12:37:07 INFO - 03-10 12:36:27.101 W/google-breakpad( 2766): ExceptionHandler::SendContinueSignalToChild sent continue signal to child Just pointing it out in case that's of interest.
Flags: needinfo?(snorp)
This bug collects an assortment of crashes. In the last couple of weeks, many have been Android 4.3 Robocop startup crashes. Most of these logs do not have crash reports (as I would expect -- crash reporter may not be initialized) and I don't see a clear cause of failure in the logs. I notice some occur shortly after "GeckoPushService: Starting up." http://archive.mozilla.org/pub/mobile/try-builds/markcapella@twcny.rr.com-7e3dbe4ee1234c2add266dff1ab1e3d9bee9c6e6/try-android-api-15/try_ubuntu64_vm_armv7_mobile_test-robocop-3-bm54-tests1-linux64-build623.txt.gz and/or "W/GeckoPushManager( 1837): Startup: needs Google Play Services. Ignoring until GCM is requested in response to user activity." http://archive.mozilla.org/pub/mobile/tinderbox-builds/mozilla-inbound-android-api-15/1457623766/mozilla-inbound_ubuntu64_vm_armv7_mobile_test-robocop-1-bm54-tests1-linux64-build686.txt.gz :nalexander -- Do any of these logs concern you? Any interest in investigating?
Flags: needinfo?(nalexander)
(In reply to Geoff Brown [:gbrown] from comment #240) > :snorp -- This bug collects an assortment of crashes, typically robocop > startup crashes lately. In some recent logs, I notice something like: Yeah that's just some (busted) breakpad debug spew.
Flags: needinfo?(snorp)
> :nalexander -- Do any of these logs concern you? Any interest in > investigating? Inexplicable startup crashes always concern me, but reading these and a few others from War on Orange doesn't really seem to point at the GCM startup, which aborts on these test devices after checking that GPS isn't available. At the same time, we are initializing the downloadable content catalog, and starting Gecko, etc. I could believe there's an interaction between starting the Gecko background thread for GCM startup, and starting it for Gecko. jchen, I'm using the Gecko background thread for all GCM actions. I initialize GCM in GeckoApplication, implicitly creating the background thread very early in the App lifecycle. This must start the background thread much earlier than it was pre-GCM. I read the Gecko background thread code pretty carefully and saw no reason to be concerned about starting it early. Does this seem dangerous to you? Could it contribute to start up crashes of the type gbrown has flagged in c#241? The background thread will be started at https://dxr.mozilla.org/mozilla-central/source/mobile/android/base/java/org/mozilla/gecko/GeckoApplication.java#169.
Flags: needinfo?(nalexander) → needinfo?(nchen)
That seems pretty safe to me.
Flags: needinfo?(nchen)
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Blocks: 951181
Many of these occur during robocop tests. Almost none are testUITelemetry.
Summary: Intermittent Android 4.3 PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) during testUITelemetry → Intermittent Android 4.3 PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?)
Depends on: 1331514
We'll hit this failure when there is a crash but no minidump is generated. I think the increase in frequency here is simply indicative of higher crash rate on Android generally, especially for testSessionOOMSave and shutdown crashes in PostTask_Helper, both of which are under investigation elsewhere.
In the last 8 months nobody took a look at this bug. The failure rate is not so high but it is still failing. Also, the bugs that bug depended on 1315652, 1318952 were fixed. :mcomella: Hi, Can you please take a look at this bug?
Flags: needinfo?(michael.l.comella)
Desrigard bugs in the comment above, I wanted to link bugs 1236194, 1331514.
Geoff, could you take a look at this? I'm only only fennec for triage and critical reviews.
Flags: needinfo?(michael.l.comella) → needinfo?(gbrown)
I can't look into this in depth. Usually this failure message indicates a crash during a robocop test. I expect there are multiple crash causes collected here. Many of the failure logs show the same NullPointerException: https://treeherder.mozilla.org/logviewer.html#?job_id=176411209&repo=mozilla-inbound&lineNumber=2324 https://treeherder.mozilla.org/logviewer.html#?job_id=176420801&repo=mozilla-inbound&lineNumber=1756 https://treeherder.mozilla.org/logviewer.html#?job_id=176452085&repo=mozilla-inbound&lineNumber=1654 https://treeherder.mozilla.org/logviewer.html#?job_id=176455960&repo=mozilla-inbound&lineNumber=1665 [task 2018-05-01T16:00:53.285Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): java.lang.NullPointerException [task 2018-05-01T16:00:53.286Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at org.mozilla.gecko.tests.SessionTest.createTestSession(SessionTest.java:141) [task 2018-05-01T16:00:53.287Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at org.mozilla.gecko.tests.AssistIntentTest.setActivityIntent(AssistIntentTest.java:12) [task 2018-05-01T16:00:53.287Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at org.mozilla.gecko.tests.BaseRobocopTest.setUp(BaseRobocopTest.java:172) [task 2018-05-01T16:00:53.287Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at org.mozilla.gecko.tests.UITest.setUp(UITest.java:46) [task 2018-05-01T16:00:53.287Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at junit.framework.TestCase.runBare(TestCase.java:132) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at junit.framework.TestResult$1.protect(TestResult.java:115) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at junit.framework.TestResult.runProtected(TestResult.java:133) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at junit.framework.TestResult.run(TestResult.java:118) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at junit.framework.TestCase.run(TestCase.java:124) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191) [task 2018-05-01T16:00:53.288Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176) [task 2018-05-01T16:00:53.289Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554) [task 2018-05-01T16:00:53.289Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at org.mozilla.gecko.FennecInstrumentationTestRunner.onStart(FennecInstrumentationTestRunner.java:64) [task 2018-05-01T16:00:53.289Z] 16:00:53 INFO - 05-01 09:00:30.402 I/TestRunner( 1803): at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701) :JanH -- It looks like you have worked on SessionTest in the past; could you have a look?
Flags: needinfo?(gbrown) → needinfo?(jh+bugzilla)
Hmm, the top line there is SessionTest.java:141, which is "PageInfo home = new PageInfo(StringHelper.STATIC_ABOUT_HOME_URL);" [1], where STATIC_ABOUT_HOME_URL is a static string and the PageInfo constructor doesn't do anything terribly complicated and in any case doesn't even appear in the stack trace. So as a first approximation I've got no idea why and how we're encountering a null pointer exception here. The only idea I've got is experimentally replacing the StringHelper reference with a string literal in case it's some very weird class initialisation issue, but other than that I'm at a loss here.
Depends on: 1460028
Flags: needinfo?(jh+bugzilla)
Update: There have been 41 failures in the last 7 days, all of them on android-em-4-3-armv7-api16 opt. Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=188871496&repo=autoland&lineNumber=1611 [task 2018-07-19T04:44:02.875Z] 04:44:02 INFO - TEST-START | testSessionOOMSave [task 2018-07-19T04:44:24.515Z] 04:44:24 INFO - GECKO | EventExpecter: no longer listening for Content:PageShow [task 2018-07-19T04:44:55.569Z] 04:44:55 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:44:55.570Z] 04:44:55 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:45:16.215Z] 04:45:16 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:45:16.215Z] 04:45:16 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:45:36.858Z] 04:45:36 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:45:36.858Z] 04:45:36 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:45:47.177Z] 04:45:47 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:45:47.177Z] 04:45:47 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:46:49.396Z] 04:46:49 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:46:49.396Z] 04:46:49 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:47:10.030Z] 04:47:10 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:47:10.030Z] 04:47:10 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:47:20.351Z] 04:47:20 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:47:20.351Z] 04:47:20 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:48:22.257Z] 04:48:22 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:48:22.257Z] 04:48:22 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:48:43.301Z] 04:48:43 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-07-19T04:48:43.301Z] 04:48:43 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-07-19T04:49:04.042Z] 04:49:04 INFO - Failed to get top activity, retrying, once... [task 2018-07-19T04:49:04.764Z] 04:49:04 INFO - INFO | automation.py | Application ran for: 0:05:14.726182 [task 2018-07-19T04:49:04.765Z] 04:49:04 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmp_eUUhYpidlog [task 2018-07-19T04:49:07.765Z] 04:49:07 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) [task 2018-07-19T04:49:08.375Z] 04:49:08 INFO - 07-18 21:48:59.355 W/Resources( 4004): Preloaded drawable resource #0x10801ca (android:drawable/btn_star_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.376Z] 04:49:08 INFO - 07-18 21:48:59.425 W/Resources( 4004): Preloaded drawable resource #0x10801fa (android:drawable/btn_toggle_on_pressed_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.377Z] 04:49:08 INFO - 07-18 21:48:59.425 W/Resources( 4004): Preloaded drawable resource #0x10801f9 (android:drawable/btn_toggle_on_pressed_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.378Z] 04:49:08 INFO - 07-18 21:48:59.435 W/Resources( 4004): Preloaded drawable resource #0x10801f8 (android:drawable/btn_toggle_on_normal_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.378Z] 04:49:08 INFO - 07-18 21:48:59.445 W/Resources( 4004): Preloaded drawable resource #0x10801f7 (android:drawable/btn_toggle_on_normal_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.383Z] 04:49:08 INFO - 07-18 21:48:59.505 W/Resources( 4004): Preloaded drawable resource #0x10801f6 (android:drawable/btn_toggle_on_focused_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.383Z] 04:49:08 INFO - 07-18 21:48:59.516 W/Resources( 4004): Preloaded drawable resource #0x10801f5 (android:drawable/btn_toggle_on_focused_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.383Z] 04:49:08 INFO - 07-18 21:48:59.525 W/Resources( 4004): Preloaded drawable resource #0x10801f4 (android:drawable/btn_toggle_on_disabled_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.383Z] 04:49:08 INFO - 07-18 21:48:59.525 W/Resources( 4004): Preloaded drawable resource #0x10801f3 (android:drawable/btn_toggle_on_disabled_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.383Z] 04:49:08 INFO - 07-18 21:48:59.597 W/Resources( 4004): Preloaded drawable resource #0x10801f2 (android:drawable/btn_toggle_on_disabled_focused_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.384Z] 04:49:08 INFO - 07-18 21:48:59.606 W/Resources( 4004): Preloaded drawable resource #0x10801f1 (android:drawable/btn_toggle_on_disabled_focused_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.384Z] 04:49:08 INFO - 07-18 21:48:59.616 W/Resources( 4004): Preloaded drawable resource #0x10801ef (android:drawable/btn_toggle_off_pressed_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.385Z] 04:49:08 INFO - 07-18 21:48:59.616 W/Resources( 4004): Preloaded drawable resource #0x10801ee (android:drawable/btn_toggle_off_pressed_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.386Z] 04:49:08 INFO - 07-18 21:48:59.686 W/Resources( 4004): Preloaded drawable resource #0x10801ed (android:drawable/btn_toggle_off_normal_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.387Z] 04:49:08 INFO - 07-18 21:48:59.686 W/Resources( 4004): Preloaded drawable resource #0x10801ec (android:drawable/btn_toggle_off_normal_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.387Z] 04:49:08 INFO - 07-18 21:48:59.696 W/Resources( 4004): Preloaded drawable resource #0x10801eb (android:drawable/btn_toggle_off_focused_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.388Z] 04:49:08 INFO - 07-18 21:48:59.696 W/Resources( 4004): Preloaded drawable resource #0x10801ea (android:drawable/btn_toggle_off_focused_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.389Z] 04:49:08 INFO - 07-18 21:48:59.766 W/Resources( 4004): Preloaded drawable resource #0x10801e9 (android:drawable/btn_toggle_off_disabled_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.391Z] 04:49:08 INFO - 07-18 21:48:59.776 W/Resources( 4004): Preloaded drawable resource #0x10801e8 (android:drawable/btn_toggle_off_disabled_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.392Z] 04:49:08 INFO - 07-18 21:48:59.786 W/Resources( 4004): Preloaded drawable resource #0x10801e7 (android:drawable/btn_toggle_off_disabled_focused_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.392Z] 04:49:08 INFO - 07-18 21:48:59.786 W/Resources( 4004): Preloaded drawable resource #0x10801e6 (android:drawable/btn_toggle_off_disabled_focused_holo_dark) that varies with configuration!! [task 2018-07-19T04:49:08.393Z] 04:49:08 INFO - 07-18 21:48:59.856 W/Resources( 4004): Preloaded drawable resource #0x10801f8 (android:drawable/btn_toggle_on_normal_holo_light) that varies with configuration!! [task 2018-07-19T04:49:08.393Z] 04:49:08 INFO - 07-18 21:48:59.867 W/Resources( 4004): Preloaded drawable resource #0x10801f4 (android:drawable/btn_toggle_on_disabled_holo_light) that varies with configuration!!
Whiteboard: [stockwell needswork]
Re-triaging per https://bugzilla.mozilla.org/show_bug.cgi?id=1473195 Needinfo :susheel if you think this bug should be re-triaged.
Priority: P3 → P5
(In reply to Intermittent Failures Robot from comment #372) > 62 failures in 760 pushes (0.082 failures/push) were associated with this > bug in the last 7 days. Most of these are bug 1476635.
Depends on: 1476635
There have been 32 failures in the last week and 87 failures in the last 21 days. Almost all the failures occur on android-em-4-3-armv7-api16 / opt with one exception for windows7-32 / pgo Recent log file and snippet with the failure: task 2018-08-26T15:26:27.346Z] 15:26:27 INFO - TEST-START | testActivityStreamPocketReferrer [task 2018-08-26T15:27:10.430Z] 15:27:10 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-08-26T15:27:10.431Z] 15:27:10 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-08-26T15:27:31.066Z] 15:27:31 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-08-26T15:27:31.066Z] 15:27:31 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-08-26T15:27:52.003Z] 15:27:52 INFO - wait for org.mozilla.fennec_aurora complete; top activity=com.android.launcher [task 2018-08-26T15:27:52.408Z] 15:27:52 INFO - INFO | automation.py | Application ran for: 0:01:38.303942 [task 2018-08-26T15:27:52.408Z] 15:27:52 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpAFxWX5pidlog [task 2018-08-26T15:27:52.926Z] 15:27:52 INFO - /data/tombstones does not exist; tombstone check skipped [task 2018-08-26T15:27:54.162Z] 15:27:54 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) [task 2018-08-26T15:27:54.570Z] 15:27:54 INFO - 08-26 08:26:20.099 I/dalvikvm( 3728): Could not find method android.app.NotificationChannel.getId, referenced from method org.mozilla.gecko.GuestSession.showNotification [task 2018-08-26T15:27:54.570Z] 15:27:54 INFO - 08-26 08:26:20.099 W/dalvikvm( 3728): VFY: unable to resolve virtual method 507: Landroid/app/NotificationChannel;.getId ()Ljava/lang/String; [task 2018-08-26T15:27:54.570Z] 15:27:54 INFO - 08-26 08:26:20.149 D/GeckoJarReader( 3728): No Entry for chrome/en-US/locale/en-US/browser/searchplugins/list.json Depends on: 1476635
Summary: Intermittent Android 4.3 PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) → Intermittent PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?)
There have been 53 failures in the last week, 97 in the last 21 days. Affected platform / build: android-em-4-3-armv7-api16 / opt. Recent relevat log file: https://treeherder.mozilla.org/logviewer.html#?job_id=197147281&repo=autoland&lineNumber=1430 Summary: Intermittent PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?)
There have been 34 failures in the last week. Most of the failures occur on android-em-4-3-armv7-api16 / opt. Recent relevant log file: https://treeherder.mozilla.org/logviewer.html#?job_id=198551672&repo=autoland&lineNumber=1595
This bug has failed 34 times in the last 7 days. Occurs on android-em-4-3-armv7-api16 on opt and debug build types. Recent log: INFO - TEST-START | testActivityStreamPocketReferrer [task 2018-09-20T03:12:51.537Z] 03:12:51 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-09-20T03:12:51.538Z] 03:12:51 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-09-20T03:13:11.967Z] 03:13:11 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-09-20T03:13:11.967Z] 03:13:11 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-09-20T03:13:32.703Z] 03:13:32 INFO - wait for org.mozilla.fennec_aurora complete; top activity=com.android.launcher [task 2018-09-20T03:13:33.008Z] 03:13:33 INFO - INFO | automation.py | Application ran for: 0:01:35.967214 [task 2018-09-20T03:13:33.008Z] 03:13:33 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmp9yY__Bpidlog [task 2018-09-20T03:13:33.525Z] 03:13:33 INFO - /data/tombstones does not exist; tombstone check skipped [task 2018-09-20T03:13:34.658Z] 03:13:34 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) [task 2018-09-20T03:13:35.065Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): StrictMode policy violation; ~duration=326 ms: android.os.StrictMode$StrictModeDiskReadViolation: policy=543 violation=2 [task 2018-09-20T03:13:35.065Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.os.StrictMode$AndroidBlockGuardPolicy.onReadFromDisk(StrictMode.java:1123) [task 2018-09-20T03:13:35.066Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.SharedPreferencesImpl.awaitLoadedLocked(SharedPreferencesImpl.java:203) [task 2018-09-20T03:13:35.067Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.SharedPreferencesImpl.contains(SharedPreferencesImpl.java:268) [task 2018-09-20T03:13:35.068Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at org.mozilla.gecko.switchboard.Preferences.getOverrideValue(Preferences.java:70) [task 2018-09-20T03:13:35.070Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at org.mozilla.gecko.switchboard.SwitchBoard.isInExperiment(SwitchBoard.java:154) [task 2018-09-20T03:13:35.071Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at org.mozilla.gecko.promotion.AddToHomeScreenPromotion.initializeExperiment(AddToHomeScreenPromotion.java:82) [task 2018-09-20T03:13:35.073Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at org.mozilla.gecko.promotion.AddToHomeScreenPromotion.onCreate(AddToHomeScreenPromotion.java:68) [task 2018-09-20T03:13:35.073Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at org.mozilla.gecko.BrowserApp.onCreate(BrowserApp.java:865) [task 2018-09-20T03:13:35.073Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.Activity.performCreate(Activity.java:5133) [task 2018-09-20T03:13:35.073Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087) [task 2018-09-20T03:13:35.074Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2175) [task 2018-09-20T03:13:35.074Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2261) [task 2018-09-20T03:13:35.074Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.ActivityThread.access$600(ActivityThread.java:141) [task 2018-09-20T03:13:35.074Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1256) [task 2018-09-20T03:13:35.075Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.os.Handler.dispatchMessage(Handler.java:99) [task 2018-09-20T03:13:35.075Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.os.Looper.loop(Looper.java:137) [task 2018-09-20T03:13:35.075Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at android.app.ActivityThread.main(ActivityThread.java:5103) [task 2018-09-20T03:13:35.076Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at java.lang.reflect.Method.invokeNative(Native Method) [task 2018-09-20T03:13:35.076Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at java.lang.reflect.Method.invoke(Method.java:525) [task 2018-09-20T03:13:35.077Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) [task 2018-09-20T03:13:35.077Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) [task 2018-09-20T03:13:35.077Z] 03:13:35 INFO - 09-19 20:12:02.925 D/StrictMode( 3139): at dalvik.system.NativeStart.main(Native Method) [task 2018-09-20T03:13:35.077Z] 03:13:35 INFO - 09-19 20:12:02.925 I/dalvikvm( 3139): Could not find method android.content.Context.startForegroundService, referenced from method org.mozilla.mozstumbler.service.mainthread.LocalPreferenceReceiver.onReceive [task 2018-09-20T03:13:35.078Z] 03:13:35 INFO - 09-19 20:12:02.925 E/GeckoSearchEngineManager( 3139): Could not find search plugin files in profile directory [task 2018-09-20T03:13:35.079Z] 03:13:35 INFO - 09-19 20:12:02.935 E/GeckoSearchEngineManager( 3139): Could not create search engine from name: null [task 2018-09-20T03:13:35.080Z] 03:13:35 INFO - 09-19 20:12:02.935 D/GeckoSessInfo( 3139): Recording start of session: 1537413122780 [task 2018-09-20T03:13:35.081Z] 03:13:35 INFO - 09-19 20:12:02.945 W/dalvikvm( 3139): VFY: unable to resolve virtual method 864: Landroid/content/Context;.startForegroundService (Landroid/content/Intent;)Landroid/content/ComponentName; [task 2018-09-20T03:13:35.081Z] 03:13:35 INFO - 09-19 20:12:02.945 D/StumblerSafeReceiver( 3139): Registered local preference listener [task 2018-09-20T03:13:35.082Z] 03:13:35 INFO - 09-19 20:12:02.985 I/Choreographer( 3139): Skipped 68 frames! The application may be doing too much work on its main thread. [task 2018-09-20T03:13:35.082Z] 03:13:35 INFO - 09-19 20:12:03.195 I/dalvikvm( 3139): Could not find method android.view.Window.setStatusBarColor, referenced from method org.mozilla.gecko.util.WindowUtil.setStatusBarColor [task 2018-09-20T03:13:35.083Z] 03:13:35 INFO - 09-19 20:12:03.205 W/dalvikvm( 3139): VFY: unable to resolve virtual method 20167: Landroid/view/Window;.setStatusBarColor (I)V [task 2018-09-20T03:13:35.083Z] 03:13:35 INFO - 09-19 20:12:03.605 D/libEGL ( 3139): loaded /system/lib/egl/libEGL_emulation.so [task 2018-09-20T03:13:35.084Z] 03:13:35 INFO - 09-19 20:12:03.625 D/ ( 3139): HostConnection::get() New Host Connection established 0x2a1f4900, tid 3139 [task 2018-09-20T03:13:35.084Z] 03:13:35 INFO - 09-19 20:12:03.645 D/libEGL ( 3139): loaded /system/lib/egl/libGLESv1_CM_emulation.so [task 2018-09-20T03:13:35.085Z] 03:13:35 INFO - 09-19 20:12:03.655 D/libEGL ( 3139): loaded /system/lib/egl/libGLESv2_emulation.so [task 2018-09-20T03:13:35.085Z] 03:13:35 INFO - 09-19 20:12:03.726 W/EGL_emulation( 3139): eglSurfaceAttrib not implemented [task 2018-09-20T03:13:35.085Z] 03:13:35 INFO - 09-19 20:12:03.755 D/OpenGLRenderer( 3139): Enabling debug mode 0 sdaswani: Can you please take a look at this bug?
Flags: needinfo?(sdaswani)
Whiteboard: [stockwell disable-recommended] → [stockwell disable-recommended][stockwell needswork]
Some investigation is already ongoing in bug 1476635, and I remember gbrown mentioning somewhere which particular sub-tests were hitting this most frequently.
Jan, so are you looking into this? Or should I find an owner?
Flags: needinfo?(sdaswani) → needinfo?(jh+bugzilla)
No, I'm not.
Flags: needinfo?(jh+bugzilla)
This bug has failed 32 times in last 7 days. Occurs on android-em-4-3-armv7-api16 on opt and 2 times on android-em-4-3-armv7-api16-ccov on debug. Recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=202089773&repo=autoland&lineNumber=1566 INFO - TEST-START | testActivityStreamPocketReferrer [task 2018-09-28T00:39:05.755Z] 00:39:05 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-09-28T00:39:05.756Z] 00:39:05 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-09-28T00:39:26.497Z] 00:39:26 INFO - GECKO | EventExpecter: no longer listening for Content:DOMContentLoaded [task 2018-09-28T00:39:26.497Z] 00:39:26 INFO - GECKO | EventExpecter: no longer listening for Content:DOMTitleChanged [task 2018-09-28T00:39:26.497Z] 00:39:26 INFO - wait for org.mozilla.fennec_aurora complete; top activity=com.android.launcher [task 2018-09-28T00:39:26.803Z] 00:39:26 INFO - INFO | automation.py | Application ran for: 0:01:16.664995 [task 2018-09-28T00:39:26.803Z] 00:39:26 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpnP9Cxipidlog [task 2018-09-28T00:39:27.323Z] 00:39:27 INFO - /data/tombstones does not exist; tombstone check skipped [task 2018-09-28T00:39:28.460Z] 00:39:28 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) [task 2018-09-28T00:39:28.867Z] 00:39:28 INFO - 09-27 17:38:16.296 D/StumblerSafeReceiver( 3180): Registered local preference listener [task 2018-09-28T00:39:28.868Z] 00:39:28 INFO - 09-27 17:38:16.296 I/Choreographer( 3180): Skipped 64 frames! The application may be doing too much work on its main thread. [task 2018-09-28T00:39:28.869Z] 00:39:28 INFO - 09-27 17:38:16.456 I/dalvikvm( 3180): Could not find method android.view.Window.setStatusBarColor, referenced from method org.mozilla.gecko.util.WindowUtil.setStatusBarColor [task 2018-09-28T00:39:28.869Z] 00:39:28 INFO - 09-27 17:38:16.466 W/dalvikvm( 3180): VFY: unable to resolve virtual method 20167: Landroid/view/Window;.setStatusBarColor (I)V [task 2018-09-28T00:39:28.869Z] 00:39:28 INFO - 09-27 17:38:16.926 D/libEGL ( 3180): loaded /system/lib/egl/libEGL_emulation.so [task 2018-09-28T00:39:28.870Z] 00:39:28 INFO - 09-27 17:38:16.926 D/ ( 3180): HostConnection::get() New Host Connection established 0x2a22ed80, tid 3180 [task 2018-09-28T00:39:28.870Z] 00:39:28 INFO - 09-27 17:38:16.955 D/libEGL ( 3180): loaded /system/lib/egl/libGLESv1_CM_emulation.so [task 2018-09-28T00:39:28.872Z] 00:39:28 INFO - 09-27 17:38:16.975 D/libEGL ( 3180): loaded /system/lib/egl/libGLESv2_emulation.so [task 2018-09-28T00:39:28.872Z] 00:39:28 INFO - 09-27 17:38:17.035 W/EGL_emulation( 3180): eglSurfaceAttrib not implemented [task 2018-09-28T00:39:28.872Z] 00:39:28 INFO - 09-27 17:38:17.056 D/OpenGLRenderer( 3180): Enabling debug mode 0 [task 2018-09-28T00:39:28.872Z] 00:39:28 INFO - 09-27 17:38:17.125 I/dalvikvm( 3180): Could not find method android.content.Context.getSystemService, referenced from method org.mozilla.gecko.util.ShortcutUtils.createHomescreenIcon26 [task 2018-09-28T00:39:28.873Z] 00:39:28 INFO - 09-27 17:38:17.125 W/dalvikvm( 3180): VFY: unable to resolve virtual method 842: Landroid/content/Context;.getSystemService (Ljava/lang/Class;)Ljava/lang/Object; [task 2018-09-28T00:39:28.875Z] 00:39:28 INFO - 09-27 17:38:17.136 I/dalvikvm( 3180): Could not find method android.content.Context.getSystemService, referenced from method org.mozilla.gecko.util.ShortcutUtils.isPinShortcutSupported26 [task 2018-09-28T00:39:28.876Z] 00:39:28 INFO - 09-27 17:38:17.136 W/dalvikvm( 3180): VFY: unable to resolve virtual method 842: Landroid/content/Context;.getSystemService (Ljava/lang/Class;)Ljava/lang/Object; [task 2018-09-28T00:39:28.877Z] 00:39:28 INFO - 09-27 17:38:17.145 D/GeckoToolbar( 3180): onTabChanged: SELECTED [task 2018-09-28T00:39:28.878Z] 00:39:28 INFO - 09-27 17:38:17.176 D/GeckoBrowserApp( 3180): BrowserApp.onTabChanged: 0: SELECTED [task 2018-09-28T00:39:28.879Z] 00:39:28 INFO - 09-27 17:38:17.296 I/dalvikvm( 3180): Could not find method android.content.res.Resources.getColor, referenced from method android.support.v4.content.res.ResourcesCompat.getColor [task 2018-09-28T00:39:28.880Z] 00:39:28 INFO - 09-27 17:38:17.316 W/dalvikvm( 3180): VFY: unable to resolve virtual method 1076: Landroid/content/res/Resources;.getColor (ILandroid/content/res/Resources$Theme;)I [task 2018-09-28T00:39:28.881Z] 00:39:28 INFO - 09-27 17:38:17.326 I/dalvikvm( 3180): Could not find method android.content.res.Resources.getColorStateList, referenced from method android.support.v4.content.res.ResourcesCompat.getColorStateList [task 2018-09-28T00:39:28.882Z] 00:39:28 INFO - 09-27 17:38:17.326 W/dalvikvm( 3180): VFY: unable to resolve virtual method 1078: Landroid/content/res/Resources;.getColorStateList (ILandroid/content/res/Resources$Theme;)Landroid/content/res/ColorStateList; [task 2018-09-28T00:39:28.884Z] 00:39:28 INFO - 09-27 17:38:17.326 I/dalvikvm( 3180): Could not find method android.content.res.Resources.getDrawable, referenced from method android.support.v4.content.res.ResourcesCompat.getDrawable [task 2018-09-28T00:39:28.885Z] 00:39:28 INFO - 09-27 17:38:17.326 W/dalvikvm( 3180): VFY: unable to resolve virtual method 1085: Landroid/content/res/Resources;.getDrawable (ILandroid/content/res/Resources$Theme;)Landroid/graphics/drawable/Drawable; [task 2018-09-28T00:39:28.886Z] 00:39:28 INFO - 09-27 17:38:17.326 I/dalvikvm( 3180): Could not find method android.content.res.Resources.getDrawableForDensity, referenced from method android.support.v4.content.res.ResourcesCompat.getDrawableForDensity [task 2018-09-28T00:39:28.887Z] 00:39:28 INFO - 09-27 17:38:17.336 W/dalvikvm( 3180): VFY: unable to resolve virtual method 1087: Landroid/content/res/Resources;.getDrawableForDensity (IILandroid/content/res/Resources$Theme;)Landroid/graphics/drawable/Drawable; [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.576 D/GeckoToolbar( 3180): onTabChanged: RESTORED [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.576 D/Telemetry( 3180): SendUIEvent: event = launch.1 method = homescreen timestamp = 1341346 extras = launcher [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.626 D/GeckoBrowserApp( 3180): onLocaleReady: en_US [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.656 D/GeckoNetworkManager( 3180): Incoming event receivedUpdate for state OnNoListeners -> OnNoListeners [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.706 D/GeckoNetworkManager( 3180): New network state: UP, CELLULAR, CELL_3G [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.716 I/Choreographer( 3180): Skipped 83 frames! The application may be doing too much work on its main thread. [task 2018-09-28T00:39:28.888Z] 00:39:28 INFO - 09-27 17:38:17.726 D/GeckoThread( 3180): State changed to JNI_READY [task 2018-09-28T00:39:28.890Z] 00:39:28 INFO - 09-27 17:38:17.736 D/GeckoSuggestedSites( 3180): No cached sites, refreshing. [task 2018-09-28T00:39:28.890Z] 00:39:28 INFO - 09-27 17:38:17.736 D/GeckoSuggestedSites( 3180): Refreshing suggested sites from file [task 2018-09-28T00:39:28.891Z] 00:39:28 INFO - 09-27 17:38:17.906 D/GeckoSuggestedSites( 3180): Loading blacklisted suggested sites from SharedPreferences. [task 2018-09-28T00:39:28.892Z] 00:39:28 INFO - 09-27 17:38:17.925 D/GeckoSuggestedSites( 3180): Number of suggested sites: 8 [task 2018-09-28T00:39:28.892Z] 00:39:28 INFO - 09-27 17:38:18.836 I/ActivityManager( 275): Displayed org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp: +6s449ms [task 2018-09-28T00:39:28.893Z] 00:39:28 INFO - 09-27 17:38:18.876 E/SQLiteLog( 3180): (1) no such table: bookmarks sdaswani: Can you please take a look at this bug?
Flags: needinfo?(sdaswani)
Flags: needinfo?(sdaswani)
Whiteboard: [stockwell disable-recommended][stockwell needswork] → [priority:medium][stockwell disable-recommended][stockwell needswork]
Priority: P5 → P1
There are 6 failures in the last 7 days, removing the disable recommended tag.
Whiteboard: [priority:medium][stockwell disable-recommended][stockwell needswork] → [priority:medium][stockwell needswork]

Downgrading priority from P1 to P2

Priority: P1 → P2

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression
We have completed our launch of our new Firefox on Android. The development of the new versions use GitHub for issue tracking. If the bug report still reproduces in a current version of [Firefox on Android nightly](https://play.google.com/store/apps/details?id=org.mozilla.fenix) an issue can be reported at the [Fenix GitHub project](https://github.com/mozilla-mobile/fenix/). If you want to discuss your report please use [Mozilla's chat](https://wiki.mozilla.org/Matrix#Connect_to_Matrix) server https://chat.mozilla.org and join the [#fenix](https://chat.mozilla.org/#/room/#fenix:mozilla.org) channel.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.