Closed Bug 1494566 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | netwerk/test/unit_ipc/test_dns_cancel_wrap.js | Test timed out

Categories

(Core :: Networking, defect, P3)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, Whiteboard: [necko-triaged])

Filed by: ebalazs [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=201850047&repo=mozilla-central https://queue.taskcluster.net/v1/task/Wk4kS25mRuqr6NnolQJGZg/runs/0/artifacts/public/logs/live_backing.log TEST-START | netwerk/test/unit_ipc/test_dns_cancel_wrap.js [task 2018-09-27T04:16:24.092Z] 04:16:24 WARNING - TEST-UNEXPECTED-TIMEOUT | netwerk/test/unit_ipc/test_dns_cancel_wrap.js | Test timed out [task 2018-09-27T04:16:24.095Z] 04:16:24 INFO - TEST-INFO took 300000ms [task 2018-09-27T04:16:24.096Z] 04:16:24 INFO - >>>>>>> [task 2018-09-27T04:16:24.098Z] 04:16:24 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) [task 2018-09-27T04:16:24.099Z] 04:16:24 INFO - (xpcshell/head.js) | test run in child pending (2) [task 2018-09-27T04:16:24.100Z] 04:16:24 INFO - (xpcshell/head.js) | test MAIN run_test finished (2) [task 2018-09-27T04:16:24.100Z] 04:16:24 INFO - running event loop [task 2018-09-27T04:16:24.101Z] 04:16:24 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties" [task 2018-09-27T04:16:24.103Z] 04:16:24 INFO - CHILD-TEST-STARTED [task 2018-09-27T04:16:24.104Z] 04:16:24 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) [task 2018-09-27T04:16:24.106Z] 04:16:24 INFO - (xpcshell/head.js) | test pending (2) [task 2018-09-27T04:16:24.106Z] 04:16:24 INFO - (xpcshell/head.js) | test pending (3) [task 2018-09-27T04:16:24.107Z] 04:16:24 INFO - (xpcshell/head.js) | test MAIN run_test finished (3) [task 2018-09-27T04:16:24.107Z] 04:16:24 INFO - running event loop [task 2018-09-27T04:16:24.108Z] 04:16:24 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "/builds/worker/workspace/build/tests/xpcshell/head.js" line: 345}]" [task 2018-09-27T04:16:24.109Z] 04:16:24 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "/builds/worker/workspace/build/tests/xpcshell/head.js" line: 345}]" [task 2018-09-27T04:16:24.113Z] 04:16:24 INFO - TEST-PASS | netwerk/test/unit_ipc/test_dns_cancel_wrap.js | onLookupComplete - [onLookupComplete : 24] 2152398878 != 2147500036 [task 2018-09-27T04:16:24.115Z] 04:16:24 INFO - (xpcshell/head.js) | test finished (2) [task 2018-09-27T04:16:24.116Z] 04:16:24 INFO - TEST-PASS | netwerk/test/unit_ipc/test_dns_cancel_wrap.js | onLookupComplete - [onLookupComplete : 43] 2152398878 != 2147500036 [task 2018-09-27T04:16:24.119Z] 04:16:24 INFO - (xpcshell/head.js) | test finished (1) [task 2018-09-27T04:16:24.123Z] 04:16:24 INFO - exiting test [task 2018-09-27T04:16:24.124Z] 04:16:24 INFO - PID 2939 | Collecting coverage for: /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit/test_dns_cancel.js [task 2018-09-27T04:16:24.125Z] 04:16:24 INFO - PID 2939 | Writing coverage to: /builds/worker/workspace/build/blobber_upload_dir/jscov_1538021484563.json [task 2018-09-27T04:16:24.126Z] 04:16:24 INFO - CHILD-TEST-COMPLETED [task 2018-09-27T04:16:24.126Z] 04:16:24 INFO - (xpcshell/head.js) | test finished (1) [task 2018-09-27T04:16:24.127Z] 04:16:24 INFO - exiting test [task 2018-09-27T04:16:24.128Z] 04:16:24 INFO - PID 2939 | Collecting coverage for: /builds/worker/workspace/build/tests/xpcshell/tests/netwerk/test/unit_ipc/test_dns_cancel_wrap.js [task 2018-09-27T04:16:24.129Z] 04:16:24 INFO - PID 2939 | Writing coverage to: /builds/worker/workspace/build/blobber_upload_dir/jscov_1538021484608.json [task 2018-09-27T04:16:24.130Z] 04:16:24 INFO - PID 2939 | JavaScript strict warning: resource://gre/modules/PlacesDBUtils.jsm, line 117: ReferenceError: reference to undefined property "status" [task 2018-09-27T04:16:24.131Z] 04:16:24 INFO - <<<<<<< [task 2018-09-27T04:16:24.132Z] 04:16:24 INFO - xpcshell return code: None [task 2018-09-27T04:16:24.133Z] 04:16:24 INFO - netwerk/test/unit_ipc/test_dns_cancel_wrap.js | Process still running after test! [task 2018-09-27T04:16:24.134Z] 04:16:24 INFO - >>>>>>> [task 2018-09-27T04:16:24.135Z] 04:16:24 INFO - PID 2939 | ExceptionHandler::GenerateDump cloned child 2984 [task 2018-09-27T04:16:24.135Z] 04:16:24 INFO - PID 2939 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child [task 2018-09-27T04:16:24.136Z] 04:16:24 INFO - PID 2939 | ExceptionHandler::WaitForContinueSignal waiting for continue signal... [task 2018-09-27T04:16:24.136Z] 04:16:24 INFO - <<<<<<< [task 2018-09-27T04:16:24.136Z] 04:16:24 WARNING - TEST-UNEXPECTED-FAIL | Received SIGINT (control-C), so stopped run. (Use --keep-going to keep running tests after killing one with SIGINT) [task 2018-09-27T04:16:24.137Z] 04:16:24 INFO - INFO | Result summary: [task 2018-09-27T04:16:24.137Z] 04:16:24 INFO - INFO | Passed: 66 [task 2018-09-27T04:16:24.137Z] 04:16:24 WARNING - INFO | Failed: 1 [task 2018-09-27T04:16:24.138Z] 04:16:24 WARNING - One or more unittests failed. [task 2018-09-27T04:16:24.138Z] 04:16:24 INFO - INFO | Todo: 0 [task 2018-09-27T04:16:24.139Z] 04:16:24 INFO - INFO | Retried: 0 [task 2018-09-27T04:16:24.140Z] 04:16:24 INFO - SUITE-END | took 346s [task 2018-09-27T04:16:24.140Z] 04:16:24 INFO - Node moz-http2 server shutting down ... [task 2018-09-27T04:16:24.223Z] 04:16:24 ERROR - Return code: 1 [task 2018-09-27T04:16:24.225Z] 04:16:24 INFO - TinderboxPrint: xpcshell-xpcshell-coverage<br/>66/<em class="testfail">1</em>/0 [task 2018-09-27T04:16:24.225Z] 04:16:24 WARNING - # TBPL FAILURE # [task 2018-09-27T04:16:24.225Z] 04:16:24 WARNING - setting return code to 2 [task 2018-09-27T04:16:24.226Z] 04:16:24 WARNING - The xpcshell suite: xpcshell-coverage ran with return status: FAILURE [task 2018-09-27T04:16:24.227Z] 04:16:24 INFO - Running post-action listener: _package_coverage_data [task 2018-09-27T04:16:24.228Z] 04:16:24 INFO - Beginning compression of JSDCov artifacts... [task 2018-09-27T04:16:24.280Z] 04:16:24 INFO - Completed compression of JSDCov artifacts! [task 2018-09-27T04:16:24.281Z] 04:16:24 INFO - Path to JSDCov compressed artifacts: /builds/worker/workspace/build/blobber_upload_dir/jsdcov_artifacts.zip [task 2018-09-27T04:16:24.281Z] 04:16:24 INFO - Running post-action listener: _resource_record_post_action [task 2018-09-27T04:16:24.282Z] 04:16:24 INFO - Running post-action listener: process_java_coverage_data [task 2018-09-27T04:16:24.283Z] 04:16:24 INFO - [mozharness: 2018-09-27 04:16:24.281171Z] Finished run-tests step (success) [task 2018-09-27T04:16:24.284Z] 04:16:24 INFO - Running post-run listener: _resource_record_post_run [task 2018-09-27T04:16:24.365Z] 04:16:24 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json [task 2018-09-27T04:16:24.371Z] 04:16:24 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 6.780464480874315}, {"name": "io_write_bytes", "value": 568532992}, {"name": "io.read_bytes", "value": 7987200}, {"name": "io_write_time", "value": 79012}, {"name": "io_read_time", "value": 120}], "extraOptions": ["taskcluster-m3.large"], "name": "xpcshell.xpcshell-coverage.5.overall"}, {"subtests": [{"name": "time", "value": 18.84323215484619}, {"name": "cpu_percent", "value": 50.27777777777778}], "name": "xpcshell.xpcshell-coverage.5.install"}, {"subtests": [{"name": "time", "value": 0.025150060653686523}], "name": "xpcshell.xpcshell-coverage.5.stage-files"}, {"subtests": [{"name": "time", "value": 347.76533699035645}, {"name": "cpu_percent", "value": 4.389481268011528}], "name": "xpcshell.xpcshell-coverage.5.run-tests"}]} [task 2018-09-27T04:16:24.371Z] 04:16:24 INFO - Total resource usage - Wall time: 367s; CPU: 4.0%; Read bytes: 7987200; Write bytes: 568532992; Read time: 120; Write time: 79012 [task 2018-09-27T04:16:24.371Z] 04:16:24 INFO - TinderboxPrint: CPU usage<br/>4.4% [task 2018-09-27T04:16:24.372Z] 04:16:24 INFO - TinderboxPrint: I/O read bytes / time<br/>7,987,200 / 120 [task 2018-09-27T04:16:24.372Z] 04:16:24 INFO - TinderboxPrint: I/O write bytes / time<br/>568,532,992 / 79,012 [task 2018-09-27T04:16:24.373Z] 04:16:24 INFO - TinderboxPrint: CPU idle<br/>673.4 (93.0%) [task 2018-09-27T04:16:24.373Z] 04:16:24 INFO - TinderboxPrint: CPU system<br/>9.4 (1.3%) [task 2018-09-27T04:16:24.373Z] 04:16:24 INFO - TinderboxPrint: CPU user<br/>39.3 (5.4%) [task 2018-09-27T04:16:24.374Z] 04:16:24 INFO - TinderboxPrint: Swap in / out<br/>0 / 0 [task 2018-09-27T04:16:24.375Z] 04:16:24 INFO - install - Wall time: 19s; CPU: 50.0%; Read bytes: 0; Write bytes: 15986688; Read time: 0; Write time: 2496 [task 2018-09-27T04:16:24.376Z] 04:16:24 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-09-27T04:16:24.379Z] 04:16:24 INFO - run-tests - Wall time: 348s; CPU: 4.0%; Read bytes: 7987200; Write bytes: 552546304; Read time: 120; Write time: 76516 [task 2018-09-27T04:16:24.466Z] 04:16:24 INFO - Running post-run listener: copy_logs_to_upload_dir [task 2018-09-27T04:16:24.466Z] 04:16:24 INFO - Copying logs to upload dir... [task 2018-09-27T04:16:24.466Z] 04:16:24 INFO - mkdir: /builds/worker/workspace/build/upload/logs [task 2018-09-27T04:16:24.469Z] 04:16:24 INFO - Copying logs to upload dir... [task 2018-09-27T04:16:24.471Z] 04:16:24 WARNING - returning nonzero exit status 2 [task 2018-09-27T04:16:24.488Z] cleanup [task 2018-09-27T04:16:24.489Z] + cleanup [task 2018-09-27T04:16:24.489Z] + local rv=2 [task 2018-09-27T04:16:24.489Z] + [[ -s /builds/worker/.xsession-errors ]] [task 2018-09-27T04:16:24.489Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log [task 2018-09-27T04:16:24.493Z] + true [task 2018-09-27T04:16:24.493Z] + cleanup_xvfb [task 2018-09-27T04:16:24.494Z] pidof Xvfb [task 2018-09-27T04:16:24.495Z] ++ pidof Xvfb [task 2018-09-27T04:16:24.499Z] + local xvfb_pid=24 [task 2018-09-27T04:16:24.499Z] + local vnc=false [task 2018-09-27T04:16:24.499Z] + local interactive=false [task 2018-09-27T04:16:24.510Z] + '[' -n 24 ']' [task 2018-09-27T04:16:24.512Z] + [[ false == false ]] [task 2018-09-27T04:16:24.514Z] + [[ false == false ]] [task 2018-09-27T04:16:24.516Z] + kill 24 [task 2018-09-27T04:16:24.517Z] + screen -XS xvfb quit [task 2018-09-27T04:16:24.517Z] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" [task 2018-09-27T04:16:24.517Z] after 1114 requests (1114 known processed) with 0 events remaining. [task 2018-09-27T04:16:24.518Z] compizconfig - Info: Backend : ini [task 2018-09-27T04:16:24.518Z] compizconfig - Info: Integration : true [task 2018-09-27T04:16:24.518Z] compizconfig - Info: Profile : default [task 2018-09-27T04:16:24.740Z] No screen session found. [task 2018-09-27T04:16:24.741Z] + true [task 2018-09-27T04:16:24.741Z] + exit 2 [taskcluster 2018-09-27 04:16:25.322Z] === Task Finished === [taskcluster 2018-09-27 04:16:31.090Z] Unsuccessful task run with exit code: 2 completed in 991.494 seconds
Priority: P5 → P3
Whiteboard: [necko-triaged]
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.