Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add option to print debug logs in JSON format #187

Merged
merged 1 commit into from
Sep 20, 2024
Merged
Show file tree
Hide file tree
Changes from all 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
30 changes: 30 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -219,6 +219,7 @@ and what each enables.
| --- | --- | --- | --- |
| wolfssl.debug | "false" | "true" | Enables native wolfSSL debug logging |
| wolfjsse.debug | "false" | "true | Enables wolfJSSE debug logging |
| wolfjsse.debugFormat | | "JSON" | Switches debug output format |
| wolfsslengine.debug | "false" | "true" | Enables SSLEngine debug logging |
| wolfsslengine.io.debug | "false" | "true" | Enables SSLEngine I/O bytes log |

Expand All @@ -240,6 +241,35 @@ System.setProperty("wolfsslengine.debug", "true);

JDK debug logging can be enabled using the `-Djavax.net.debug=all` option.

### JSON Log Message Format

Debug messages can be output in JSON format for consumption by tools such as
DataDog. Setting the following System property to "JSON" will cause all debug
messages to print in JSON instead of the default text output:

```
System.setProperty("wolfjsse.debugFormat", "JSON");
```

This can also be specified at runtime on the command line like so:

```
-Dwolfjsse.debug=true -Dwolfjsse.debugFormat=JSON
```

Debug messages will look similar to the following when output in JSON format:

```
{
"@timestamp": "2024-04-05 11:13:07.193",
"level": "INFO",
"logger_name": "wolfJSSE",
"message": "[ WolfSSLTrustManager] entered engineInit()",
"thread_name": "main",:
"thread_id": "1"
}
```

## Building for Android

wolfSSL JNI and JSSE can be built and used on the Android platform, either
Expand Down
147 changes: 130 additions & 17 deletions src/java/com/wolfssl/provider/jsse/WolfSSLDebug.java
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,19 @@
public class WolfSSLDebug {

/**
* boolean to check if debug mode is on
* Check if debug mode is on.
*
* Is true if "wolfjsse.debug" is set to "true", otherwise false.
*/
public static final boolean DEBUG = checkProperty();

/**
* Check if JSON debug mode is on.
*
* Is true if "wolfjsse.debugFormat" is set to "JSON", otherwise false.
*/
public static final boolean DEBUG_JSON = jsonOutEnabled();

/**
* Error level debug message
*/
Expand All @@ -58,6 +67,11 @@ public class WolfSSLDebug {
*/
private static WolfSSLNativeLoggingCallback nativeLogCb = null;

/**
* Check if "wolfjsse.debug" System property is set to "true".
*
* @return true if set to "true", otherwise return false
*/
private static boolean checkProperty() {

String enabled = System.getProperty("wolfjsse.debug");
Expand All @@ -69,6 +83,22 @@ private static boolean checkProperty() {
return false;
}

/**
* Check if "wolfjsse.debugFormat" is set to "JSON".
*
* @return true if set to "JSON", otherwise false.
*/
private static boolean jsonOutEnabled() {

String enabled = System.getProperty("wolfjsse.debugFormat");

if ((enabled != null) && (enabled.equalsIgnoreCase("JSON"))) {
return true;
}

return false;
}

/**
* Prints out a message to the console
* @param string message to be printed
Expand All @@ -77,25 +107,102 @@ public static void print(String string) {
System.out.println("wolfJSSE: " + string);
}

/**
* Internal method to print debug message as JSON for consumption by
* tools such as DataDog.
*/
private static synchronized void logJSON(String tag, String msg,
long threadID, String threadName, String className) {

System.out.printf(
"{\n" +
" \"@timestamp\": \"%s\",\n" +
" \"level\": \"%s\",\n" +
" \"logger_name\": \"wolfJSSE\",\n" +
" \"message\": \"%s\",\n" +
" \"thread_name\": \"%s\",:\n" +
" \"thread_id\": \"%s\"\n" +
"}\n",
new Timestamp(new java.util.Date().getTime()),
tag, "[" + className + "] " + msg,
threadID, threadName
);
}

/**
* Internal method to print debug message with byte array hex as JSON,
* for consumption by tools such as DataDog.
*/
private static synchronized void logJSONHex(String tag, String label,
long threadID, String threadName, String className, byte[] in, int sz) {

/* Convert byte[] to hex string */
StringBuilder builder = new StringBuilder();
for (byte b: in) {
builder.append(String.format("%02X", b));
}

logJSON(tag, label + " [" + sz + "]: " + builder.toString(), threadID,
threadName, className);
}

/**
* Checks if debugging is turned on and prints out the message.
*
* Output format can be controlled with the "wolfjsse.debugFormat"
* System property. If not set, default debug output format will be used.
* If set to "JSON", all debug logs will be output in the following JSON
* format, which can be read by DataDog:
*
* {
* "@timestamp": "2024-04-05 11:13:07.193",
* "level": "INFO",
* "logger_name": "wolfJSSE",
* "message": "debug message",
* "thread_name": "thread_name",:
* "thread_id": "thread_ID"
* }
*
* @param cl class being called from to get debug info
* @param tag level of debug message i.e. WolfSSLDebug.INFO
* @param string message to be printed out
*/
public static synchronized void log(Class cl, String tag, String string) {
if (DEBUG) {
System.out.println(new Timestamp(new java.util.Date().getTime()) +
" [wolfJSSE " + tag + ": TID " +
Thread.currentThread().getId() + ": " +
cl.getSimpleName() + "] " + string);

long threadID = Thread.currentThread().getId();
String threadName = Thread.currentThread().getName();
String className = cl.getSimpleName();

if (DEBUG_JSON) {
logJSON(tag, string, threadID, threadName, className);
}
else {
System.out.println(
new Timestamp(new java.util.Date().getTime()) +
" [wolfJSSE " + tag + ": TID " + threadID + ": " +
className + "] " + string);
}
}
}

/**
* Print out a byte array in hex if debugging is enabled.
*
* Output format can be controlled with the "wolfjsse.debugFormat"
* System property. If not set, default debug output format will be used.
* If set to "JSON", all debug logs will be output in the following JSON
* format, which can be read by DataDog:
*
* {
* "@timestamp": "2024-04-05 11:13:07.193",
* "level": "INFO",
* "logger_name": "wolfJSSE",
* "message": "label [sz]: array hex string",
* "thread_name": "thread_name",:
* "thread_id": "thread_ID"
* }
*
* @param cl class this method is being called from
* @param tag level of debug message i.e. WolfSSLDebug.INFO
* @param label label string to print with hex
Expand All @@ -107,26 +214,32 @@ public static synchronized void logHex(Class cl, String tag, String label,
if (DEBUG) {
int i = 0, j = 0;
int printSz = 0;
long tid = Thread.currentThread().getId();
String clName = null;
long threadID = Thread.currentThread().getId();
String threadName = Thread.currentThread().getName();
String className = null;

if (cl == null || in == null || sz == 0) {
return;
}
clName = cl.getSimpleName();
className = cl.getSimpleName();
printSz = Math.min(in.length, sz);

System.out.print("[wolfJSSE " + tag + ": TID " + tid + ": " +
clName + "] " + label + " [" + sz + "]: ");
for (i = 0; i < printSz; i++) {
if ((i % 16) == 0) {
System.out.printf("\n[wolfJSSE " + tag + ": TID " +
tid + ": " + clName + "] %06X", j * 8);
j++;
if (DEBUG_JSON) {
logJSONHex(tag, label, threadID, threadName, className, in, sz);
}
else {
System.out.print("[wolfJSSE " + tag + ": TID " + threadID +
": " + className + "] " + label + " [" + sz + "]: ");
for (i = 0; i < printSz; i++) {
if ((i % 16) == 0) {
System.out.printf("\n[wolfJSSE " + tag + ": TID " +
threadID + ": " + className + "] %06X", j * 8);
j++;
}
System.out.printf(" %02X ", in[i]);
}
System.out.printf(" %02X ", in[i]);
System.out.println("");
}
System.out.println("");
}
}

Expand Down