Closed Bug 1504873 Opened 6 years ago Closed 6 years ago

Intermittent toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | xpcshell return code: 0

Categories

(Toolkit :: Places, defect, P5)

Product:
Toolkit
Component:
Places
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: shindli [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=209898786&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/EK412kKpQW2ZtDI3QULwCw/runs/0/artifacts/public/logs/live_backing.log [task 2018-11-05T20:15:06.182Z] 20:15:06 INFO - Retrying tests that failed when run in parallel. [task 2018-11-05T20:15:06.185Z] 20:15:06 INFO - TEST-START | toolkit/components/places/tests/unifiedcomplete/test_keywords.js [task 2018-11-05T20:15:09.985Z] 20:15:09 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_keywords.js | took 3800ms [task 2018-11-05T20:15:10.001Z] 20:15:10 INFO - TEST-START | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js [task 2018-11-05T20:15:12.743Z] 20:15:12 WARNING - TEST-UNEXPECTED-FAIL | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | xpcshell return code: 0 [task 2018-11-05T20:15:12.744Z] 20:15:12 INFO - TEST-INFO took 2738ms [task 2018-11-05T20:15:12.745Z] 20:15:12 INFO - >>>>>>> [task 2018-11-05T20:15:12.746Z] 20:15:12 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) [task 2018-11-05T20:15:12.747Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2) [task 2018-11-05T20:15:12.748Z] 20:15:12 INFO - (xpcshell/head.js) | test MAIN run_test finished (2) [task 2018-11-05T20:15:12.748Z] 20:15:12 INFO - running event loop [task 2018-11-05T20:15:12.749Z] 20:15:12 INFO - toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | Starting ensure_search_engine [task 2018-11-05T20:15:12.750Z] 20:15:12 INFO - (xpcshell/head.js) | test ensure_search_engine pending (2) [task 2018-11-05T20:15:12.750Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2) [task 2018-11-05T20:15:12.752Z] 20:15:12 INFO - PID 9968 | JavaScript strict warning: jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/nsSearchService.js, line 721: ReferenceError: reference to undefined property "name" [task 2018-11-05T20:15:12.752Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2) [task 2018-11-05T20:15:12.754Z] 20:15:12 INFO - (xpcshell/head.js) | test ensure_search_engine finished (2) [task 2018-11-05T20:15:12.754Z] 20:15:12 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "name"" {file: "jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/nsSearchService.js" line: 721}]" [task 2018-11-05T20:15:12.756Z] 20:15:12 INFO - toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | Starting init [task 2018-11-05T20:15:12.757Z] 20:15:12 INFO - (xpcshell/head.js) | test init pending (2) [task 2018-11-05T20:15:12.757Z] 20:15:12 INFO - PID 9968 | JavaScript strict warning: resource://testing-common/PlacesTestUtils.jsm, line 83: ReferenceError: reference to undefined property "transition" [task 2018-11-05T20:15:12.758Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2) [task 2018-11-05T20:15:12.760Z] 20:15:12 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "transition"" {file: "resource://testing-common/PlacesTestUtils.jsm" line: 83}]" [task 2018-11-05T20:15:12.761Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2) [task 2018-11-05T20:15:12.762Z] 20:15:12 INFO - (xpcshell/head.js) | test init finished (2) [task 2018-11-05T20:15:12.763Z] 20:15:12 INFO - toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | Starting getPost [task 2018-11-05T20:15:12.763Z] 20:15:12 INFO - (xpcshell/head.js) | test getPost pending (2) [task 2018-11-05T20:15:12.764Z] 20:15:12 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2) [task 2018-11-05T20:15:12.765Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 3 == 3 [task 2018-11-05T20:15:12.767Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 3 == 3 [task 2018-11-05T20:15:12.767Z] 20:15:12 INFO - "Searching for: 'get'" [task 2018-11-05T20:15:12.768Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.769Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.770Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.771Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.772Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"","input":"get%20","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.774Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"\\",\\"input\\":\\"get%20\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20\\",\\"searchQuery\\":\\"\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.774Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.775Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.776Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.777Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.785Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.786Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.786Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 4 == 4 [task 2018-11-05T20:15:12.786Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 4 == 4 [task 2018-11-05T20:15:12.788Z] 20:15:12 INFO - "Searching for: 'get '" [task 2018-11-05T20:15:12.788Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.788Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.788Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.789Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.789Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"","input":"get%20","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.790Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"\\",\\"input\\":\\"get%20\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20\\",\\"searchQuery\\":\\"\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.790Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.791Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.791Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.792Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.792Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.793Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.800Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 8 == 8 [task 2018-11-05T20:15:12.801Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 8 == 8 [task 2018-11-05T20:15:12.803Z] 20:15:12 INFO - "Searching for: 'get fire'" [task 2018-11-05T20:15:12.804Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.808Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.809Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.811Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.812Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"fire","input":"get%20fire","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.813Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"fire\\",\\"input\\":\\"get%20fire\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20fire\\",\\"searchQuery\\":\\"fire\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.815Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.818Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.819Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.821Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.824Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.825Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.827Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 11 == 11 [task 2018-11-05T20:15:12.832Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 11 == 11 [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "Searching for: 'get mozilla'" [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"mozilla","input":"get%20mozilla","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.835Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"mozilla\\",\\"input\\":\\"get%20mozilla\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20mozilla\\",\\"searchQuery\\":\\"mozilla\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.838Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.839Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.844Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.845Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.846Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.848Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.849Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 11 == 11 [task 2018-11-05T20:15:12.851Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 11 == 11 [task 2018-11-05T20:15:12.852Z] 20:15:12 INFO - "Searching for: 'get MoZiLlA'" [task 2018-11-05T20:15:12.858Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.860Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.861Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.862Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.864Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"MoZiLlA","input":"get%20MoZiLlA","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.865Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"MoZiLlA\\",\\"input\\":\\"get%20MoZiLlA\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20MoZiLlA\\",\\"searchQuery\\":\\"MoZiLlA\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.867Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.868Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.870Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.871Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.873Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.874Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.876Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 22 == 22 [task 2018-11-05T20:15:12.877Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 22 == 22 [task 2018-11-05T20:15:12.879Z] 20:15:12 INFO - "Searching for: 'get mozzarella mozilla'" [task 2018-11-05T20:15:12.880Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.881Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.883Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.885Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.886Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedGETMozSearch","searchQuery":"mozzarella%20mozilla","input":"get%20mozzarella%20mozilla","alias":"get"}", "AliasedGETMozSearch"" [task 2018-11-05T20:15:12.888Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"searchQuery\\":\\"mozzarella%20mozilla\\",\\"input\\":\\"get%20mozzarella%20mozilla\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedGETMozSearch\\",\\"input\\":\\"get%20mozzarella%20mozilla\\",\\"searchQuery\\":\\"mozzarella%20mozilla\\",\\"alias\\":\\"get\\"}","comment":"AliasedGETMozSearch"}" [task 2018-11-05T20:15:12.889Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.891Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.892Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.893Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.895Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.896Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.898Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 4 == 4 [task 2018-11-05T20:15:12.899Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 4 == 4 [task 2018-11-05T20:15:12.901Z] 20:15:12 INFO - "Searching for: 'post'" [task 2018-11-05T20:15:12.902Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.903Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.905Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.906Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.908Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"","input":"post%20","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:12.909Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"\\",\\"input\\":\\"post%20\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20\\",\\"searchQuery\\":\\"\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:12.911Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.912Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.913Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.915Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.916Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.917Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.919Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 5 == 5 [task 2018-11-05T20:15:12.920Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 5 == 5 [task 2018-11-05T20:15:12.921Z] 20:15:12 INFO - "Searching for: 'post '" [task 2018-11-05T20:15:12.923Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.924Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.926Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.927Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.929Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"","input":"post%20","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:12.930Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"\\",\\"input\\":\\"post%20\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20\\",\\"searchQuery\\":\\"\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:12.932Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.933Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.935Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.936Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.938Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.939Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.940Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 9 == 9 [task 2018-11-05T20:15:12.942Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 9 == 9 [task 2018-11-05T20:15:12.943Z] 20:15:12 INFO - "Searching for: 'post fire'" [task 2018-11-05T20:15:12.945Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.946Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.947Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.949Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.953Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"fire","input":"post%20fire","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:12.955Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"fire\\",\\"input\\":\\"post%20fire\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20fire\\",\\"searchQuery\\":\\"fire\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:12.956Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.958Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.959Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.961Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.962Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.964Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.965Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 12 == 12 [task 2018-11-05T20:15:12.967Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 12 == 12 [task 2018-11-05T20:15:12.968Z] 20:15:12 INFO - "Searching for: 'post mozilla'" [task 2018-11-05T20:15:12.970Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.971Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.973Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.974Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.976Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"mozilla","input":"post%20mozilla","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:12.977Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"mozilla\\",\\"input\\":\\"post%20mozilla\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20mozilla\\",\\"searchQuery\\":\\"mozilla\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:12.979Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.980Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.982Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.983Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.984Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.986Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.987Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 12 == 12 [task 2018-11-05T20:15:12.988Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 12 == 12 [task 2018-11-05T20:15:12.989Z] 20:15:12 INFO - "Searching for: 'post MoZiLlA'" [task 2018-11-05T20:15:12.990Z] 20:15:12 INFO - "onSearchBegin received" [task 2018-11-05T20:15:12.991Z] 20:15:12 INFO - "onSearchComplete received" [task 2018-11-05T20:15:12.992Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:12.992Z] 20:15:12 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:12.993Z] 20:15:12 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"MoZiLlA","input":"post%20MoZiLlA","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:12.993Z] 20:15:12 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"MoZiLlA\\",\\"input\\":\\"post%20MoZiLlA\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20MoZiLlA\\",\\"searchQuery\\":\\"MoZiLlA\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:12.994Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:12.994Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:12.995Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:12.996Z] 20:15:12 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:12.997Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:12.998Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:12.998Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 205] Selection starts at end - 23 == 23 [task 2018-11-05T20:15:12.999Z] 20:15:12 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 206] Selection ends at the end - 23 == 23 [task 2018-11-05T20:15:13.000Z] 20:15:12 INFO - "Searching for: 'post mozzarella mozilla'" [task 2018-11-05T20:15:13.001Z] 20:15:13 INFO - "onSearchBegin received" [task 2018-11-05T20:15:13.001Z] 20:15:13 INFO - "onSearchComplete received" [task 2018-11-05T20:15:13.002Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 233] All searches started - 1 == 1 [task 2018-11-05T20:15:13.003Z] 20:15:13 INFO - "Checking first match is first autocomplete entry" [task 2018-11-05T20:15:13.004Z] 20:15:13 INFO - "First match is "moz-action:searchengine,{"engineName":"AliasedPOSTMozSearch","searchQuery":"mozzarella%20mozilla","input":"post%20mozzarella%20mozilla","alias":"post"}", "AliasedPOSTMozSearch"" [task 2018-11-05T20:15:13.005Z] 20:15:13 INFO - "Checking match: actual={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"searchQuery\\":\\"mozzarella%20mozilla\\",\\"input\\":\\"post%20mozzarella%20mozilla\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"} ... expected={"value":"moz-action:searchengine,{\\"engineName\\":\\"AliasedPOSTMozSearch\\",\\"input\\":\\"post%20mozzarella%20mozilla\\",\\"searchQuery\\":\\"mozzarella%20mozilla\\",\\"alias\\":\\"post\\"}","comment":"AliasedPOSTMozSearch"}" [task 2018-11-05T20:15:13.006Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 164] Match should have expected style - "action,alias,heuristic,searchengine" == "action,alias,heuristic,searchengine" [task 2018-11-05T20:15:13.006Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 166] moz-action results should always have 'action' in their style - true == true [task 2018-11-05T20:15:13.008Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 256] first item is correct - true == true [task 2018-11-05T20:15:13.009Z] 20:15:13 INFO - "Checking rest of the matches" [task 2018-11-05T20:15:13.009Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 289] Got as many results as expected - 1 == 1 [task 2018-11-05T20:15:13.010Z] 20:15:13 INFO - TEST-PASS | toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | getPost - [getPost : 293] 4 == 4 [task 2018-11-05T20:15:13.011Z] 20:15:13 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2) [task 2018-11-05T20:15:13.012Z] 20:15:13 INFO - (xpcshell/head.js) | test getPost finished (2) [task 2018-11-05T20:15:13.013Z] 20:15:13 INFO - toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js | Starting engineWithSuggestions [task 2018-11-05T20:15:13.013Z] 20:15:13 INFO - (xpcshell/head.js) | test engineWithSuggestions pending (2) [task 2018-11-05T20:15:13.014Z] 20:15:13 INFO - PID 9968 | !!! could not start server on port 9000: [Exception... "Component returned failure code: 0x804b0036 (NS_ERROR_SOCKET_ADDRESS_IN_USE) [nsIServerSocket.init]" nsresult: "0x804b0036 (NS_ERROR_SOCKET_ADDRESS_IN_USE)" location: "JS frame :: resource://testing-common/httpd.js :: _start :: line 542" data: no] [task 2018-11-05T20:15:13.016Z] 20:15:13 INFO - (xpcshell/head.js) | test run_next_test 3 finished (2) [task 2018-11-05T20:15:13.017Z] 20:15:13 INFO - Unexpected exception NS_ERROR_NOT_AVAILABLE: [task 2018-11-05T20:15:13.018Z] 20:15:13 INFO - _start@resource://testing-common/httpd.js:578:13 [task 2018-11-05T20:15:13.020Z] 20:15:13 INFO - start@resource://testing-common/httpd.js:502:5 [task 2018-11-05T20:15:13.021Z] 20:15:13 INFO - makeTestServer@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/places/tests/unifiedcomplete/head_autocomplete.js:454:3 [task 2018-11-05T20:15:13.022Z] 20:15:13 INFO - addTestSuggestionsEngine@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/places/tests/unifiedcomplete/head_autocomplete.js:495:16 [task 2018-11-05T20:15:13.023Z] 20:15:13 INFO - async*engineWithSuggestions@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/places/tests/unifiedcomplete/test_search_engine_alias.js:110:22 [task 2018-11-05T20:15:13.025Z] 20:15:13 INFO - async*run_next_test/_run_next_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:1442:22 [task 2018-11-05T20:15:13.026Z] 20:15:13 INFO - async*_run_next_test@/builds/worker/workspace/build/tests/xpcshell/head.js:1442:10 [task 2018-11-05T20:15:13.027Z] 20:15:13 INFO - run@/builds/worker/workspace/build/tests/xpcshell/head.js:693:9 [task 2018-11-05T20:15:13.029Z] 20:15:13 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:220:3 [task 2018-11-05T20:15:13.030Z] 20:15:13 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:534:5 [task 2018-11-05T20:15:13.032Z] 20:15:13 INFO - @-e:1:1 [task 2018-11-05T20:15:13.033Z] 20:15:13 INFO - exiting test [task 2018-11-05T20:15:13.034Z] 20:15:13 INFO - <<<<<<< [task 2018-11-05T20:15:13.036Z] 20:15:13 INFO - TEST-START | toolkit/components/reputationservice/test/unit/test_app_rep_maclinux.js [task 2018-11-05T20:15:13.679Z] 20:15:13 INFO - TEST-PASS | toolkit/components/reputationservice/test/unit/test_app_rep_maclinux.js | took 845ms [task 2018-11-05T20:15:13.687Z] 20:15:13 INFO - INFO | Result summary: [task 2018-11-05T20:15:13.688Z] 20:15:13 INFO - INFO | Passed: 374 [task 2018-11-05T20:15:13.689Z] 20:15:13 WARNING - INFO | Failed: 1 [task 2018-11-05T20:15:13.690Z] 20:15:13 WARNING - One or more unittests failed. [task 2018-11-05T20:15:13.691Z] 20:15:13 INFO - INFO | Todo: 0 [task 2018-11-05T20:15:13.692Z] 20:15:13 INFO - INFO | Retried: 3 [task 2018-11-05T20:15:13.693Z] 20:15:13 INFO - SUITE-END | took 560s [task 2018-11-05T20:15:13.694Z] 20:15:13 INFO - Node moz-http2 server shutting down ... [task 2018-11-05T20:15:13.743Z] 20:15:13 ERROR - Return code: 1 [task 2018-11-05T20:15:13.744Z] 20:15:13 INFO - TinderboxPrint: xpcshell-xpcshell<br/>374/<em class="testfail">1</em>/0 [task 2018-11-05T20:15:13.746Z] 20:15:13 WARNING - # TBPL FAILURE # [task 2018-11-05T20:15:13.746Z] 20:15:13 WARNING - setting return code to 2 [task 2018-11-05T20:15:13.747Z] 20:15:13 WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE [task 2018-11-05T20:15:13.748Z] 20:15:13 INFO - Running post-action listener: _package_coverage_data [task 2018-11-05T20:15:13.749Z] 20:15:13 INFO - Running post-action listener: _resource_record_post_action [task 2018-11-05T20:15:13.749Z] 20:15:13 INFO - Running post-action listener: process_java_coverage_data [task 2018-11-05T20:15:13.750Z] 20:15:13 INFO - [mozharness: 2018-11-05 20:15:13.749319Z] Finished run-tests step (success) [task 2018-11-05T20:15:13.750Z] 20:15:13 INFO - Running post-run listener: _resource_record_post_run [task 2018-11-05T20:15:13.838Z] 20:15:13 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json [task 2018-11-05T20:15:13.845Z] 20:15:13 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 90.82574803149605}, {"name": "io_write_bytes", "value": 13258240000}, {"name": "io.read_bytes", "value": 126427136}, {"name": "io_write_time", "value": 708740}, {"name": "io_read_time", "value": 1544}], "extraOptions": ["taskcluster-m3.large"], "name": "xpcshell.xpcshell.7.overall"}, {"subtests": [{"name": "time", "value": 75.63406705856323}, {"name": "cpu_percent", "value": 50.406}], "name": "xpcshell.xpcshell.7.install"}, {"subtests": [{"name": "time", "value": 0.029234886169433594}], "name": "xpcshell.xpcshell.7.stage-files"}, {"subtests": [{"name": "time", "value": 561.4869451522827}, {"name": "cpu_percent", "value": 96.31422182468692}], "name": "xpcshell.xpcshell.7.run-tests"}]} [task 2018-11-05T20:15:13.846Z] 20:15:13 INFO - Total resource usage - Wall time: 636s; CPU: 96.0%; Read bytes: 126427136; Write bytes: 13258240000; Read time: 1544; Write time: 708740 [task 2018-11-05T20:15:13.847Z] 20:15:13 INFO - TinderboxPrint: CPU usage<br/>96.3% [task 2018-11-05T20:15:13.848Z] 20:15:13 INFO - TinderboxPrint: I/O read bytes / time<br/>126,427,136 / 1,544 [task 2018-11-05T20:15:13.849Z] 20:15:13 INFO - TinderboxPrint: I/O write bytes / time<br/>13,258,240,000 / 708,740 [task 2018-11-05T20:15:13.849Z] 20:15:13 INFO - TinderboxPrint: CPU idle<br/>107.8 (8.5%) [task 2018-11-05T20:15:13.851Z] 20:15:13 INFO - TinderboxPrint: CPU system<br/>157.4 (12.4%) [task 2018-11-05T20:15:13.851Z] 20:15:13 INFO - TinderboxPrint: CPU user<br/>997.6 (78.6%) [task 2018-11-05T20:15:13.852Z] 20:15:13 INFO - TinderboxPrint: Swap in / out<br/>0 / 0 [task 2018-11-05T20:15:13.854Z] 20:15:13 INFO - install - Wall time: 76s; CPU: 50.0%; Read bytes: 0; Write bytes: 1837408256; Read time: 0; Write time: 238400 [task 2018-11-05T20:15:13.854Z] 20:15:13 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 [task 2018-11-05T20:15:13.859Z] 20:15:13 INFO - run-tests - Wall time: 561s; CPU: 96.0%; Read bytes: 126427136; Write bytes: 11420831744; Read time: 1544; Write time: 470340 [task 2018-11-05T20:15:14.027Z] 20:15:14 WARNING - returning nonzero exit status 2 [task 2018-11-05T20:15:14.048Z] cleanup [task 2018-11-05T20:15:14.048Z] + cleanup [task 2018-11-05T20:15:14.048Z] + local rv=2 [task 2018-11-05T20:15:14.048Z] + [[ -s /builds/worker/.xsession-errors ]] [task 2018-11-05T20:15:14.049Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log [task 2018-11-05T20:15:14.053Z] + true [task 2018-11-05T20:15:14.053Z] + cleanup_xvfb [task 2018-11-05T20:15:14.054Z] pidof Xvfb [task 2018-11-05T20:15:14.055Z] ++ pidof Xvfb [task 2018-11-05T20:15:14.059Z] + local xvfb_pid=25 [task 2018-11-05T20:15:14.059Z] + local vnc=false [task 2018-11-05T20:15:14.059Z] + local interactive=false [task 2018-11-05T20:15:14.064Z] + '[' -n 25 ']' [task 2018-11-05T20:15:14.065Z] + [[ false == false ]] [task 2018-11-05T20:15:14.092Z] + [[ false == false ]] [task 2018-11-05T20:15:14.092Z] + kill 25 [task 2018-11-05T20:15:14.093Z] + screen -XS xvfb quit [task 2018-11-05T20:15:14.096Z] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" [task 2018-11-05T20:15:14.097Z] after 847 requests (847 known processed) with 1 events remaining. [task 2018-11-05T20:15:14.098Z] compizconfig - Info: Backend : ini [task 2018-11-05T20:15:14.098Z] compizconfig - Info: Integration : true [task 2018-11-05T20:15:14.099Z] compizconfig - Info: Profile : default [task 2018-11-05T20:15:14.290Z] No screen session found. [task 2018-11-05T20:15:14.291Z] + true [task 2018-11-05T20:15:14.291Z] + exit 2 [taskcluster 2018-11-05 20:15:14.603Z] === Task Finished === [taskcluster 2018-11-05 20:15:20.920Z] Unsuccessful task run with exit code: 2 completed in 980.929 seconds
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.