Skip to content

Commit 077c8cb

Browse files
jnimehjnimeh
committed
8337826: Improve logging in OCSPTimeout and SimpleOCSPResponder to help diagnose JDK-8309754
1 parent 9856216 commit 077c8cb

File tree

2 files changed

+82
-60
lines changed

2 files changed

+82
-60
lines changed

‎test/jdk/java/security/cert/CertPathValidator/OCSP/OCSPTimeout.java

+68-58
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright (c) 2023, Oracle and/or its affiliates. All rights reserved.
2+
* Copyright (c) 2023, 2024, Oracle and/or its affiliates. All rights reserved.
33
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
44
*
55
* This code is free software; you can redistribute it and/or modify it
@@ -29,24 +29,24 @@
2929

3030
/**
3131
* @test
32-
* @bug 8179502
32+
* @bug 8179502 8337826
3333
* @summary Enhance OCSP, CRL and Certificate Fetch Timeouts
3434
* @modules java.base/sun.security.x509
3535
* java.base/sun.security.provider.certpath
3636
* java.base/sun.security.util
3737
* @library ../../../../../java/security/testlibrary
3838
* @build CertificateBuilder SimpleOCSPServer
39-
* @run main/othervm OCSPTimeout 1000 true
40-
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=5
41-
* OCSPTimeout 1000 true
42-
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1
43-
* OCSPTimeout 5000 false
44-
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1s
45-
* OCSPTimeout 5000 false
46-
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=1500ms
47-
* OCSPTimeout 5000 false
48-
* @run main/othervm -Dcom.sun.security.ocsp.readtimeout=4500ms
49-
* OCSPTimeout 1000 true
39+
* @run main/othervm -Djava.security.debug=certpath OCSPTimeout 1000 true
40+
* @run main/othervm -Djava.security.debug=certpath
41+
* -Dcom.sun.security.ocsp.readtimeout=5 OCSPTimeout 1000 true
42+
* @run main/othervm -Djava.security.debug=certpath
43+
* -Dcom.sun.security.ocsp.readtimeout=1 OCSPTimeout 5000 false
44+
* @run main/othervm -Djava.security.debug=certpath
45+
* -Dcom.sun.security.ocsp.readtimeout=1s OCSPTimeout 5000 false
46+
* @run main/othervm -Djava.security.debug=certpath
47+
* -Dcom.sun.security.ocsp.readtimeout=1500ms OCSPTimeout 5000 false
48+
* @run main/othervm -Djava.security.debug=certpath
49+
* -Dcom.sun.security.ocsp.readtimeout=4500ms OCSPTimeout 1000 true
5050
*/
5151

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

85-
public static void main(String args[]) throws Exception {
85+
public static void main(String[] args) throws Exception {
8686
int ocspTimeout = 15000;
8787
boolean expected = false;
8888

8989
createPKI();
9090

91-
if (args[0] != null) {
92-
ocspTimeout = Integer.parseInt(args[0]);
93-
}
94-
rootOcsp.setDelay(ocspTimeout);
95-
96-
expected = (args[1] != null && Boolean.parseBoolean(args[1]));
97-
log("Test case expects to " + (expected ? "pass" : "fail"));
98-
99-
// validate chain
100-
CertPathValidator cpv = CertPathValidator.getInstance("PKIX");
101-
PKIXRevocationChecker prc =
102-
(PKIXRevocationChecker) cpv.getRevocationChecker();
103-
prc.setOptions(EnumSet.of(NO_FALLBACK, SOFT_FAIL));
104-
PKIXParameters params =
105-
new PKIXParameters(Set.of(new TrustAnchor(rootCert, null)));
106-
params.addCertPathChecker(prc);
107-
CertificateFactory cf = CertificateFactory.getInstance("X.509");
108-
CertPath cp = cf.generateCertPath(List.of(eeCert));
109-
cpv.validate(cp, params);
110-
111-
// unwrap soft fail exceptions and check for SocketTimeoutException
112-
List<CertPathValidatorException> softExc = prc.getSoftFailExceptions();
113-
if (expected) {
114-
if (softExc.size() > 0) {
115-
throw new RuntimeException("Expected to pass, found " +
116-
softExc.size() + " soft fail exceptions");
91+
try {
92+
if (args[0] != null) {
93+
ocspTimeout = Integer.parseInt(args[0]);
11794
}
118-
} else {
119-
// If we expect to fail the validation then there should be a
120-
// SocketTimeoutException
121-
boolean found = false;
122-
for (CertPathValidatorException softFail : softExc) {
123-
log("CPVE: " + softFail);
124-
Throwable cause = softFail.getCause();
125-
log("Cause: " + cause);
126-
while (cause != null) {
127-
if (cause instanceof SocketTimeoutException) {
128-
found = true;
129-
break;
95+
rootOcsp.setDelay(ocspTimeout);
96+
97+
expected = (args[1] != null && Boolean.parseBoolean(args[1]));
98+
log("Test case expects to " + (expected ? "pass" : "fail"));
99+
100+
// validate chain
101+
CertPathValidator cpv = CertPathValidator.getInstance("PKIX");
102+
PKIXRevocationChecker prc =
103+
(PKIXRevocationChecker) cpv.getRevocationChecker();
104+
prc.setOptions(EnumSet.of(NO_FALLBACK, SOFT_FAIL));
105+
PKIXParameters params =
106+
new PKIXParameters(Set.of(new TrustAnchor(rootCert, null)));
107+
params.addCertPathChecker(prc);
108+
CertificateFactory cf = CertificateFactory.getInstance("X.509");
109+
CertPath cp = cf.generateCertPath(List.of(eeCert));
110+
cpv.validate(cp, params);
111+
112+
// unwrap soft fail exceptions and check for SocketTimeoutException
113+
List<CertPathValidatorException> softExc = prc.getSoftFailExceptions();
114+
if (expected) {
115+
if (!softExc.isEmpty()) {
116+
log("Expected to pass, found " + softExc.size() +
117+
" soft fail exceptions");
118+
for (CertPathValidatorException cpve : softExc) {
119+
log("Exception: " + cpve);
130120
}
131-
cause = cause.getCause();
121+
throw new RuntimeException("Expected to pass, found " +
122+
softExc.size() + " soft fail exceptions");
132123
}
133-
if (found) {
134-
break;
124+
} else {
125+
// If we expect to fail the validation then there should be a
126+
// SocketTimeoutException
127+
boolean found = false;
128+
for (CertPathValidatorException softFail : softExc) {
129+
log("CPVE: " + softFail);
130+
Throwable cause = softFail.getCause();
131+
log("Cause: " + cause);
132+
while (cause != null) {
133+
if (cause instanceof SocketTimeoutException) {
134+
found = true;
135+
break;
136+
}
137+
cause = cause.getCause();
138+
}
139+
if (found) {
140+
break;
141+
}
135142
}
136-
}
137143

138-
if (!found) {
139-
throw new RuntimeException("SocketTimeoutException not thrown");
144+
if (!found) {
145+
throw new RuntimeException("SocketTimeoutException not thrown");
146+
}
140147
}
148+
} finally {
149+
rootOcsp.stop();
150+
rootOcsp.shutdownNow();
141151
}
142152
}
143153

‎test/jdk/java/security/testlibrary/SimpleOCSPServer.java

+14-2
Original file line numberDiff line numberDiff line change
@@ -572,8 +572,8 @@ public void setDisableContentLength(boolean isDisabled) {
572572
*/
573573
private synchronized void log(String message) {
574574
if (logEnabled || debug != null) {
575-
System.out.println("[" + Thread.currentThread().getName() + "]: " +
576-
message);
575+
System.out.println("[" + Thread.currentThread().getName() + "][" +
576+
System.currentTimeMillis() + "]: " + message);
577577
}
578578
}
579579

@@ -727,6 +727,7 @@ public void run() {
727727
// wait out the delay here before any other processing.
728728
try {
729729
if (delayMsec > 0) {
730+
log("Delaying response for " + delayMsec + " milliseconds.");
730731
Thread.sleep(delayMsec);
731732
}
732733
} catch (InterruptedException ie) {
@@ -908,6 +909,13 @@ private LocalOcspRequest parseHttpOcspPost(InputStream inStream)
908909
*/
909910
private LocalOcspRequest parseHttpOcspGet(String[] headerTokens,
910911
InputStream inStream) throws IOException, CertificateException {
912+
// Display the whole request
913+
StringBuilder sb = new StringBuilder("OCSP GET REQUEST\n");
914+
for (String hTok : headerTokens) {
915+
sb.append(hTok).append("\n");
916+
}
917+
log(sb.toString());
918+
911919
// Before we process the remainder of the GET URL, we should drain
912920
// the InputStream of any other header data. We (for now) won't
913921
// use it, but will display the contents if logging is enabled.
@@ -1000,6 +1008,10 @@ private LocalOcspRequest(byte[] requestBytes) throws IOException,
10001008
CertificateException {
10011009
Objects.requireNonNull(requestBytes, "Received null input");
10021010

1011+
// Display the DER encoding before parsing
1012+
log("Local OCSP Request Constructor, parsing bytes:\n" +
1013+
dumpHexBytes(requestBytes));
1014+
10031015
DerInputStream dis = new DerInputStream(requestBytes);
10041016

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

0 commit comments

Comments
 (0)