Closed Bug 1439540 Opened 7 years ago Closed 7 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | dom/push/test/xpcshell/test_unregister_success_http2.js | Test timed out

Categories

(Core :: DOM: Push Subscriptions, defect, P5)

Product:
Core
Component:
DOM: Push Subscriptions
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=163143654&repo=autoland https://queue.taskcluster.net/v1/task/ebWz3gmiS3WNu__wtRucUQ/runs/0/artifacts/public/logs/live_backing.log [task 2018-02-20T10:50:13.205Z] 10:50:13 INFO - TEST-START | dom/push/test/xpcshell/test_unregister_success_http2.js [task 2018-02-20T10:55:13.205Z] 10:55:13 WARNING - TEST-UNEXPECTED-TIMEOUT | dom/push/test/xpcshell/test_unregister_success_http2.js | Test timed out [task 2018-02-20T10:55:13.208Z] 10:55:13 INFO - TEST-INFO took 300000ms [task 2018-02-20T10:55:13.209Z] 10:55:13 INFO - >>>>>>> [task 2018-02-20T10:55:13.217Z] 10:55:13 INFO - PID 9054 | JavaScript strict warning: resource://gre/modules/PushService.jsm, line 18: ReferenceError: reference to undefined property "getCryptoParams" [task 2018-02-20T10:55:13.218Z] 10:55:13 INFO - (xpcshell/head.js) | test MAIN run_test pending (1) [task 2018-02-20T10:55:13.218Z] 10:55:13 INFO - "Using HTTP/2 server on port 46314" [task 2018-02-20T10:55:13.219Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties" [task 2018-02-20T10:55:13.220Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "getCryptoParams"" {file: "resource://gre/modules/PushService.jsm" line: 18}]" [task 2018-02-20T10:55:13.220Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties" [task 2018-02-20T10:55:13.220Z] 10:55:13 INFO - PID 9054 | Certificate Override in place [task 2018-02-20T10:55:13.221Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "localhost:46314 uses an invalid security certificate. [task 2018-02-20T10:55:13.221Z] 10:55:13 INFO - The certificate is not trusted because the issuer certificate is unknown. [task 2018-02-20T10:55:13.222Z] 10:55:13 INFO - The server might not be sending the appropriate intermediate certificates. [task 2018-02-20T10:55:13.222Z] 10:55:13 INFO - An additional root certificate may need to be imported. [task 2018-02-20T10:55:13.223Z] 10:55:13 INFO - The certificate is only valid for the following names: [task 2018-02-20T10:55:13.223Z] 10:55:13 INFO - foo.example.com, alt1.example.com, alt2.example.com [task 2018-02-20T10:55:13.224Z] 10:55:13 INFO - Error code: <a id="errorCode" title="SEC_ERROR_UNKNOWN_ISSUER">SEC_ERROR_UNKNOWN_ISSUER</a> [task 2018-02-20T10:55:13.224Z] 10:55:13 INFO - "]" [task 2018-02-20T10:55:13.225Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2) [task 2018-02-20T10:55:13.225Z] 10:55:13 INFO - (xpcshell/head.js) | test MAIN run_test finished (2) [task 2018-02-20T10:55:13.225Z] 10:55:13 INFO - running event loop [task 2018-02-20T10:55:13.227Z] 10:55:13 INFO - dom/push/test/xpcshell/test_unregister_success_http2.js | Starting test_pushUnsubscriptionSuccess [task 2018-02-20T10:55:13.227Z] 10:55:13 INFO - (xpcshell/head.js) | test test_pushUnsubscriptionSuccess pending (2) [task 2018-02-20T10:55:13.227Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2) [task 2018-02-20T10:55:13.228Z] 10:55:13 INFO - PID 9054 | JavaScript error: resource://gre/modules/PushDB.jsm, line 393: Error: Record https://localhost:46314/subscriptionUnsubscriptionSuccess does not exist [task 2018-02-20T10:55:13.228Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: Record https://localhost:46314/subscriptionUnsubscriptionSuccess does not exist" {file: "resource://gre/modules/PushDB.jsm" line: 393}]" [task 2018-02-20T10:55:13.229Z] 10:55:13 INFO - PID 9054 | console.error: PushServiceHttp2: [task 2018-02-20T10:55:13.230Z] 10:55:13 INFO - PID 9054 | startConnections: Error updating record [task 2018-02-20T10:55:13.231Z] 10:55:13 INFO - PID 9054 | https://localhost:46314/subscriptionUnsubscriptionSuccess [task 2018-02-20T10:55:13.231Z] 10:55:13 INFO - PID 9054 | AbortError [task 2018-02-20T10:55:13.231Z] 10:55:13 INFO - TEST-PASS | dom/push/test/xpcshell/test_unregister_success_http2.js | test_pushUnsubscriptionSuccess - [test_pushUnsubscriptionSuccess : 70] Unregister did not remove record - true == true [task 2018-02-20T10:55:13.231Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2) [task 2018-02-20T10:55:13.233Z] 10:55:13 INFO - (xpcshell/head.js) | test test_pushUnsubscriptionSuccess finished (2) [task 2018-02-20T10:55:13.233Z] 10:55:13 INFO - dom/push/test/xpcshell/test_unregister_success_http2.js | Starting test_complete [task 2018-02-20T10:55:13.234Z] 10:55:13 INFO - (xpcshell/head.js) | test test_complete pending (2) [task 2018-02-20T10:55:13.234Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2) [task 2018-02-20T10:55:13.235Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2) [task 2018-02-20T10:55:13.236Z] 10:55:13 INFO - (xpcshell/head.js) | test test_complete finished (2) [task 2018-02-20T10:55:13.237Z] 10:55:13 INFO - (xpcshell/head.js) | test run_next_test 2 finished (1) [task 2018-02-20T10:55:13.237Z] 10:55:13 INFO - exiting test [task 2018-02-20T10:55:13.237Z] 10:55:13 INFO - PID 9054 | JavaScript strict warning: resource://gre/modules/IndexedDBHelper.jsm, line 166: ReferenceError: reference to undefined property "result" [task 2018-02-20T10:55:13.238Z] 10:55:13 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "result"" {file: "resource://gre/modules/IndexedDBHelper.jsm" line: 166}]" [task 2018-02-20T10:55:13.238Z] 10:55:13 INFO - <<<<<<< [task 2018-02-20T10:55:13.238Z] 10:55:13 INFO - xpcshell return code: None [task 2018-02-20T11:11:53.278Z] 11:11:53 INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py', '--total-chunks', '8', '--this-chunk', '3', '--symbols-path=https://queue.taskcluster.net/v1/task/Qr7ehxxjTei0aO2IYePiaQ/artifacts/public/build/target.crashreporter-symbols.zip', '--test-plugin-path=/builds/worker/workspace/build/application/firefox/plugins', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/xpcshell_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/xpcshell_errorsummary.log', '--utility-path=tests/bin', '--xpcshell=/builds/worker/workspace/build/application/firefox/xpcshell', '--manifest=tests/xpcshell/tests/xpcshell.ini'] [task 2018-02-20T11:11:53.320Z] 11:11:53 ERROR - timed out after 1000 seconds of no output [task 2018-02-20T11:11:53.321Z] 11:11:53 ERROR - Return code: -15 [task 2018-02-20T11:11:53.322Z] 11:11:53 ERROR - No tests run or test summary not found [task 2018-02-20T11:11:53.323Z] 11:11:53 INFO - TinderboxPrint: xpcshell-xpcshell<br/><em class="testfail">T-FAIL</em> [task 2018-02-20T11:11:53.323Z] 11:11:53 WARNING - # TBPL FAILURE # [task 2018-02-20T11:11:53.324Z] 11:11:53 WARNING - setting return code to 2 [task 2018-02-20T11:11:53.325Z] 11:11:53 WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE [task 2018-02-20T11:11:53.326Z] 11:11:53 INFO - Running post-action listener: _package_coverage_data [task 2018-02-20T11:11:53.326Z] 11:11:53 INFO - Running post-action listener: _resource_record_post_action [task 2018-02-20T11:11:53.327Z] 11:11:53 INFO - [mozharness: 2018-02-20 11:11:53.326848Z] Finished run-tests step (success) [task 2018-02-20T11:11:53.327Z] 11:11:53 INFO - Running post-run listener: _resource_record_post_run [task 2018-02-20T11:11:53.423Z] 11:11:53 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json [task 2018-02-20T11:11:53.430Z] 11:11:53 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 6.678262411347519}, {"name": "io_write_bytes", "value": 2055073792}, {"name": "io.read_bytes", "value": 311296}, {"name": "io_write_time", "value": 553028}, {"name": "io_read_time", "value": 208}], "extraOptions": ["taskcluster-m3.large"], "name": "xpcshell.xpcshell.3.overall"}, {"subtests": [{"name": "time", "value": 16.657598972320557}, {"name": "cpu_percent", "value": 50.2}], "name": "xpcshell.xpcshell.3.install"}, {"subtests": [{"name": "time", "value": 0.026343822479248047}], "name": "xpcshell.xpcshell.3.stage-files"}, {"subtests": [{"name": "time", "value": 1394.930824995041}, {"name": "cpu_percent", "value": 6.145333811916727}], "name": "xpcshell.xpcshell.3.run-tests"}]} [task 2018-02-20T11:11:53.430Z] 11:11:53 INFO - Total resource usage - Wall time: 1411s; CPU: 6.0%; Read bytes: 311296; Write bytes: 2055073792; Read time: 208; Write time: 553028 [task 2018-02-20T11:11:53.431Z] 11:11:53 INFO - TinderboxPrint: CPU usage<br/>6.1% [task 2018-02-20T11:11:53.431Z] 11:11:53 INFO - TinderboxPrint: I/O read bytes / time<br/>311,296 / 208 [task 2018-02-20T11:11:53.432Z] 11:11:53 INFO - TinderboxPrint: I/O write bytes / time<br/>2,055,073,792 / 553,028 [task 2018-02-20T11:11:53.433Z] 11:11:53 INFO - TinderboxPrint: CPU idle<br/>2,605.8 (92.8%) [task 2018-02-20T11:11:53.433Z] 11:11:53 INFO - TinderboxPrint: CPU system<br/>38.8 (1.4%) [task 2018-02-20T11:11:53.433Z] 11:11:53 INFO - TinderboxPrint: CPU user<br/>148.1 (5.3%) [task 2018-02-20T11:11:53.433Z] 11:11:53 INFO - TinderboxPrint: Swap in / out<br/>0 / 0 [task 2018-02-20T11:11:53.434Z] 11:11:53 INFO - install - Wall time: 17s; CPU: 50.0%; Read bytes: 0; Write bytes: 11706368; Read time: 0; Write time: 1736 [task 2018-02-20T11:11:53.436Z] 11:11:53 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-02-20T11:11:53.447Z] 11:11:53 INFO - run-tests - Wall time: 1395s; CPU: 6.0%; Read bytes: 311296; Write bytes: 2043367424; Read time: 208; Write time: 551292 [task 2018-02-20T11:11:53.774Z] 11:11:53 INFO - Running post-run listener: _upload_blobber_files [task 2018-02-20T11:11:53.775Z] 11:11:53 WARNING - Blob upload gear skipped. Missing cmdline options. [task 2018-02-20T11:11:53.775Z] 11:11:53 INFO - Running post-run listener: copy_logs_to_upload_dir [task 2018-02-20T11:11:53.777Z] 11:11:53 INFO - Copying logs to upload dir... [task 2018-02-20T11:11:53.778Z] 11:11:53 INFO - mkdir: /builds/worker/workspace/build/upload/logs [task 2018-02-20T11:11:53.778Z] 11:11:53 INFO - Copying logs to upload dir... [task 2018-02-20T11:11:53.781Z] 11:11:53 WARNING - returning nonzero exit status 2 [task 2018-02-20T11:11:53.800Z] cleanup
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.