1281984 - Intermittent devtools/client/performance/test/browser_perf-loading-02.js | application timed out after 330 seconds with no output

Status: RESOLVED WONTFIX

(DevTools :: Performance Tools (Profiler/Timeline), defect, P3)

Description

[Alison Shiue]

https://treeherder.mozilla.org/logviewer.html#?job_id=30523788&repo=mozilla-inbound#L1621

09:43:01     INFO -  62 INFO TEST-START | devtools/client/performance/test/browser_perf-loading-02.js
09:43:01     INFO -  Adding tab with url: http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#4284594671783170.
09:43:01     INFO -  Tab added and finished loading: http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#4284594671783170.
09:43:01     INFO -  Initializing a performance panel.
09:43:03     INFO -  Waiting for event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] for 1 time(s).
09:43:03     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-started"}.
09:43:03     INFO -  Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: {"1":{}}.
09:43:03     INFO -  Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: {"1":100}.
09:43:04     INFO -  Event: 'Performance:UI:StateChanged' on [object PerformanceView] received.
09:43:04     INFO -  Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
09:43:04     INFO -  Event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] received.
09:43:05     INFO -  Event: 'Performance:UI:OverviewRendered' on [object OverviewView] received.
09:43:05     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-stopping"}.
09:43:05     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-stopped"}.
09:43:05     INFO -  Waiting for event: 'Performance:BackendReadyRecordingStop' on [object PerformanceController] for 1 time(s).
09:43:05     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-stopping"}.
09:43:05     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-stopped"}.
09:43:05     INFO -  Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: {"1":"recorded"}.
09:43:05     INFO -  Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: {"1":16}.
09:43:05     INFO -  Waiting for event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] for 1 time(s).
09:43:05     INFO -  Ignoring event 'Performance:UI:StateChanged' with unexpected argument at index 1: loading
09:43:05     INFO -  Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
09:43:05     INFO -  Ignoring event 'Performance:RecordingStateChange' with unexpected argument at index 1: recording-stopping
09:43:05     INFO -  Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
09:43:05     INFO -  Ignoring event 'Performance:RecordingStateChange' with unexpected argument at index 1: recording-stopping
09:43:06     INFO -  Event: 'Performance:UI:StateChanged' on [object PerformanceView] received.
09:43:06     INFO -  Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
09:43:06     INFO -  Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
09:43:10     INFO -  Event: 'Performance:UI:WaterfallRendered' on [object WaterfallView] received.
09:43:10     INFO -  Event: 'Performance:BackendReadyRecordingStop' on [object PerformanceController] received.
09:43:11     INFO -  Event: 'Performance:UI:OverviewRendered' on [object OverviewView] received.
09:43:11     INFO -  Waiting for event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] for 1 time(s).
09:43:11     INFO -  Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: {"1":"recording-started"}.
09:43:11     INFO -  Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: {"1":{}}.
09:43:11     INFO -  Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: {"1":100}.
09:48:41     INFO -  63 INFO checking window state
09:48:41     INFO -  64 INFO Entering test bound
09:48:41     INFO -  65 INFO TEST-PASS | devtools/client/performance/test/browser_perf-loading-02.js | The recording-notice is shown while recording. -
09:48:41     INFO -  66 INFO TEST-PASS | devtools/client/performance/test/browser_perf-loading-02.js | The loading-notice is shown while the record is stopping. -
09:48:41     INFO -  67 INFO TEST-PASS | devtools/client/performance/test/browser_perf-loading-02.js | The details panel is shown after the record has stopped. -
09:48:41  WARNING -  TEST-UNEXPECTED-TIMEOUT | devtools/client/performance/test/browser_perf-loading-02.js | application timed out after 330 seconds with no output
09:48:41     INFO -  68 ERROR Force-terminating active process(es).
09:48:41     INFO -  Determining child pids from psutil
09:48:41     INFO -  Found child pids: [1312]
09:48:41     INFO -  Killing process: 1312
09:48:41     INFO -  TEST-INFO | started process screentopng
09:48:41     INFO -  TEST-INFO | screentopng: exit 0
09:49:11     INFO -  failed to kill pid 1312 after 30s
09:49:11     INFO -  Killing process: 1246
09:49:11     INFO -  Not taking screenshot here: see the one that was previously logged
09:49:12     INFO -  TEST-INFO | Main app process: exit 6
09:49:12  WARNING -  TEST-UNEXPECTED-FAIL | devtools/client/performance/test/browser_perf-loading-02.js | application terminated with exit code 6
09:49:12     INFO -  runtests.py | Application ran for: 0:13:54.693653
09:49:12     INFO -  zombiecheck | Reading PID log: /tmp/tmpFcGJogpidlog
09:49:12     INFO -  ==> process 1246 launched child process 1312
09:49:12     INFO -  zombiecheck | Checking for orphan process with PID: 1312
09:49:12     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/SZ9LN62XQzGiANfvgoUQcg/artifacts/public/build/target.crashreporter-symbols.zip
09:49:24     INFO -  mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmp9bDT3K.mozrunner/minidumps/3bab88d0-472b-96d0-155dfdd2-64102153.dmp /tmp/tmpIJcElf
09:49:35     INFO -  mozcrash Saved minidump as /home/worker/workspace/build/blobber_upload_dir/3bab88d0-472b-96d0-155dfdd2-64102153.dmp
09:49:35     INFO -  mozcrash Saved app info as /home/worker/workspace/build/blobber_upload_dir/3bab88d0-472b-96d0-155dfdd2-64102153.extra
09:49:35  WARNING -  PROCESS-CRASH | devtools/client/performance/test/browser_perf-loading-02.js | application crashed [@ libpthread-2.15.so + 0xbd84]
09:49:35     INFO -  Crash dump filename: /tmp/tmp9bDT3K.mozrunner/minidumps/3bab88d0-472b-96d0-155dfdd2-64102153.dmp

Comment 1

[Julien Wajsberg [:julienw]]

These tests are being removed in Bug 1668219. Of course we might still see intermittents in beta / release for some time.

Filter on MASSCLOSEOLDPERFTOOLBUGS.