From 6d77947ed5ddf8be37c63e568cf74416ad7c7d35 Mon Sep 17 00:00:00 2001 From: Chris Conlon Date: Wed, 10 Apr 2024 10:33:32 -0600 Subject: [PATCH] JSSE: add new wolfjsse.debugFormat=JSON option for printing debug logs in JSON format --- README.md | 30 ++++ .../wolfssl/provider/jsse/WolfSSLDebug.java | 147 ++++++++++++++++-- 2 files changed, 160 insertions(+), 17 deletions(-) diff --git a/README.md b/README.md index 60b1b4bd..964125ef 100644 --- a/README.md +++ b/README.md @@ -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 | @@ -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 diff --git a/src/java/com/wolfssl/provider/jsse/WolfSSLDebug.java b/src/java/com/wolfssl/provider/jsse/WolfSSLDebug.java index 973b48a7..070f29f8 100644 --- a/src/java/com/wolfssl/provider/jsse/WolfSSLDebug.java +++ b/src/java/com/wolfssl/provider/jsse/WolfSSLDebug.java @@ -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 */ @@ -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"); @@ -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 @@ -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 @@ -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(""); } }