Closed Bug 1632194 Opened 5 years ago Closed 4 years ago

Intermittent raptor-perftest Critical: [chrome] Process has been unexpectedly closed

Categories

(Testing :: Raptor, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

This is about a crash of Chrome, and in the above case it is version 80.0.3987.106.

This clearly looks to be a startup crash of Chrome:

[task 2020-04-24T12:18:59.123Z] 12:18:59 INFO - Application command: /usr/bin/google-chrome --allow-downgrade --user-data-dir=/tmp/tmpZqMWDF.mozrunner --profile-directory=Default --no-first-run --use-mock-keychain --no-default-browser-check --proxy-server=127.0.0.1:36654 --proxy-bypass-list=localhost;127.0.0.1 --ignore-certificate-errors --load-extension=/home/cltbld/tasks/task_1587730604/build/tests/raptor/raptor/webextension/../../webext/raptor
[task 2020-04-24T12:19:00.129Z] 12:19:00 CRITICAL - raptor-perftest Critical: Process has been unexpectedly closed

In the last 7 days there have been 24 occurrences on windows10-64 opt and linux64-shippable opt.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=301489549&repo=mozilla-central&lineNumber=977

...
task 2020-05-09T01:41:05.670Z] 01:41:05     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] Response: pageloadjs-ready-response"
[task 2020-05-09T01:41:05.912Z] 01:41:05     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:06.172Z] 01:41:06     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:06.415Z] 01:41:06     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:06.668Z] 01:41:06     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:06.928Z] 01:41:06     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:07.170Z] 01:41:07     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:07.431Z] 01:41:07     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:07.670Z] 01:41:07     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:07.931Z] 01:41:07     INFO -  PID 4748 | console.info: "[raptor-runnerjs] results pending..."
[task 2020-05-09T01:41:08.033Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] will be measuring fnbpaint"
[task 2020-05-09T01:41:08.033Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] got fnbpaint"
[task 2020-05-09T01:41:08.034Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] sending result back to runner: fnbpaint 9656"
[task 2020-05-09T01:41:08.034Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] will be measuring dcf"
[task 2020-05-09T01:41:08.034Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] got domContentFlushed: 1588988454013"
[task 2020-05-09T01:41:08.034Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] sending result back to runner: dcf 10999"
[task 2020-05-09T01:41:08.035Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] will be measuring first-contentful-paint"
[task 2020-05-09T01:41:08.035Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] got time to first-contentful-paint"
[task 2020-05-09T01:41:08.035Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] sending result back to runner: fcp 11112"
[task 2020-05-09T01:41:08.035Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] received message from https://www.netflix.com/title/80117263"
[task 2020-05-09T01:41:08.035Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] result: fnbpaint 9656"
[task 2020-05-09T01:41:08.036Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] will be measuring loadtime"
[task 2020-05-09T01:41:08.036Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] got loadEventStart: 1588988465621"
[task 2020-05-09T01:41:08.036Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] sending result back to runner: loadtime 22607"
[task 2020-05-09T01:41:08.036Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] received message from https://www.netflix.com/title/80117263"
[task 2020-05-09T01:41:08.037Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] result: dcf 10999"
[task 2020-05-09T01:41:08.037Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] Response: confirmed fnbpaint"
[task 2020-05-09T01:41:08.037Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] Response: confirmed dcf"
[task 2020-05-09T01:41:08.039Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] received message from https://www.netflix.com/title/80117263"
[task 2020-05-09T01:41:08.039Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] result: fcp 11112"
[task 2020-05-09T01:41:08.039Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] Response: confirmed fcp"
[task 2020-05-09T01:41:08.039Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] received message from https://www.netflix.com/title/80117263"
[task 2020-05-09T01:41:08.039Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] result: loadtime 22607"
[task 2020-05-09T01:41:08.042Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-pageloadjs] Response: confirmed loadtime"
[task 2020-05-09T01:41:08.183Z] 01:41:08     INFO -  raptor-control-server Info: received webext_status: results received
[task 2020-05-09T01:41:08.183Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] cancelled raptor alarm raptor-page-timeout"
[task 2020-05-09T01:41:08.183Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] Verifying results:"
[task 2020-05-09T01:41:08.184Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] [object Object]"
[task 2020-05-09T01:41:08.184Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] have 1 results for fnbpaint, as expected"
[task 2020-05-09T01:41:08.184Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] have 1 results for dcf, as expected"
[task 2020-05-09T01:41:08.184Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] have 1 results for fcp, as expected"
[task 2020-05-09T01:41:08.184Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] have 1 results for loadtime, as expected"
[task 2020-05-09T01:41:08.185Z] 01:41:08     INFO -  raptor-control-server Info: received webext_results: {u'expected_browser_cycles': 25, u'subtest_unit': u'ms', u'name': u'raptor-tp6-netflix-firefox-cold', u'lower_is_better': True, u'measurements': {u'dcf': [10999], u'fcp': [11112], u'fnbpaint': [9656], u'loadtime': [22607]}, u'browser_cycle': u'2', u'subtest_lower_is_better': True, u'cold': True, u'browser': u'Firefox 78.0a1 20200508215459', u'type': u'pageload', u'page': u'https://www.netflix.com/title/80117263', u'unit': u'ms', u'alert_threshold': 2}
[task 2020-05-09T01:41:08.185Z] 01:41:08     INFO -  perftest-results-handler Info: received results in RaptorResultsHandler.add
[task 2020-05-09T01:41:08.195Z] 01:41:08     INFO -  raptor-control-server Info: received webext_status: closing Tab: 2
[task 2020-05-09T01:41:08.254Z] 01:41:08     INFO -  raptor-control-server Info: received webext_status: closed tab: 2
[task 2020-05-09T01:41:08.264Z] 01:41:08     INFO -  PID 4748 | console.info: "[raptor-runnerjs] pageload test finished"
[task 2020-05-09T01:41:08.264Z] 01:41:08     INFO -  raptor-control-server Info: received request to shutdown the browser
[task 2020-05-09T01:41:08.264Z] 01:41:08     INFO -  raptor-control-server Info: shutting down browser (pid: 4748)
[task 2020-05-09T01:41:11.190Z] 01:41:11 CRITICAL -  raptor-perftest Critical: Test failed to finish. Application timed out after 141 seconds
[task 2020-05-09T01:41:11.190Z] 01:41:11     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 6096
[task 2020-05-09T01:41:11.191Z] 01:41:11     INFO -  raptor-mitmproxy Info: Sending CTRL_BREAK_EVENT to mitmproxy
[task 2020-05-09T01:41:13.774Z] 01:41:13     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process with exit code 572
[task 2020-05-09T01:41:13.774Z] 01:41:13     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2020-05-09T01:41:13.774Z] 01:41:13     INFO -  raptor-mitmproxy Info: writing: C:\Users\task_1588986021\build\application\firefox\distribution\policies.json
[task 2020-05-09T01:41:13.855Z] 01:41:13     INFO -  raptor-mitmproxy Info: Reading confidence values from: C:\Users\task_1588986021\build\blobber_upload_dir\mitm_netlocs_netflix.json
[task 2020-05-09T01:41:13.857Z] 01:41:13     INFO -  perftest-results-handler Info: RaptorResultsHandler.add_supporting_data received mozproxy data
[task 2020-05-09T01:41:13.857Z] 01:41:13     INFO -  raptor-webext Info: removing webext C:\Users\task_1588986021\build\tests\raptor\raptor\webextension\..\..\webext\raptor
[task 2020-05-09T01:41:13.859Z] 01:41:13     INFO -  raptor-perftest Info: Removing temporary directory: c:\users\task_1588986021\appdata\local\temp\tmpeupyac
[task 2020-05-09T01:41:32.601Z] 01:41:32     INFO -  raptor-perftest Info: Removing temporary directory: c:\users\task_1588986021\appdata\local\temp\tmpawcbut
[task 2020-05-09T01:41:39.861Z] 01:41:39     INFO -  raptor-control-server Info: shutting down control server
[task 2020-05-09T01:41:39.925Z] 01:41:39     INFO -  raptor-webext Info: finished
[task 2020-05-09T01:41:40.043Z] 01:41:40    ERROR - Return code: 1
[task 2020-05-09T01:41:40.043Z] 01:41:40  WARNING - setting return code to 1

There are many Firefox failures that keep getting classified as a chrome failure in this bug. For anyone that comes looking for where the Firefox failures should be classified, they should be classified as this bug: https://bugzilla.mozilla.org/show_bug.cgi?id=1609295

In the last 7 days there have been 28 occurrences linux64-shippable and windows10-64-shippable opt.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=310202714&repo=mozilla-central&lineNumber=1669

:davehunt, can we find someone to update desktop chrome? That should help for this failure.

Flags: needinfo?(dave.hunt)

Ah misclassifications made it seem like chrome was becoming problematic, nevermind.

Flags: needinfo?(dave.hunt)

In the last 7 days there have been 21 occurrences, most on linux64-shippable opt, some on windows (windows10-64 and windows-7-32) opt.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=313006157&repo=mozilla-central&lineNumber=1051

Sparky, could you, please, take a look?

Flags: needinfo?(gmierz2)
Whiteboard: [stockwell needswork:owner]

It was likely a bad chromium update that caused that rise in failures which seems to have resolved itself (daily update). We'll be update chrome soon so that should help with those failures.

That said, I'm going to look into getting this dropped to a tier 3 test.

Flags: needinfo?(gmierz2)
Summary: Intermittent Chrome raptor-perftest Critical: Process has been unexpectedly closed → Intermittent raptor-perftest Critical: [chrome] Process has been unexpectedly closed
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.