Closed Bug 1235287 Opened 8 years ago Closed 7 years ago

Intermittent test_ocsp_stapling_expired.js | xpcshell return code: 0 | - Actual and expected connection result should match - 2153390068 == 0

Categories

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

Product:
Core
Component:
Security: PSM
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla58
Tracking Flags:
Tracking Status
firefox58 --- fixed

People

(Reporter: aryx, Assigned: keeler)

Details

(Keywords: intermittent-failure, Whiteboard: [psm-assigned] [stockwell fixed:timing])

Attachments

(1 file)

bug 1235287 - set a longer ocsp request timeout in test_ocsp_stapling_expired.js to avoid intermittent failures on android
59 bytes, text/x-review-board-request
jcj
: review+
Details 
https://treeherder.mozilla.org/logviewer.html#?job_id=19030486&repo=mozilla-inbound

14:19:01     INFO -  TEST-START | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js
14:20:25  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcshell return code: 0
14:20:25     INFO -  TEST-INFO took 83560ms
14:20:25     INFO -  >>>>>>>
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcw: cd /data/local/tests/xpc/security/manager/ssl/tests/unit
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcw: xpcshell -r /data/local/tests/xpc/c/httpd.manifest -m -s -e const _HEAD_JS_PATH = "/data/local/tests/xpc/head.js"; -e const _MOZINFO_JS_PATH = "/data/local/tests/xpc/p/mozinfo.json"; -e const _TESTING_MODULES_DIR = "/data/local/tests/xpc/m"; -f /data/local/tests/xpc/head.js -e const _SERVER_ADDR = "localhost" -e const _HEAD_FILES = ["/data/local/tests/xpc/security/manager/ssl/tests/unit/head_psm.js"]; -e const _TAIL_FILES = []; -e const _JSDEBUGGER_PORT = 0; -e const _TEST_FILE = ["test_ocsp_stapling_expired.js"]; -e const _TEST_NAME = "security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js" -e _execute_test(); quit(0);
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | *****************************************************************
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | ***
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | *** This is stdout. Most of the useful output will be in logcat.
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | ***
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | *****************************************************************
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | _getBinaryUtil - [_getBinaryUtil : 428] Binary util GenerateOCSPResponse should exist - true == true
14:20:25     INFO -  "arg_array =sql:ocsp_certs,good,default-ee,unused,/data/local/tests/xpc/security/manager/ssl/tests/unit/0.ocsp"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 507] Process exit value should be 0 - 0 == 0
14:20:25     INFO -  "arg_array =sql:ocsp_certs,expiredresponse,default-ee,unused,/data/local/tests/xpc/security/manager/ssl/tests/unit/1.ocsp"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 507] Process exit value should be 0 - 0 == 0
14:20:25     INFO -  "arg_array =sql:ocsp_certs,oldvalidperiod,default-ee,unused,/data/local/tests/xpc/security/manager/ssl/tests/unit/2.ocsp"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 507] Process exit value should be 0 - 0 == 0
14:20:25     INFO -  "arg_array =sql:ocsp_certs,revoked,default-ee,unused,/data/local/tests/xpc/security/manager/ssl/tests/unit/3.ocsp"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 507] Process exit value should be 0 - 0 == 0
14:20:25     INFO -  "arg_array =sql:ocsp_certs,unknown,default-ee,unused,/data/local/tests/xpc/security/manager/ssl/tests/unit/4.ocsp"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 507] Process exit value should be 0 - 0 == 0
14:20:25     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
14:20:25     INFO -  running event loop
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Binary util OCSPStaplingServer should exist - true == true
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - certificate folder (ocsp_certs) should exist - true == true
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | sending 'GET / HTTP/1.0
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | '
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | HTTP/1.0 200 OK
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | content-type: text/plain
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | connection: close
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | server: httpd.js
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | date: Sun, 27 Dec 2015 22:19:12 GMT
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | content-length: 3
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | read '0x30'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | sending '0'
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have received ASCII '0' from server - "0" == "0"
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 0 == 0
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | read '0x30'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | sending '0'
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have received ASCII '0' from server - "0" == "0"
14:20:25     INFO -  "handling ocsp-stapling-expired-fresh-ca.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 0 == 0
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 3 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 3 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 4 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 4 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired-fresh-ca.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 5 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 5 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 6 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 6 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired-fresh-ca.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 7 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 7 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 8 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 8 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 2153389948
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 9 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 9 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_REVOKED_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153390068 == 2153390068
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 10 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 10 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_REVOKED_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired-fresh-ca.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153390068 == 2153390068
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 11 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 11 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389954 == 2153389954
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 12 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 12 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired-fresh-ca.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-expired-fresh-ca.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389954 == 2153389954
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 8 fallback OCSP requests - 8 == 8
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 13 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 13 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-revoked-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-revoked-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_REVOKED_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-revoked-old.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153390068 == 2153390068
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 14 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 14 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-unknown-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-unknown-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-unknown-old.example.com"
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389954 == 2153389954
14:20:25     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 15 pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test finished (2)
14:20:25     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
14:20:25     INFO -  (xpcshell/head.js) | test pending (2)
14:20:25     INFO -  (xpcshell/head.js) | test run_next_test 15 finished (2)
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-revoked-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-revoked-old.example.com'
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_REVOKED_CERT_ALERT
14:20:25     INFO -  "handling ocsp-stapling-revoked-old.example.com"
14:20:25  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153390068 == 0
14:20:25     INFO -  /data/local/tests/xpc/security/manager/ssl/tests/unit/head_psm.js:add_connection_test/</<:396
14:20:25     INFO -  resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:Handler.prototype.process:933
14:20:25     INFO -  resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:this.PromiseWalker.walkerLoop:812
14:20:25     INFO -  resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:this.PromiseWalker.scheduleWalkerLoop/<:746
14:20:25     INFO -  /data/local/tests/xpc/head.js:_do_main:208
14:20:25     INFO -  /data/local/tests/xpc/head.js:_execute_test:535
14:20:25     INFO -  -e:null:1
14:20:25     INFO -  exiting test
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | JavaScript strict warning: resource://testing-common/httpd.js, line 791: ReferenceError: reference to undefined property this._stopCallback
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | !!! error running onStopped callback: TypeError: callback is not a function
14:20:25     INFO -  PROCESS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | JavaScript error: /data/local/tests/xpc/head.js, line 506: TypeError: _testLogger is undefined
14:20:25     INFO -  <<<<<<<
Component: Security → Security: PSM
Mass whiteboard change to annotate PSM intermittent test failures as [psm-intermittent]. Filter on 31b932bd-1aad-4e29-9f4b-4cd864a3ffdc if that's important to you.
Whiteboard: [psm-intermittent]
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Whiteboard: [psm-intermittent] → [psm-intermittent] [stockwell needswork]
this started failing October 10th, but picked up on the 18th- we fail on android debug.

Here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=138763055&lineNumber=1979

and some related data from the log:
[task 2017-10-22T23:04:00.050Z] 23:04:00     INFO -  TEST-START | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js
[task 2017-10-22T23:04:17.215Z] 23:04:17  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcshell return code: 0
[task 2017-10-22T23:04:17.219Z] 23:04:17     INFO -  TEST-INFO took 17165ms
[task 2017-10-22T23:04:17.220Z] 23:04:17     INFO -  >>>>>>>
[task 2017-10-22T23:04:17.226Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcw: cd /storage/sdcard/tests/xpc/security/manager/ssl/tests/unit
[task 2017-10-22T23:04:17.227Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | xpcw: xpcshell -r /storage/sdcard/tests/xpc/c/httpd.manifest --greomni /data/local/xpcb/target.apk -m -s -e const _HEAD_JS_PATH = "/storage/sdcard/tests/xpc/head.js"; -e const _MOZINFO_JS_PATH = "/storage/sdcard/tests/xpc/p/mozinfo.json"; -e const _TESTING_MODULES_DIR = "/storage/sdcard/tests/xpc/m"; -f /storage/sdcard/tests/xpc/head.js -e const _SERVER_ADDR = "localhost" -e const _HEAD_FILES = ["/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/head_psm.js"]; -e const _JSDEBUGGER_PORT = 0; -e const _TEST_FILE = ["test_ocsp_stapling_expired.js"]; -e const _TEST_NAME = "security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js" -e _execute_test(); quit(0);
[task 2017-10-22T23:04:17.227Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | [6668, Unnamed thread 45c16080] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 171
[task 2017-10-22T23:04:17.228Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | [6668, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 508
[task 2017-10-22T23:04:17.228Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | [6668, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2872
[task 2017-10-22T23:04:17.229Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | _getBinaryUtil - [_getBinaryUtil : 483] Binary util GenerateOCSPResponse should exist - true == true
[task 2017-10-22T23:04:17.229Z] 23:04:17     INFO -  "argArray = sql:ocsp_certs,good,default-ee,unused,0,/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/0.ocsp"
[task 2017-10-22T23:04:17.230Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 561] Process exit value should be 0 - 0 == 0
[task 2017-10-22T23:04:17.230Z] 23:04:17     INFO -  "argArray = sql:ocsp_certs,expiredresponse,default-ee,unused,0,/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/1.ocsp"
[task 2017-10-22T23:04:17.230Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 561] Process exit value should be 0 - 0 == 0
[task 2017-10-22T23:04:17.230Z] 23:04:17     INFO -  "argArray = sql:ocsp_certs,oldvalidperiod,default-ee,unused,0,/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/2.ocsp"
[task 2017-10-22T23:04:17.231Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 561] Process exit value should be 0 - 0 == 0
[task 2017-10-22T23:04:17.231Z] 23:04:17     INFO -  "argArray = sql:ocsp_certs,revoked,default-ee,unused,0,/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/3.ocsp"
[task 2017-10-22T23:04:17.231Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 561] Process exit value should be 0 - 0 == 0
[task 2017-10-22T23:04:17.231Z] 23:04:17     INFO -  "argArray = sql:ocsp_certs,unknown,default-ee,unused,0,/storage/sdcard/tests/xpc/security/manager/ssl/tests/unit/4.ocsp"
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | generateOCSPResponses - [generateOCSPResponses : 561] Process exit value should be 0 - 0 == 0
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  running event loop
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  (xpcshell/head.js) | test pending (2)
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Binary util OCSPStaplingServer should exist - true == true
[task 2017-10-22T23:04:17.232Z] 23:04:17     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - certificate folder (ocsp_certs) should exist - true == true
[task 2017-10-22T23:04:17.233Z] 23:04:17     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2017-10-22T23:04:17.233Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | sending 'GET / HTTP/1.0
[task 2017-10-22T23:04:17.233Z] 23:04:17     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | '
[task 2017-10-22T23:04:17.233Z] 23:04:17     INFO -  (xpcshell/head.js) | test pending (2)
[task 2017-10-22T23:04:17.233Z] 23:04:17     INFO -  (xpcshell/head.js) | test finished (2)



:keeler, I see you are the triage owner for Security:PSM, can you help prioritize this bug as you see fit and get it in front of the right developer when appropriate?
Flags: needinfo?(dkeeler)
This is on my radar. I'll see what I can do.
Flags: needinfo?(dkeeler)
There have been 38 failures in the last week.

:keeler, do you have any updates on this?
Flags: needinfo?(dkeeler)
This test depends on an OCSP responder that we run as an http server from in the browser (httpd.js). If the server can't send a response within a second, the test would fail in the way we're seeing. I haven't been able to verify that this is what's happening, though: https://treeherder.mozilla.org/#/jobs?repo=try&revision=541a7509d970fb2d8bfc7c827c73c18a6e26e1fa
(that includes some logging to show what events are happening when, but as you can see I've ran it 100 times without it failing this test)
Now that I think about it some more, we've disabled OCSP fetching for DV certificates on android, so it might not even make sense to run this test on android. We should probably just disable it or change its behavior depending on the platform it's running on.
Flags: needinfo?(dkeeler)
Finally got a failure: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6726472f153015bae4ae2b5d233aaa7f577bb40f&selectedJob=143171014

[task 2017-11-09T00:23:58.727Z] 00:23:58     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | Starting
[task 2017-11-09T00:23:58.727Z] 00:23:58     INFO -  (xpcshell/head.js) | test pending (2)
[task 2017-11-09T00:23:58.727Z] 00:23:58     INFO -  "beforeConnect: it is now Wed Nov 08 2017 16:23:52 GMT-0800 (PST)"
[task 2017-11-09T00:23:58.728Z] 00:23:58     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2017-11-09T00:23:58.728Z] 00:23:58     INFO -  "afterStreamOpen: it is now Wed Nov 08 2017 16:23:52 GMT-0800 (PST)"
[task 2017-11-09T00:23:58.728Z] 00:23:58     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
[task 2017-11-09T00:23:58.728Z] 00:23:58     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | found pre-defined host 'ocsp-stapling-expired.example.com'
[task 2017-11-09T00:23:58.729Z] 00:23:58     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | [6566, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004002: file /builds/worker/workspace/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 182
[task 2017-11-09T00:23:58.729Z] 00:23:58     INFO -  "ocspResponder sending:"
[task 2017-11-09T00:23:58.730Z] 00:23:58     INFO -  "30 82 01 d3 0a 01 00 a0 82 01 cc 30 82 01 c8 06 09 2b 06 01 05 05 07 30 01 01 04 82 01 b9 30 82 01 b5 30 81 a0 a2 16 04 14 4d 64 35 64 d7 9d 29 ed f9 bb ba 9e 5b 7b af da ce 51 a4 49 18 0f 32 30 31 37 31 31 30 39 30 30 32 33 34 35 5a 30 75 30 73 30 4b 30 07 06 05 2b 0e 03 02 1a 04 14 bf 70 52 c8 b9 c0 f7 60 c8 91 23 e0 99 81 5e b2 c0 39 42 26 04 14 4d 64 35 64 d7 9d 29 ed f9 bb ba 9e 5b 7b af da ce 51 a4 49 02 14 35 1b e9 3a 1b 03 1c 46 1b 45 fe 9b b2 20 0f 6e f2 9e d9 50 80 00 18 0f 32 30 31 37 31 31 30 39 30 30 32 33 34 35 5a a0 11 18 0f 32 30 31 37 31 31 31 30 30 30 32 33 34 35 5a 30 0b 06 09 2a 86 48 86 f7 0d 01 01 0b 03 82 01 01 00 05 78 db 5f f9 59 12 d7 5b 96 c6 4e f0 6f a4 0e 5a 8e af e6 1f 02 1f f1 8d c5 b2 3b c1 aa 15 6d c9 b6 c9 50 49 e3 2d 20 90 c1 74 7c 94 97 69 54 7c d7 c0 dc 18 59 01 9d 76 74 04 19 68 66 d3 bc ef af 48 b3 38 84 ec 2d bf 90 bc 6f 19 33 05 06 84 13 ff b5 7c de c4 5a e3 b3 99 f9 00 d1 b4 0f 84 30 42 9d 15 3b ae 3f d3 22 89 eb 60 e1 1b 6f 62 c2 65 41 ea 1e 5d b6 09 4c ba 50 e0 cc 9d 1b af 48 93 e7 01 5b d9 8c e4 0f a1 bb 7b a4 34 d5 62 65 3b 61 5a 71 f6 09 45 6e e9 ef 61 b1 b8 f1 09 c2 6e d5 7d ca fb c6 25 43 a3 2e f2 ea 8f aa 9a 06 6b 6b a3 52 d8 60 46 a7 73 a2 15 2a 88 47 e3 7e 19 cc 26 e5 c7 bb 8b 51 7c 04 36 8f 8f 43 5b aa 39 72 b0 b7 1c fb d0 fd 2c a7 95 9b 18 4c 04 8e 70 5c 45 17 04 94 09 29 d5 4b 96 92 42 03 fc 1b c9 41 f8 4f 88 26 35 56 55 30 60 4a 32 21"
[task 2017-11-09T00:23:58.730Z] 00:23:58     INFO -  "at Wed Nov 08 2017 16:23:53 GMT-0800 (PST)"
[task 2017-11-09T00:23:58.730Z] 00:23:58     INFO -  security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js | PR_Recv failed: SSL_ERROR_BAD_CERT_ALERT
[task 2017-11-09T00:23:58.730Z] 00:23:58     INFO -  "handling ocsp-stapling-expired.example.com"
[task 2017-11-09T00:23:58.731Z] 00:23:58     INFO -  "withSecurityInfo: it is now Wed Nov 08 2017 16:23:54 GMT-0800 (PST)"
[task 2017-11-09T00:23:58.731Z] 00:23:58     INFO -  TEST-PASS | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Should have made 1 fallback OCSP request - 1 == 1
[task 2017-11-09T00:23:58.732Z] 00:23:58  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_ocsp_stapling_expired.js |  - Actual and expected connection result should match - 2153389948 == 0

This isn't definitive, but since the timeout is 1 second by default and since there is indeed at least 1 second between the ocsp responder sending the response and xpcshell completing the handshake (pay no attention to the leftmost timestamps, they're just a red herring), this is probably what the issue is. I imagine we could just increase the timeout for this test - we're not testing the timeout aspect of ocsp requests here.
Assignee: nobody → dkeeler
Priority: P3 → P1
Whiteboard: [psm-intermittent] [stockwell needswork] → [psm-assigned] [stockwell needswork]
Comment on attachment 8926933 [details]
bug 1235287 - set a longer ocsp request timeout in test_ocsp_stapling_expired.js to avoid intermittent failures on android

https://reviewboard.mozilla.org/r/198174/#review203430

LGTM
Attachment #8926933 - Flags: review?(jjones) → review+
Pushed by dkeeler@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e25cdbfcfa0f
set a longer ocsp request timeout in test_ocsp_stapling_expired.js to avoid intermittent failures on android r=jcj
https://hg.mozilla.org/mozilla-central/rev/e25cdbfcfa0f
Status: NEW → RESOLVED
Closed: 7 years ago
status-firefox58: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
Whiteboard: [psm-assigned] [stockwell needswork] → [psm-assigned] [stockwell fixed:timing]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: