Skip to content

Commit

Permalink
8337826: Improve logging in OCSPTimeout and SimpleOCSPResponder to he…
Browse files Browse the repository at this point in the history 
…lp diagnose JDK-8309754

Backport-of: 9b11bd7
  • Loading branch information
Alexey Bakhtin committed Nov 20, 2024
1 parent f9cd285 commit 2029e4e
Show file tree
Hide file tree
Showing 2 changed files with 81 additions and 59 deletions.
124 changes: 67 additions & 57 deletions test/jdk/java/security/cert/CertPathValidator/OCSP/OCSPTimeout.java
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2023, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2023, 2024, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
Expand Down Expand Up @@ -36,17 +36,17 @@
* java.base/sun.security.util
* @library ../../../../../java/security/testlibrary
* @build CertificateBuilder SimpleOCSPServer
* @run main/othervm OCSPTimeout 1000 true
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=5
* OCSPTimeout 1000 true
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1
* OCSPTimeout 5000 false
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1s
* OCSPTimeout 5000 false
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1500ms
* OCSPTimeout 5000 false
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=4500ms
* OCSPTimeout 1000 true
* @run main/othervm -Djava.security.debug=certpath OCSPTimeout 1000 true
* @run main/othervm -Djava.security.debug=certpath
* -Dcom.sun.security.ocsp.readtimeout=5 OCSPTimeout 1000 true
* @run main/othervm -Djava.security.debug=certpath
* -Dcom.sun.security.ocsp.readtimeout=1 OCSPTimeout 5000 false
* @run main/othervm -Djava.security.debug=certpath
* -Dcom.sun.security.ocsp.readtimeout=1s OCSPTimeout 5000 false
* @run main/othervm -Djava.security.debug=certpath
* -Dcom.sun.security.ocsp.readtimeout=1500ms OCSPTimeout 5000 false
* @run main/othervm -Djava.security.debug=certpath
* -Dcom.sun.security.ocsp.readtimeout=4500ms OCSPTimeout 1000 true
*/

import java.io.*;
Expand Down Expand Up @@ -82,62 +82,72 @@ public class OCSPTimeout {
static SimpleOCSPServer rootOcsp; // Root CA OCSP Responder
static int rootOcspPort; // Port number for root OCSP

public static void main(String args[]) throws Exception {
public static void main(String[] args) throws Exception {
int ocspTimeout = 15000;
boolean expected = false;

createPKI();

if (args[0] != null) {
ocspTimeout = Integer.parseInt(args[0]);
}
rootOcsp.setDelay(ocspTimeout);

expected = (args[1] != null && Boolean.parseBoolean(args[1]));
log("Test case expects to " + (expected ? "pass" : "fail"));

// validate chain
CertPathValidator cpv = CertPathValidator.getInstance("PKIX");
PKIXRevocationChecker prc =
(PKIXRevocationChecker) cpv.getRevocationChecker();
prc.setOptions(EnumSet.of(NO_FALLBACK, SOFT_FAIL));
PKIXParameters params =
new PKIXParameters(Set.of(new TrustAnchor(rootCert, null)));
params.addCertPathChecker(prc);
CertificateFactory cf = CertificateFactory.getInstance("X.509");
CertPath cp = cf.generateCertPath(List.of(eeCert));
cpv.validate(cp, params);

// unwrap soft fail exceptions and check for SocketTimeoutException
List<CertPathValidatorException> softExc = prc.getSoftFailExceptions();
if (expected) {
if (softExc.size() > 0) {
throw new RuntimeException("Expected to pass, found " +
softExc.size() + " soft fail exceptions");
try {
if (args[0] != null) {
ocspTimeout = Integer.parseInt(args[0]);
}
} else {
// If we expect to fail the validation then there should be a
// SocketTimeoutException
boolean found = false;
for (CertPathValidatorException softFail : softExc) {
log("CPVE: " + softFail);
Throwable cause = softFail.getCause();
log("Cause: " + cause);
while (cause != null) {
if (cause instanceof SocketTimeoutException) {
found = true;
break;
rootOcsp.setDelay(ocspTimeout);

expected = (args[1] != null && Boolean.parseBoolean(args[1]));
log("Test case expects to " + (expected ? "pass" : "fail"));

// validate chain
CertPathValidator cpv = CertPathValidator.getInstance("PKIX");
PKIXRevocationChecker prc =
(PKIXRevocationChecker) cpv.getRevocationChecker();
prc.setOptions(EnumSet.of(NO_FALLBACK, SOFT_FAIL));
PKIXParameters params =
new PKIXParameters(Set.of(new TrustAnchor(rootCert, null)));
params.addCertPathChecker(prc);
CertificateFactory cf = CertificateFactory.getInstance("X.509");
CertPath cp = cf.generateCertPath(List.of(eeCert));
cpv.validate(cp, params);

// unwrap soft fail exceptions and check for SocketTimeoutException
List<CertPathValidatorException> softExc = prc.getSoftFailExceptions();
if (expected) {
if (!softExc.isEmpty()) {
log("Expected to pass, found " + softExc.size() +
" soft fail exceptions");
for (CertPathValidatorException cpve : softExc) {
log("Exception: " + cpve);
}
cause = cause.getCause();
throw new RuntimeException("Expected to pass, found " +
softExc.size() + " soft fail exceptions");
}
if (found) {
break;
} else {
// If we expect to fail the validation then there should be a
// SocketTimeoutException
boolean found = false;
for (CertPathValidatorException softFail : softExc) {
log("CPVE: " + softFail);
Throwable cause = softFail.getCause();
log("Cause: " + cause);
while (cause != null) {
if (cause instanceof SocketTimeoutException) {
found = true;
break;
}
cause = cause.getCause();
}
if (found) {
break;
}
}
}

if (!found) {
throw new RuntimeException("SocketTimeoutException not thrown");
if (!found) {
throw new RuntimeException("SocketTimeoutException not thrown");
}
}
} finally {
rootOcsp.stop();
rootOcsp.shutdownNow();
}
}

Expand Down
16 changes: 14 additions & 2 deletions test/jdk/java/security/testlibrary/SimpleOCSPServer.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -574,8 +574,8 @@ public void setDisableContentLength(boolean isDisabled) {
*/
private synchronized void log(String message) {
if (logEnabled || debug != null) {
System.out.println("[" + Thread.currentThread().getName() + "]: " +
message);
System.out.println("[" + Thread.currentThread().getName() + "][" +
System.currentTimeMillis() + "]: " + message);
}
}

Expand Down Expand Up @@ -729,6 +729,7 @@ public void run() {
// wait out the delay here before any other processing.
try {
if (delayMsec > 0) {
log("Delaying response for " + delayMsec + " milliseconds.");
Thread.sleep(delayMsec);
}
} catch (InterruptedException ie) {
Expand Down Expand Up @@ -910,6 +911,13 @@ private LocalOcspRequest parseHttpOcspPost(InputStream inStream)
*/
private LocalOcspRequest parseHttpOcspGet(String[] headerTokens,
InputStream inStream) throws IOException, CertificateException {
// Display the whole request
StringBuilder sb = new StringBuilder("OCSP GET REQUEST\n");
for (String hTok : headerTokens) {
sb.append(hTok).append("\n");
}
log(sb.toString());

// Before we process the remainder of the GET URL, we should drain
// the InputStream of any other header data. We (for now) won't
// use it, but will display the contents if logging is enabled.
Expand Down Expand Up @@ -1002,6 +1010,10 @@ private LocalOcspRequest(byte[] requestBytes) throws IOException,
CertificateException {
Objects.requireNonNull(requestBytes, "Received null input");

// Display the DER encoding before parsing
log("Local OCSP Request Constructor, parsing bytes:\n" +
dumpHexBytes(requestBytes));

DerInputStream dis = new DerInputStream(requestBytes);

// Parse the top-level structure, it should have no more than
Expand Down

0 comments on commit 2029e4e

Please sign in to comment.