Closed Bug 1534013 Opened 5 years ago Closed 5 years ago

Perma tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0 when Gecko 67 merges to beta on 2019-03-11

Categories

(Core :: Gecko Profiler, defect, P2)

defect

Tracking

()

VERIFIED FIXED
mozilla67
Tracking Status
firefox-esr60 --- unaffected
firefox65 --- unaffected
firefox66 --- unaffected
firefox67 + verified

People

(Reporter: intermittent-bug-filer, Assigned: gregtatum)

References

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

#[markdown(off)]
Filed by: dluca [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=232910928&repo=try

https://queue.taskcluster.net/v1/task/MANpNNSsTei5H2pTy-UGbA/runs/0/artifacts/public/logs/live_backing.log

INFO - TEST-START | toolkit/components/url-classifier/tests/unit/test_listmanager.js
[task 2019-03-09T14:48:57.361Z] 14:48:57 INFO - TEST-PASS | toolkit/components/url-classifier/tests/unit/test_listmanager.js | took 1289ms
[task 2019-03-09T14:48:57.377Z] 14:48:57 INFO - TEST-START | tools/profiler/tests/test_feature_mainthreadio.js
[task 2019-03-09T14:48:59.963Z] 14:48:59 WARNING - TEST-UNEXPECTED-FAIL | tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0
[task 2019-03-09T14:48:59.964Z] 14:48:59 INFO - TEST-INFO took 2592ms
[task 2019-03-09T14:48:59.964Z] 14:48:59 INFO - >>>>>>>
[task 2019-03-09T14:48:59.964Z] 14:48:59 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-03-09T14:48:59.966Z] 14:48:59 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-03-09T14:48:59.966Z] 14:48:59 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-03-09T14:48:59.967Z] 14:48:59 INFO - running event loop
[task 2019-03-09T14:48:59.968Z] 14:48:59 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2019-03-09T14:48:59.968Z] 14:48:59 INFO - tools/profiler/tests/test_feature_mainthreadio.js | Starting
[task 2019-03-09T14:48:59.973Z] 14:48:59 INFO - (xpcshell/head.js) | test pending (2)
[task 2019-03-09T14:48:59.974Z] 14:48:59 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2019-03-09T14:48:59.974Z] 14:48:59 WARNING - TEST-UNEXPECTED-FAIL | tools/profiler/tests/test_feature_mainthreadio.js | - FileIO markers were found when using the mainthreadio feature on the profiler. - 0 > 0
[task 2019-03-09T14:48:59.975Z] 14:48:59 INFO - /builds/worker/workspace/build/tests/xpcshell/tests/tools/profiler/tests/test_feature_mainthreadio.js:null:23
[task 2019-03-09T14:48:59.975Z] 14:48:59 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:224
[task 2019-03-09T14:48:59.975Z] 14:48:59 INFO - /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:526
[task 2019-03-09T14:48:59.976Z] 14:48:59 INFO - -e:null:1
[task 2019-03-09T14:48:59.976Z] 14:48:59 INFO - exiting test
[task 2019-03-09T14:48:59.976Z] 14:48:59 INFO - Unexpected exception NS_ERROR_ABORT:
[task 2019-03-09T14:48:59.976Z] 14:48:59 INFO - _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:739:20
[task 2019-03-09T14:48:59.977Z] 14:48:59 INFO - do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:846:5
[task 2019-03-09T14:48:59.978Z] 14:48:59 INFO - Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:54:5
[task 2019-03-09T14:48:59.978Z] 14:48:59 INFO - proto.report@resource://testing-common/Assert.jsm:213:10
[task 2019-03-09T14:48:59.978Z] 14:48:59 INFO - compareNumbers@resource://testing-common/Assert.jsm:443:10
[task 2019-03-09T14:48:59.979Z] 14:48:59 INFO - greater@resource://testing-common/Assert.jsm:468:18
[task 2019-03-09T14:48:59.979Z] 14:48:59 INFO - @/builds/worker/workspace/build/tests/xpcshell/tests/tools/profiler/tests/test_feature_mainthreadio.js:23:5
[task 2019-03-09T14:48:59.979Z] 14:48:59 INFO - _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:224:6
[task 2019-03-09T14:48:59.980Z] 14:48:59 INFO - _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:526:5
[task 2019-03-09T14:48:59.980Z] 14:48:59 INFO - @-e:1:1
[task 2019-03-09T14:48:59.980Z] 14:48:59 INFO - exiting test
[task 2019-03-09T14:48:59.980Z] 14:48:59 INFO - <<<<<<<
[task 2019-03-09T14:48:59.983Z] 14:48:59 INFO - INFO | Result summary:
[task 2019-03-09T14:48:59.984Z] 14:48:59 INFO - INFO | Passed: 394
[task 2019-03-09T14:48:59.984Z] 14:48:59 WARNING - INFO | Failed: 1
[task 2019-03-09T14:48:59.984Z] 14:48:59 WARNING - One or more unittests failed.
[task 2019-03-09T14:48:59.984Z] 14:48:59 INFO - INFO | Todo: 0
[task 2019-03-09T14:48:59.984Z] 14:48:59 INFO - INFO | Retried: 2
[task 2019-03-09T14:48:59.984Z] 14:48:59 INFO - SUITE-END | took 191s
[task 2019-03-09T14:48:59.984Z] 14:48:59 INFO - Node moz-http2 server shutting down ...
[task 2019-03-09T14:49:00.051Z] 14:49:00 ERROR - Return code: 1
[task 2019-03-09T14:49:00.052Z] 14:49:00 INFO - TinderboxPrint: xpcshell-xpcshell<br/>394/<em class="testfail">1</em>/0
[task 2019-03-09T14:49:00.052Z] 14:49:00 WARNING - # TBPL FAILURE #
[task 2019-03-09T14:49:00.052Z] 14:49:00 WARNING - setting return code to 2
[task 2019-03-09T14:49:00.053Z] 14:49:00 WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE
[task 2019-03-09T14:49:00.054Z] 14:49:00 INFO - Running post-action listener: _package_coverage_data
[task 2019-03-09T14:49:00.054Z] 14:49:00 INFO - Running post-action listener: _resource_record_post_action
[task 2019-03-09T14:49:00.055Z] 14:49:00 INFO - Running post-action listener: process_java_coverage_data
[task 2019-03-09T14:49:00.055Z] 14:49:00 INFO - [mozharness: 2019-03-09 14:49:00.053122Z] Finished run-tests step (success)
[task 2019-03-09T14:49:00.055Z] 14:49:00 INFO - Running post-run listener: _resource_record_post_run
[task 2019-03-09T14:49:00.117Z] 14:49:00 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2019-03-09T14:49:00.124Z] 14:49:00 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 93.27666666666666}, {"name": "io_write_bytes", "value": 1510416384}, {"name": "io.read_bytes", "value": 120446976}, {"name": "io_write_time", "value": 76048}, {"name": "io_read_time", "value": 2452}], "extraOptions": ["taskcluster-m3.large"], "name": "xpcshell.xpcshell.8.overall"}, {"subtests": [{"name": "time", "value": 17.92993688583374}, {"name": "cpu_percent", "value": 50.48823529411764}], "name": "xpcshell.xpcshell.8.install"}, {"subtests": [{"name": "time", "value": 0.02092909812927246}], "name": "xpcshell.xpcshell.8.stage-files"}, {"subtests": [{"name": "time", "value": 192.8903729915619}, {"name": "cpu_percent", "value": 97.28229166666667}], "name": "xpcshell.xpcshell.8.run-tests"}]}
[task 2019-03-09T14:49:00.125Z] 14:49:00 INFO - Total resource usage - Wall time: 210s; CPU: 97.0%; Read bytes: 120446976; Write bytes: 1510416384; Read time: 2452; Write time: 76048
[task 2019-03-09T14:49:00.126Z] 14:49:00 INFO - TinderboxPrint: CPU usage<br/>97.3%
[task 2019-03-09T14:49:00.126Z] 14:49:00 INFO - TinderboxPrint: I/O read bytes / time<br/>120,446,976 / 2,452
[task 2019-03-09T14:49:00.127Z] 14:49:00 INFO - TinderboxPrint: I/O write bytes / time<br/>1,510,416,384 / 76,048
[task 2019-03-09T14:49:00.128Z] 14:49:00 INFO - TinderboxPrint: CPU idle<br/>28.0 (6.7%)
[task 2019-03-09T14:49:00.129Z] 14:49:00 INFO - TinderboxPrint: CPU system<br/>90.8 (21.6%)
[task 2019-03-09T14:49:00.129Z] 14:49:00 INFO - TinderboxPrint: CPU user<br/>301.4 (71.7%)
[task 2019-03-09T14:49:00.130Z] 14:49:00 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2019-03-09T14:49:00.130Z] 14:49:00 INFO - install - Wall time: 18s; CPU: 50.0%; Read bytes: 0; Write bytes: 11005952; Read time: 0; Write time: 1640
[task 2019-03-09T14:49:00.131Z] 14:49:00 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2019-03-09T14:49:00.133Z] 14:49:00 INFO - run-tests - Wall time: 193s; CPU: 97.0%; Read bytes: 120446976; Write bytes: 1497952256; Read time: 2452; Write time: 74088
[task 2019-03-09T14:49:00.187Z] 14:49:00 WARNING - returning nonzero exit status 2
[task 2019-03-09T14:49:00.212Z] cleanup
[task 2019-03-09T14:49:00.212Z] + cleanup
[task 2019-03-09T14:49:00.213Z] + local rv=2
[task 2019-03-09T14:49:00.213Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2019-03-09T14:49:00.213Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2019-03-09T14:49:00.217Z] + true
[task 2019-03-09T14:49:00.218Z] + cleanup_xvfb
[task 2019-03-09T14:49:00.219Z] pidof Xvfb
[task 2019-03-09T14:49:00.219Z] ++ pidof Xvfb
[task 2019-03-09T14:49:00.225Z] + local xvfb_pid=25
[task 2019-03-09T14:49:00.225Z] + local vnc=false
[task 2019-03-09T14:49:00.228Z] + local interactive=false
[task 2019-03-09T14:49:00.229Z] + '[' -n 25 ']'
[task 2019-03-09T14:49:00.230Z] + [[ false == false ]]
[task 2019-03-09T14:49:00.230Z] + [[ false == false ]]
[task 2019-03-09T14:49:00.230Z] + kill 25
[task 2019-03-09T14:49:00.230Z] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
[task 2019-03-09T14:49:00.230Z] after 4916 requests (4916 known processed) with 1 events remaining.
[task 2019-03-09T14:49:00.230Z] + screen -XS xvfb quit
[task 2019-03-09T14:49:00.232Z] compizconfig - Info: Backend : ini
[task 2019-03-09T14:49:00.232Z] compizconfig - Info: Integration : true
[task 2019-03-09T14:49:00.232Z] compizconfig - Info: Profile : default
[task 2019-03-09T14:49:00.480Z] No screen session found.
[task 2019-03-09T14:49:00.481Z] + true
[task 2019-03-09T14:49:00.481Z] + exit 2
[taskcluster 2019-03-09 14:49:01.065Z] === Task Finished ===
[taskcluster 2019-03-09 14:49:04.335Z] Unsuccessful task run with exit code: 2 completed in 512.863 seconds

Summary: Intermittent tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0 when Gecko 67 merges to beta on 2019-03-11 → tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0 when Gecko 67 merges to beta on 2019-03-11
Blocks: 1527737
Flags: needinfo?(gtatum)
Summary: tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0 when Gecko 67 merges to beta on 2019-03-11 → Perma tools/profiler/tests/test_feature_mainthreadio.js | xpcshell return code: 0 when Gecko 67 merges to beta on 2019-03-11

Changing the priority to p2 as the bug is tracked by a release manager for the current nightly.
See How Do You Triage for more information

Priority: P5 → P2
Assignee: nobody → gtatum
Flags: needinfo?(gtatum)

I initially forgot that this test should only be run on nightly, as the
interposer is only enabled on nightly.

I have an r+ patch that should fix this, but I'm not sure on the procedure here. My understanding is that this test is perma-failing on beta. Is there anything special I need to do?

Flags: needinfo?(aryx.bugmail)

Just land it normally on central, that gets merged to beta until next Monday, if everything works well daily.

Flags: needinfo?(aryx.bugmail)
Pushed by gtatum@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3cb869d04118
Only run profiler's mainthreadio feature test on nightly; r=canaltinova
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: