Skip to content
Open
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2015, 2023, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2015, 2025, 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 @@ -391,8 +391,7 @@ public static void logError(String s, Object... s1) {

public static void logError(Throwable t) {
if (errors()) {
String s = Utils.stackTrace(t);
logger.log(Level.INFO, "ERROR: " + s);
logger.log(Level.INFO, "ERROR: " + t, t);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
logger.log(Level.INFO, "ERROR: " + t, t);
logger.log(Level.INFO, "ERROR:", t);

}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -591,6 +591,11 @@ public void failHandshakeCFs(final Throwable cause) {
SSLHandshakeException sslHandshakeException = null;
if (!handshakeCF.isDone()) {
sslHandshakeException = sslHandshakeException(cause);
if (Log.errors()) {
Log.logError("%s QUIC handshake failed: %s"
.formatted(logTag(), message(cause)));
Log.logError(cause);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This produces 2 error messages like:

Nov 07, 2025 6:01:57 PM jdk.internal.net.http.quic.QuicConnectionImpl$HandshakeFlow failHandshakeCFs
INFO: ERROR: QuicServerConnection(1) QUIC handshake failed: java.io.IOException: Connection closed by client peer: CRYPTO_ERROR|certificate_unknown certificate_unknown
Nov 07, 2025 6:01:57 PM jdk.internal.net.http.quic.QuicConnectionImpl$HandshakeFlow failHandshakeCFs
INFO: ERROR: java.io.IOException: Connection closed by client peer: CRYPTO_ERROR|certificate_unknown certificate_unknown
java.io.IOException: Connection closed by client peer: CRYPTO_ERROR|certificate_unknown certificate_unknown
	at java.net.http/jdk.internal.net.http.quic.TerminationCause.toReportedCause(TerminationCause.java:129)

Can we remove the duplicate information? Currently there are 2 timestamps, and the exception message is printed 3 times.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have considered this. This would require adding a new logError metod to Log:

    public void logError(String msg, Throwable throwable) {
         ....
    } 

I refrained from doing that because there may be place where we call logError with a message and a throwable and don't expect to see the stack trace. That would require examining all such call sites and cast the Throwable to Object - or add a call to toString() - so that they keep on calling logError(String, Object...).

I'd rather do that in a separate cleanup.

FWIW - what you are seeing in the quoted log are a mix of client traces and server traces: the message on the server talks of the client peer

}
handshakeCF.completeExceptionally(sslHandshakeException);
}
if (!handshakeReachedPeerCF.isDone()) {
Expand All @@ -608,6 +613,12 @@ private SSLHandshakeException sslHandshakeException(final Throwable cause) {
return new SSLHandshakeException("QUIC connection establishment failed", cause);
}

private String message(Throwable cause) {
String message = cause.getMessage();
if (message != null && !message.isEmpty()) return message;
return cause.toString();
}

/**
* Marks the start of a handshake.
* @throws IllegalStateException If handshake has already started
Expand Down
175 changes: 175 additions & 0 deletions test/jdk/java/net/httpclient/http3/H3LogHandshakeErrors.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,175 @@
/*
* Copyright (c) 2025, 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
* under the terms of the GNU General Public License version 2 only, as
* published by the Free Software Foundation.
*
* This code is distributed in the hope that it will be useful, but WITHOUT
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
* version 2 for more details (a copy is included in the LICENSE file that
* accompanied this code).
*
* You should have received a copy of the GNU General Public License version
* 2 along with this work; if not, write to the Free Software Foundation,
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
*
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
* or visit www.oracle.com if you need additional information or have any
* questions.
*/

import java.io.IOException;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse;
import java.net.http.HttpResponse.BodyHandlers;
import java.util.Arrays;
import java.util.Optional;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.logging.Level;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.logging.Handler;

import javax.net.ssl.SSLContext;

import jdk.httpclient.test.lib.common.HttpServerAdapters;
import jdk.internal.net.http.quic.QuicConnectionImpl;
import jdk.test.lib.net.SimpleSSLContext;
import org.testng.Assert;
import org.testng.annotations.AfterClass;
import org.testng.annotations.BeforeClass;
import org.testng.annotations.Test;

import static java.net.http.HttpClient.Builder.NO_PROXY;
import static java.net.http.HttpClient.Version.HTTP_3;
import static java.net.http.HttpOption.Http3DiscoveryMode.HTTP_3_URI_ONLY;
import static org.testng.Assert.*;

/*
* @test
* @bug 8371471
* @summary Verify that HTTP/3 handshake failures are logged if
* logging errors is enabled
* @library /test/lib /test/jdk/java/net/httpclient/lib
* @build jdk.test.lib.net.SimpleSSLContext
* jdk.httpclient.test.lib.common.HttpServerAdapters
* @run testng/othervm
* -Djdk.httpclient.HttpClient.log=errors
* H3LogHandshakeErrors
*/
// -Djava.security.debug=all
public class H3LogHandshakeErrors implements HttpServerAdapters {

private SSLContext sslContext;
private HttpTestServer h3Server;
private String requestURI;

@BeforeClass
public void beforeClass() throws Exception {
sslContext = new SimpleSSLContext().get();
if (sslContext == null) {
throw new AssertionError("Unexpected null sslContext");
}
// create an H3 only server
h3Server = HttpTestServer.create(HTTP_3_URI_ONLY, sslContext);
h3Server.addHandler((exchange) -> exchange.sendResponseHeaders(200, 0), "/hello");
h3Server.start();
System.out.println("Server started at " + h3Server.getAddress());
requestURI = "https://" + h3Server.serverAuthority() + "/hello";
}

@AfterClass
public void afterClass() throws Exception {
if (h3Server != null) {
System.out.println("Stopping server " + h3Server.getAddress());
h3Server.stop();
}
}

static String format(LogRecord record) {
String thrown = Optional.ofNullable(record.getThrown())
.map(t -> ": " + t).orElse("");
return "\n \"%s: %s %s: %s%s\"".formatted(
record.getLevel(),
record.getSourceClassName(),
record.getSourceMethodName(),
record.getMessage(),
thrown);
}

/**
* Issues a GET HTTP3 requests and verifies that the
* expected exception is logged.
*/
@Test
public void testErrorLogging() throws Exception {
// jdk.httpclient.HttpClient.log=errors must be enabled
// for this test
String logging = System.getProperty("jdk.httpclient.HttpClient.log", "");
var categories = Arrays.asList(logging.split(","));
assertTrue(categories.contains("errors"),
"'errors' not found in " + categories);

// create a client that doesn't have the server's
// certificate
final HttpClient client = newClientBuilderForH3()
.proxy(NO_PROXY)
.build();
final URI reqURI = new URI(requestURI);
final HttpRequest.Builder reqBuilder = HttpRequest.newBuilder(reqURI)
.version(HTTP_3);
Logger serverLogger = Logger.getLogger("jdk.httpclient.HttpClient");

CopyOnWriteArrayList<LogRecord> records = new CopyOnWriteArrayList<>();
Handler handler = new Handler() {
@Override
public void publish(LogRecord record) {
record.getSourceClassName();
records.add(record);
}
@Override public void flush() {}
@Override public void close() {
}
};
serverLogger.addHandler(handler);

try {
final HttpRequest req1 = reqBuilder.copy().GET().build();
System.out.println("Issuing request: " + req1);
final HttpResponse<Void> resp1 = client.send(req1, BodyHandlers.discarding());
Assert.assertEquals(resp1.statusCode(), 200, "unexpected response code for GET request");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry I missed htis in the previous round of review. Shouldn't this line be a fail("Request expected to fail but didn't")?

Copy link
Member Author

@dfuch dfuch Nov 7, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh sorry I meant to just remove this line. I thought it was better to not configure HTTP_3_URI_ONLY on the request in order to trigger the fallback on TCP. So something might actually respond. If something responds then we could get a response. On the other hand this might impacts other tests that might run on the machine...
hmmm... maybe I should fix that.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test now creates a TCP ServerSocket bound to the same port and which will close accepted connections. That should ensure safe fallback on TCP. If the ServerSocket cannot be created (address already in use) then the request will be configured with HTTP3_URI_ONLY to prevent fallback to TCP.

} catch (IOException io) {
System.out.println("Got expected exception: " + io);
} finally {
LogRecord expected = null;
// this is a bit fragile and may need to be updated if the
// place where we log the exception from changes.
String expectedClassName = QuicConnectionImpl.class.getName()
+ "$HandshakeFlow";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would just asserting for the (expected) log message and the presence of stacktrace be enough? Irrespective of which class logs it?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Possibly. Let's keep that for now.

for (var record : records) {
if (record.getLevel() != Level.INFO) continue;
if (!record.getMessage().contains("ERROR:")) continue;
if (record.getMessage().contains("client peer")) continue;
var expectedThrown = record.getThrown();
if (expectedThrown == null) continue;
if (!record.getSourceClassName().equals(expectedClassName)) continue;
if (expectedThrown.getMessage().contains("client peer")) continue;
expected = record;
break;
}
assertNotNull(expected, "No throwable for "
+ expectedClassName + " found in "
+ records.stream().map(H3LogHandshakeErrors::format).toList()
+ "\n ");
System.out.printf("Found expected exception: %s%n\t logged at: %s %s%n",
expected.getThrown(),
expected.getSourceClassName(),
expected.getSourceMethodName());
}
}
}