Closed Bug 1776553 Opened 4 years ago Closed 3 years ago

Intermittent security/manager/ssl/tests/unit/test_ocsp_must_staple.js | single tracking bug

Categories

(Core :: Security: PSM, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=382529650&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Ljkaqlh2STmS6kNSU68ggg/runs/0/artifacts/public/logs/live_backing.log


[task 2022-06-25T14:17:53.605Z] 14:17:53     INFO -  TEST-START | security/manager/ssl/tests/unit/test_ocsp_must_staple.js
[task 2022-06-25T14:17:54.270Z] 14:17:54  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_must_staple.js | xpcshell return code: 0
[task 2022-06-25T14:17:54.271Z] 14:17:54     INFO -  TEST-INFO took 654ms
[task 2022-06-25T14:17:54.271Z] 14:17:54     INFO -  >>>>>>>
[task 2022-06-25T14:17:54.272Z] 14:17:54     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-06-25T14:17:54.272Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2022-06-25T14:17:54.272Z] 14:17:54     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2022-06-25T14:17:54.273Z] 14:17:54     INFO -  running event loop
[task 2022-06-25T14:17:54.273Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.273Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.273Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Binary util OCSPStaplingServer should exist - true == true
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - certificate folder (ocsp_certs) should exist - true == true
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  PID 3280 | sending 'GET / HTTP/1.0
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  PID 3280 | '
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.274Z] 14:17:54     INFO -  PID 3280 | HTTP/1.0 200 OK
[task 2022-06-25T14:17:54.275Z] 14:17:54     INFO -  PID 3280 | content-type: text/plain
[task 2022-06-25T14:17:54.275Z] 14:17:54     INFO -  PID 3280 | connection: close
[task 2022-06-25T14:17:54.275Z] 14:17:54     INFO -  PID 3280 | server: httpd.js
[task 2022-06-25T14:17:54.276Z] 14:17:54     INFO -  PID 3280 | date: Sat, 25 Jun 2022 14:17:53 GMT
[task 2022-06-25T14:17:54.276Z] 14:17:54     INFO -  PID 3280 | content-length: 3
[task 2022-06-25T14:17:54.276Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2022-06-25T14:17:54.276Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.277Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.277Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.277Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2022-06-25T14:17:54.278Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-plain-ee-with-must-staple-int.example.com'
[task 2022-06-25T14:17:54.278Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-plain-ee-with-must-staple-int.example.com'
[task 2022-06-25T14:17:54.278Z] 14:17:54     INFO -  PID 3280 | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
[task 2022-06-25T14:17:54.278Z] 14:17:54     INFO -  "handling ocsp-stapling-plain-ee-with-must-staple-int.example.com"
[task 2022-06-25T14:17:54.278Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 2153398262 == 2153398262
[task 2022-06-25T14:17:54.279Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2022-06-25T14:17:54.279Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.280Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.280Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.281Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2022-06-25T14:17:54.281Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'multi-tls-feature-good.example.com'
[task 2022-06-25T14:17:54.281Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'multi-tls-feature-good.example.com'
[task 2022-06-25T14:17:54.282Z] 14:17:54     INFO -  PID 3280 | read '0x30'
[task 2022-06-25T14:17:54.282Z] 14:17:54     INFO -  PID 3280 | sending '0'
[task 2022-06-25T14:17:54.282Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Should have received ASCII '0' from server - "0" == "0"
[task 2022-06-25T14:17:54.283Z] 14:17:54     INFO -  "handling multi-tls-feature-good.example.com"
[task 2022-06-25T14:17:54.283Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 0 == 0
[task 2022-06-25T14:17:54.284Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2022-06-25T14:17:54.284Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.284Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.285Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.285Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 3 finished (2)
[task 2022-06-25T14:17:54.285Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'multi-tls-feature-bad.example.com'
[task 2022-06-25T14:17:54.286Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'multi-tls-feature-bad.example.com'
[task 2022-06-25T14:17:54.286Z] 14:17:54     INFO -  PID 3280 | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
[task 2022-06-25T14:17:54.286Z] 14:17:54     INFO -  "handling multi-tls-feature-bad.example.com"
[task 2022-06-25T14:17:54.286Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 2153398262 == 2153398262
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 4 pending (2)
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 4 finished (2)
[task 2022-06-25T14:17:54.287Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple.example.com'
[task 2022-06-25T14:17:54.288Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple.example.com'
[task 2022-06-25T14:17:54.288Z] 14:17:54     INFO -  PID 3280 | read '0x30'
[task 2022-06-25T14:17:54.288Z] 14:17:54     INFO -  PID 3280 | sending '0'
[task 2022-06-25T14:17:54.289Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Should have received ASCII '0' from server - "0" == "0"
[task 2022-06-25T14:17:54.289Z] 14:17:54     INFO -  "handling ocsp-stapling-must-staple.example.com"
[task 2022-06-25T14:17:54.289Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 0 == 0
[task 2022-06-25T14:17:54.294Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 5 pending (2)
[task 2022-06-25T14:17:54.294Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.294Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.295Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.295Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 5 finished (2)
[task 2022-06-25T14:17:54.295Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-revoked.example.com'
[task 2022-06-25T14:17:54.295Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-revoked.example.com'
[task 2022-06-25T14:17:54.296Z] 14:17:54     INFO -  PID 3280 | PR_Recv failed: SSL_ERROR_REVOKED_CERT_ALERT
[task 2022-06-25T14:17:54.296Z] 14:17:54     INFO -  "handling ocsp-stapling-must-staple-revoked.example.com"
[task 2022-06-25T14:17:54.296Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 2153390068 == 2153390068
[task 2022-06-25T14:17:54.297Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 6 pending (2)
[task 2022-06-25T14:17:54.297Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.297Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.297Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.297Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 6 finished (2)
[task 2022-06-25T14:17:54.298Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-missing.example.com'
[task 2022-06-25T14:17:54.298Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-missing.example.com'
[task 2022-06-25T14:17:54.298Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Should be getting an OCSP request only when expected - true == true
[task 2022-06-25T14:17:54.298Z] 14:17:54     INFO -  PID 3280 | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
[task 2022-06-25T14:17:54.299Z] 14:17:54     INFO -  "handling ocsp-stapling-must-staple-missing.example.com"
[task 2022-06-25T14:17:54.299Z] 14:17:54     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 2153398262 == 2153398262
[task 2022-06-25T14:17:54.299Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 7 pending (2)
[task 2022-06-25T14:17:54.299Z] 14:17:54     INFO -  (xpcshell/head.js) | test finished (2)
[task 2022-06-25T14:17:54.300Z] 14:17:54     INFO -  security/manager/ssl/tests/unit/test_ocsp_must_staple.js | Starting
[task 2022-06-25T14:17:54.300Z] 14:17:54     INFO -  (xpcshell/head.js) | test pending (2)
[task 2022-06-25T14:17:54.300Z] 14:17:54     INFO -  (xpcshell/head.js) | test run_next_test 7 finished (2)
[task 2022-06-25T14:17:54.300Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-empty.example.com'
[task 2022-06-25T14:17:54.300Z] 14:17:54     INFO -  PID 3280 | found pre-defined host 'ocsp-stapling-must-staple-empty.example.com'
[task 2022-06-25T14:17:54.301Z] 14:17:54     INFO -  "handling ocsp-stapling-must-staple-empty.example.com"
[task 2022-06-25T14:17:54.301Z] 14:17:54  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - Actual and expected connection result should match - 2152398868 == 2153389951
[task 2022-06-25T14:17:54.301Z] 14:17:54     INFO -  -e:null:1
[task 2022-06-25T14:17:54.301Z] 14:17:54     INFO -  exiting test
[task 2022-06-25T14:17:54.302Z] 14:17:54     INFO -  PID 3280 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 868: NS_ERROR_ABORT
[task 2022-06-25T14:17:54.302Z] 14:17:54     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NS_ERROR_ABORT" {file: "/builds/worker/workspace/build/tests/xpcshell/head.js" line: 868}]"
[task 2022-06-25T14:17:54.302Z] 14:17:54     INFO -  PID 3280 | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
[task 2022-06-25T14:17:54.302Z] 14:17:54  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_must_staple.js |  - A promise chain failed to handle a rejection: [Exception... "Abort"  nsresult: "0x80004004 (NS_ERROR_ABORT)"  location: "JS frame :: /builds/worker/workspace/build/tests/xpcshell/head.js :: _abort_failed_test :: line 868"  data: no] - stack: _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:868:20
[task 2022-06-25T14:17:54.302Z] 14:17:54     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:969:5
[task 2022-06-25T14:17:54.303Z] 14:17:54     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:75:21
[task 2022-06-25T14:17:54.303Z] 14:17:54     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-06-25T14:17:54.303Z] 14:17:54     INFO -  equal@resource://testing-common/Assert.jsm:270:8
[task 2022-06-25T14:17:54.303Z] 14:17:54     INFO -  asyncConnectTo/<@/builds/worker/workspace/build/tests/xpcshell/tests/security/manager/ssl/tests/unit/head_psm.js:627:12
[task 2022-06-25T14:17:54.304Z] 14:17:54     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2022-06-25T14:17:54.304Z] 14:17:54     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:597:5
[task 2022-06-25T14:17:54.304Z] 14:17:54     INFO -  @-e:1:1
[task 2022-06-25T14:17:54.304Z] 14:17:54     INFO -  Rejection date: Sat Jun 25 2022 14:17:54 GMT+0000 (Coordinated Universal Time) - false == true
[task 2022-06-25T14:17:54.305Z] 14:17:54     INFO -  resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:271
[task 2022-06-25T14:17:54.305Z] 14:17:54     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:598
[task 2022-06-25T14:17:54.305Z] 14:17:54     INFO -  -e:null:1
[task 2022-06-25T14:17:54.305Z] 14:17:54     INFO -  exiting test
[task 2022-06-25T14:17:54.305Z] 14:17:54     INFO -  PID 3280 | !!! error running onStopped callback: TypeError: callback is not a function
[task 2022-06-25T14:17:54.306Z] 14:17:54     INFO -  <<<<<<<
[task 2022-06-25T14:17:55.481Z] 14:17:55     INFO -  TEST-START | security/manager/ssl/tests/unit/test_ocsp_private_caching.js

Hi Joel! Can you please take a look at this? Could this also be regressed by Bug 1769154 ?
Thank you!

Flags: needinfo?(jmaher)

this is very low frequency intermittent,

Flags: needinfo?(jmaher)
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.