8350689: Turn on timestamp and thread metadata by default for java.security.debug

Reviewed-by: mullan
This commit is contained in:
Sean Coffey 2025-06-04 09:41:51 +00:00
parent cd16b68962
commit 42f48a39e8
5 changed files with 55 additions and 170 deletions

View File

@ -52,24 +52,10 @@
<p> To monitor security access, you can set the <code>java.security.debug</code>
system property, which determines what trace messages are printed during
execution. The value of the property is one or more options separated by a
comma.
comma. Each trace message includes the thread id, caller information, and
timestamp.
</p>
<h2>Printing Thread and Timestamp Information</h2>
<p>
You can append the following strings to any option specified in the
<code>java.security.debug</code> system property to print additional
information:
<ul>
<li><code>+thread</code>: Print thread and caller information</li>
<li><code>+timestamp</code>: Print timestamp information</li>
</ul>
<p>
For example, to add thread, caller, and timestamp information to all
debugging output, set the <code>java.security.debug</code> system property
on the command line as follows:
<pre><code>java -Djava.security.debug=all+thread+timestamp MyApp</code></pre>
<p>The following table lists the <code>java.security.debug</code> options:</p>
<table id="debug">

View File

@ -41,14 +41,7 @@ import java.util.Locale;
public class Debug {
private String prefix;
private boolean printDateTime;
private boolean printThreadDetails;
private static String args;
private static boolean threadInfoAll;
private static boolean timeStampInfoAll;
private static final String TIMESTAMP_OPTION = "+timestamp";
private static final String THREAD_OPTION = "+thread";
static {
args = System.getProperty("java.security.debug");
@ -66,16 +59,6 @@ public class Debug {
args = args.toLowerCase(Locale.ENGLISH);
if (args.equals("help")) {
Help();
} else if (args.contains("all")) {
// "all" option has special handling for decorator options
// If the thread or timestamp decorator option is detected
// with the "all" option, then it impacts decorator options
// for other categories
int beginIndex = args.lastIndexOf("all") + "all".length();
int commaIndex = args.indexOf(',', beginIndex);
if (commaIndex == -1) commaIndex = args.length();
threadInfoAll = args.substring(beginIndex, commaIndex).contains(THREAD_OPTION);
timeStampInfoAll = args.substring(beginIndex, commaIndex).contains(TIMESTAMP_OPTION);
}
}
}
@ -106,11 +89,6 @@ public class Debug {
System.err.println("ts timestamping");
System.err.println("x509 X.509 certificate debugging");
System.err.println();
System.err.println("+timestamp can be appended to any of above options to print");
System.err.println(" a timestamp for that debug option");
System.err.println("+thread can be appended to any of above options to print");
System.err.println(" thread and caller information for that debug option");
System.err.println();
System.err.println("The following can be used with provider:");
System.err.println();
System.err.println("engine=<engines>");
@ -151,7 +129,6 @@ public class Debug {
if (isOn(option)) {
Debug d = new Debug();
d.prefix = prefix;
d.configureExtras(option);
return d;
} else {
return null;
@ -166,32 +143,6 @@ public class Debug {
.findFirst().orElse("unknown caller"));
}
// parse an option string to determine if extra details,
// like thread and timestamp, should be printed
private void configureExtras(String option) {
// treat "all" as special case, only used for java.security.debug property
this.printDateTime = timeStampInfoAll;
this.printThreadDetails = threadInfoAll;
if (printDateTime && printThreadDetails) {
// nothing left to configure
return;
}
// args is converted to lower case for the most part via marshal method
int optionIndex = args.lastIndexOf(option);
if (optionIndex == -1) {
// option not in args list. Only here since "all" was present
// in debug property argument. "all" option already parsed
return;
}
int beginIndex = optionIndex + option.length();
int commaIndex = args.indexOf(',', beginIndex);
if (commaIndex == -1) commaIndex = args.length();
String subOpt = args.substring(beginIndex, commaIndex);
printDateTime = printDateTime || subOpt.contains(TIMESTAMP_OPTION);
printThreadDetails = printThreadDetails || subOpt.contains(THREAD_OPTION);
}
/**
* Get a Debug object corresponding to the given option on the given
@ -208,11 +159,6 @@ public class Debug {
* Debug debug = Debug.of("login", property);
* }
*
* +timestamp string can be appended to property value
* to print timestamp information. (e.g. true+timestamp)
* +thread string can be appended to property value
* to print thread and caller information. (e.g. true+thread)
*
* @param prefix the debug option name
* @param property debug setting for this option
* @return a new Debug object if the property is true
@ -221,8 +167,6 @@ public class Debug {
if (property != null && property.toLowerCase(Locale.ROOT).startsWith("true")) {
Debug d = new Debug();
d.prefix = prefix;
d.printThreadDetails = property.contains(THREAD_OPTION);
d.printDateTime = property.contains(TIMESTAMP_OPTION);
return d;
}
return null;
@ -285,23 +229,18 @@ public class Debug {
}
/**
* If thread debug option enabled, include information containing
* hex value of threadId and the current thread name
* If timestamp debug option enabled, include timestamp string
* @return extra info if debug option enabled.
* Include information containing:
* - hex value of threadId
* - the current thread name
* - timestamp string
* @return String with above metadata
*/
private String extraInfo() {
String retString = "";
if (printThreadDetails) {
retString = "0x" + Long.toHexString(
Thread.currentThread().threadId()).toUpperCase(Locale.ROOT) +
"|" + Thread.currentThread().getName() + "|" + formatCaller();
}
if (printDateTime) {
retString += (retString.isEmpty() ? "" : "|")
+ FormatHolder.DATE_TIME_FORMATTER.format(Instant.now());
}
return retString.isEmpty() ? "" : "[" + retString + "]";
return String.format("[0x%s|%s|%s|%s]",
Long.toHexString(Thread.currentThread().threadId()).toUpperCase(Locale.ROOT),
Thread.currentThread().getName(),
formatCaller(),
FormatHolder.DATE_TIME_FORMATTER.format(Instant.now()));
}
/**

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2024, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2024, 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
@ -47,8 +47,8 @@ public class LoginModuleDebug {
// debug option set to true - no extra info
Arguments.of("debug",
"true",
"krb5loginmodule:",
"krb5loginmodule\\["),
"krb5loginmodule\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
"krb5loginmodule:"),
// debug option set to false
Arguments.of("debug",
"false",
@ -59,19 +59,9 @@ public class LoginModuleDebug {
"bar",
"",
"krb5loginmodule"),
// thread info only
// test for thread and timestamp info
Arguments.of("debug",
"true+thread",
"krb5loginmodule\\[.*\\|main|\\.*java.*]:",
"\\|" + DATE_REGEX + ".*\\]:"),
// timestamp info only
Arguments.of("debug",
"true+timestamp",
"krb5loginmodule\\[" + DATE_REGEX + ".*\\]",
"\\|main\\]:"),
// both thread and timestamp
Arguments.of("debug",
"true+timestamp+thread",
"krb5loginmodule\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
"krb5loginmodule:")
);
@ -104,4 +94,4 @@ public class LoginModuleDebug {
new Subject(), null, Map.of(), Map.of(args[0], args[1]));
}
}
}
}

View File

@ -51,8 +51,11 @@ public class DebugPropertyValuesTest extends SSLSocketTemplate {
private static final Path LOG_FILE = Path.of("logging.conf");
private static final HashMap<String, List<String>> debugMessages = new HashMap<>();
private static final String DATE_REGEX = "\\d{4}-\\d{2}-\\d{2}";
static {
debugMessages.put("handshake",
List.of("Produced ClientHello handshake message",
"supported_versions"));
@ -74,10 +77,10 @@ public class DebugPropertyValuesTest extends SSLSocketTemplate {
debugMessages.put("help",
List.of("print the help messages",
"debugging can be widened with:"));
debugMessages.put("javax.net.debug",
List.of("properties: Initial security property:",
"certpath: Cert path validation succeeded"));
debugMessages.put("logger",
debugMessages.put("java.security.debug",
List.of("properties\\[.*\\|main\\|.*" + DATE_REGEX + ".*\\]:",
"certpath\\[.*\\|main\\|.*" + DATE_REGEX + ".*\\]:"));
debugMessages.put("javax.net.debug.logger",
List.of("FINE: adding as trusted certificates",
"FINE: WRITE: TLSv1.3 application_data"));
}
@ -151,14 +154,15 @@ public class DebugPropertyValuesTest extends SSLSocketTemplate {
// add in javax.net.debug sanity test
Arguments.of(List.of("-Djavax.net.debug=ssl:trustmanager",
"-Djava.security.debug=all"),
List.of("handshake", "javax.net.debug", "keymanager",
List.of("handshake", "java.security.debug", "keymanager",
"record", "session", "ssl", "sslctx",
"trustmanager", "verbose")),
// empty invokes System.Logger use
Arguments.of(List.of("-Djavax.net.debug",
"-Djava.util.logging.config.file=" + LOG_FILE),
List.of("handshake", "keymanager", "logger", "packet",
"plaintext", "record", "session", "ssl",
List.of("handshake", "javax.net.debug.logger",
"keymanager", "packet", "plaintext",
"record", "session", "ssl",
"sslctx", "trustmanager", "verbose"))
);
}

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2024, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2024, 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
@ -23,7 +23,7 @@
/*
* @test
* @bug 8051959
* @bug 8051959 8350689
* @summary Option to print extra information in java.security.debug output
* @library /test/lib
* @run junit DebugOptions
@ -43,75 +43,41 @@ import jdk.test.lib.process.ProcessTools;
public class DebugOptions {
static final String DATE_REGEX = "\\d{4}-\\d{2}-\\d{2}";
static final String EXPECTED_PROP_REGEX =
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:";
static final String EXPECTED_PROP_KEYSTORE_REGEX =
"properties\\[.*\\|main|" + DATE_REGEX +
".*\\Rkeystore\\[.*\\|main|" + DATE_REGEX + ".*\\]:";
static final String EXPECTED_ALL_REGEX =
"properties\\[.*\\|main.*\\|" + DATE_REGEX +
".*\\]((.*\\R)*)keystore\\[.*\\|main.*\\|"
+ DATE_REGEX + ".*\\]:";
private static Stream<Arguments> patternMatches() {
return Stream.of(
// no extra info present
// test for thread and timestamp info
Arguments.of("properties",
"properties: Initial",
"properties\\["),
// thread info only
EXPECTED_PROP_REGEX,
"properties:"),
// test for thread and timestamp info
Arguments.of("properties+thread",
"properties\\[.*\\|main\\|.*java.*]:",
"properties\\[" + DATE_REGEX),
// timestamp info only
Arguments.of("properties+timestamp",
"properties\\[" + DATE_REGEX + ".*\\]",
"\\|main\\]:"),
// both thread and timestamp
Arguments.of("properties+timestamp+thread",
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
EXPECTED_PROP_REGEX,
"properties:"),
// flip the arguments of previous test
Arguments.of("properties+thread+timestamp",
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
EXPECTED_PROP_REGEX,
"properties:"),
// comma not valid separator, ignore extra info printing request
Arguments.of("properties,thread,timestamp",
"properties:",
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:"),
// no extra info for keystore debug prints
Arguments.of("properties+thread+timestamp,keystore",
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
"keystore\\["),
// flip arguments around in last test - same outcome expected
Arguments.of("keystore,properties+thread+timestamp",
"properties\\[.*\\|main|" + DATE_REGEX + ".*\\]:",
"keystore\\["),
// turn on thread info for both keystore and properties components
Arguments.of("keystore+thread,properties+thread",
"properties\\[.*\\|main|.*\\Rkeystore\\[.*\\|main|.*\\]:",
"\\|" + DATE_REGEX + ".*\\]:"),
// same as above with erroneous comma at end of string. same output expected
Arguments.of("keystore+thread,properties+thread,",
"properties\\[.*\\|main|.*\\Rkeystore\\[.*\\|main|.*\\]:",
"\\|" + DATE_REGEX + ".*\\]:"),
// turn on thread info for properties and timestamp for keystore
Arguments.of("keystore+timestamp,properties+thread",
"properties\\[.*\\|main|.*\\Rkeystore\\[" + DATE_REGEX + ".*\\]:",
"properties\\[.*\\|" + DATE_REGEX + ".*\\]:"),
// turn on thread info for all components
// regular keystore,properties component string
Arguments.of("keystore,properties",
EXPECTED_PROP_KEYSTORE_REGEX,
"properties:"),
// turn on all
Arguments.of("all",
EXPECTED_ALL_REGEX,
"properties:"),
// expect thread and timestamp info
Arguments.of("all+thread",
"properties\\[.*\\|main.*((.*\\R)*)keystore\\[.*\\|main.*java.*\\]:",
"properties\\[" + DATE_REGEX + ".*\\]:"),
// turn on thread info and timestamp for all components
Arguments.of("all+thread+timestamp",
"properties\\[.*\\|main.*\\|" + DATE_REGEX +
".*\\]((.*\\R)*)keystore\\[.*\\|main.*\\|" + DATE_REGEX + ".*\\]:",
"properties:"),
// all decorator option should override other component options
Arguments.of("all+thread+timestamp,properties",
"properties\\[.*\\|main.*\\|" + DATE_REGEX +
".*\\]((.*\\R)*)keystore\\[.*\\|main.*\\|" + DATE_REGEX + ".*\\]:",
"properties:"),
// thread details should only be printed for properties option
Arguments.of("properties+thread,all",
"properties\\[.*\\|main\\|.*\\]:",
"keystore\\[.*\\|main\\|.*\\]:"),
// thread details should be printed for all statements
Arguments.of("properties,all+thread",
"properties\\[.*\\|main.*java" +
".*\\]((.*\\R)*)keystore\\[.*\\|main.*java.*\\]:",
EXPECTED_ALL_REGEX,
"properties:")
);
}