diff --git a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLogger.java b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLogger.java index 5680d8e1..755fcb52 100644 --- a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLogger.java +++ b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLogger.java @@ -38,8 +38,11 @@ import static com.kingsrook.qqq.backend.core.logging.LogUtils.logPair; /******************************************************************************* ** Access-Logger used for QJavalin handlers. ** - ** Can be disabled through the JavalinMetaData in the QJavalinImplementation - - ** See one of those 2 places for details (e.g., system properties). + ** Can be fully disabled through the JavalinMetaData object, or via system property: + ** qqq.javalin.loggerDisabled + * + ** Alternatively, individual log types and even actions can be enabled or disabled + ** via the logFilter in JavalinMetaData. ** ** Note - when working in this class - be overly aggressive with wrapping ** everything in try-catch, and not allowing exceptions to bubble. There isn't @@ -49,12 +52,38 @@ public class QJavalinAccessLogger { private static final QLogger LOG = QLogger.getLogger(QJavalinAccessLogger.class); + public static final String DISABLED_PROPERTY = "qqq.javalin.loggerDisabled"; + private static ThreadLocal requestStartTime = new ThreadLocal<>(); private static ThreadLocal requestActionName = new ThreadLocal<>(); private static ThreadLocal requestLogPairs = new ThreadLocal<>(); + /******************************************************************************* + ** Types of log entries - useful for a filter (from javalin meta data). + *******************************************************************************/ + public enum LogType + { + START, + END_SUCCESS, + END_SUCCESS_SLOW, + END_FAIL, + PROCESS_SUMMARY + } + + + + /******************************************************************************* + ** input to filter method (from javalin meta data), to decide if entry should be logged. + *******************************************************************************/ + public record LogEntry(LogType logType, String actionName) + { + + } + + + /******************************************************************************* ** *******************************************************************************/ @@ -62,7 +91,7 @@ public class QJavalinAccessLogger { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessStarts() && !QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { ///////////////////////////////////////////////////// // if we're not to log starts or ends, just return // @@ -72,11 +101,12 @@ public class QJavalinAccessLogger setThreadLocals(actionName, logPairs); - if(QJavalinImplementation.javalinMetaData.getLogAllAccessStarts()) + List pairList = new ArrayList<>(Arrays.asList(logPairs)); + pairList.add(0, logPair("action", actionName)); + pairList.add(0, logPair("access", "start")); + + if(shouldLog(new LogEntry(LogType.START, actionName))) { - List pairList = new ArrayList<>(Arrays.asList(logPairs)); - pairList.add(0, logPair("action", actionName)); - pairList.add(0, logPair("access", "start")); LOG.info(pairList); } } @@ -88,6 +118,49 @@ public class QJavalinAccessLogger + /******************************************************************************* + ** + *******************************************************************************/ + private static boolean shouldLog(LogEntry logEntry) + { + if(isLoggerDisabled()) + { + return (false); + } + + if(QJavalinImplementation.javalinMetaData != null && QJavalinImplementation.javalinMetaData.getLogFilter() != null) + { + return (QJavalinImplementation.javalinMetaData.getLogFilter().apply(logEntry)); + } + + return (true); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + private static boolean isLoggerDisabled() + { + ///////////////////////////////////////////////////////////////////////////////////// + // if there's no javalin metadata, then just read the disabled property ourselves, // + // and be disabled iff the property value is "true" // + ///////////////////////////////////////////////////////////////////////////////////// + if(QJavalinImplementation.javalinMetaData == null) + { + return System.getProperty(QJavalinAccessLogger.DISABLED_PROPERTY, "false").equals("true"); + } + + /////////////////////////////////////////////////////////////////////////////////////////////////// + // else, there is javalinMetaData, then let IT say if we're disabled. // + // note that will use the same system property by default, but it may be overridden via app code // + /////////////////////////////////////////////////////////////////////////////////////////////////// + return QJavalinImplementation.javalinMetaData.getLoggerDisabled(); + } + + + /******************************************************************************* ** *******************************************************************************/ @@ -105,10 +178,7 @@ public class QJavalinAccessLogger { try { - //////////////////////////////////////////////////////// - // only set the thread locals if we're doing log-ends // - //////////////////////////////////////////////////////// - if(QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(!isLoggerDisabled()) { requestActionName.set(actionName); requestStartTime.set(System.currentTimeMillis()); @@ -130,7 +200,7 @@ public class QJavalinAccessLogger { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { return; } @@ -145,7 +215,7 @@ public class QJavalinAccessLogger if(millis != null && millis > slowThreshold) { - logEnd("success", new ArrayList<>(Arrays.asList(logPairs))); + logEnd(LogType.END_SUCCESS_SLOW, "success", new ArrayList<>(Arrays.asList(logPairs))); } } catch(Exception e) @@ -163,13 +233,13 @@ public class QJavalinAccessLogger { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { return; } List pairList = new ArrayList<>(Arrays.asList(logPairs)); - logEnd("success", pairList); + logEnd(LogType.END_SUCCESS, "success", pairList); } catch(Exception e) { @@ -186,7 +256,7 @@ public class QJavalinAccessLogger { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { return; } @@ -194,7 +264,7 @@ public class QJavalinAccessLogger List pairList = new ArrayList<>(Arrays.asList(logPairs)); // pairList.add(0, logPair("exceptionMessage", t.getMessage())); // pairList.add(0, logPair("exceptionType", t.getClass().getSimpleName())); - logEnd("failure", pairList); + logEnd(LogType.END_FAIL, "failure", pairList); } catch(Exception e) { @@ -207,11 +277,11 @@ public class QJavalinAccessLogger /******************************************************************************* ** *******************************************************************************/ - private static void logEnd(String accessType, List pairList) + private static void logEnd(LogType logType, String accessType, List pairList) { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { return; } @@ -266,7 +336,10 @@ public class QJavalinAccessLogger return (false); }); - LOG.info(pairList); + if(shouldLog(new LogEntry(logType, actionName))) + { + LOG.info(pairList); + } } catch(Exception e) { @@ -293,7 +366,7 @@ public class QJavalinAccessLogger { try { - if(!QJavalinImplementation.javalinMetaData.getLogAllAccessEnds()) + if(isLoggerDisabled()) { return; } @@ -325,7 +398,7 @@ public class QJavalinAccessLogger } } - logEnd("processSummary", logPairs); + logEnd(LogType.PROCESS_SUMMARY, "processSummary", logPairs); } catch(Exception e) { diff --git a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinMetaData.java b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinMetaData.java index 06321225..e55db75c 100644 --- a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinMetaData.java +++ b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinMetaData.java @@ -22,6 +22,9 @@ package com.kingsrook.qqq.backend.javalin; +import java.util.function.Function; + + /******************************************************************************* ** MetaData specific to a QQQ Javalin server. *******************************************************************************/ @@ -29,8 +32,9 @@ public class QJavalinMetaData { private String uploadedFileArchiveTableName; - private boolean logAllAccessStarts = true; - private boolean logAllAccessEnds = true; + private boolean loggerDisabled = false; + + private Function logFilter; @@ -40,8 +44,7 @@ public class QJavalinMetaData *******************************************************************************/ public QJavalinMetaData() { - logAllAccessStarts = System.getProperty("qqq.javalin.logAllAccessStarts", "true").equals("true"); - logAllAccessEnds = System.getProperty("qqq.javalin.logAllAccessEnds", "true").equals("true"); + loggerDisabled = System.getProperty(QJavalinAccessLogger.DISABLED_PROPERTY, "false").equals("true"); } @@ -81,62 +84,62 @@ public class QJavalinMetaData /******************************************************************************* - ** Getter for logAllAccessStarts + ** Getter for loggerDisabled *******************************************************************************/ - public boolean getLogAllAccessStarts() + public boolean getLoggerDisabled() { - return (this.logAllAccessStarts); + return (this.loggerDisabled); } /******************************************************************************* - ** Setter for logAllAccessStarts + ** Setter for loggerDisabled *******************************************************************************/ - public void setLogAllAccessStarts(boolean logAllAccessStarts) + public void setLoggerDisabled(boolean loggerDisabled) { - this.logAllAccessStarts = logAllAccessStarts; + this.loggerDisabled = loggerDisabled; } /******************************************************************************* - ** Fluent setter for logAllAccessStarts + ** Fluent setter for loggerDisabled *******************************************************************************/ - public QJavalinMetaData withLogAllAccessStarts(boolean logAllAccessStarts) + public QJavalinMetaData withLoggerDisabled(boolean loggerDisabled) { - this.logAllAccessStarts = logAllAccessStarts; + this.loggerDisabled = loggerDisabled; return (this); } /******************************************************************************* - ** Getter for logAllAccessEnds + ** Getter for logFilter *******************************************************************************/ - public boolean getLogAllAccessEnds() + public Function getLogFilter() { - return (this.logAllAccessEnds); + return (this.logFilter); } /******************************************************************************* - ** Setter for logAllAccessEnds + ** Setter for logFilter *******************************************************************************/ - public void setLogAllAccessEnds(boolean logAllAccessEnds) + public void setLogFilter(Function logFilter) { - this.logAllAccessEnds = logAllAccessEnds; + this.logFilter = logFilter; } /******************************************************************************* - ** Fluent setter for logAllAccessEnds + ** Fluent setter for logFilter *******************************************************************************/ - public QJavalinMetaData withLogAllAccessEnds(boolean logAllAccessEnds) + public QJavalinMetaData withLogFilter(Function logFilter) { - this.logAllAccessEnds = logAllAccessEnds; + this.logFilter = logFilter; return (this); } diff --git a/qqq-middleware-javalin/src/test/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLoggerTest.java b/qqq-middleware-javalin/src/test/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLoggerTest.java index 332c6800..380df252 100644 --- a/qqq-middleware-javalin/src/test/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLoggerTest.java +++ b/qqq-middleware-javalin/src/test/java/com/kingsrook/qqq/backend/javalin/QJavalinAccessLoggerTest.java @@ -34,41 +34,152 @@ import com.kingsrook.qqq.backend.core.model.metadata.QInstance; import com.kingsrook.qqq.backend.core.processes.implementations.etl.streamedwithfrontend.StreamedETLWithFrontendProcess; import com.kingsrook.qqq.backend.core.utils.SleepUtils; import org.junit.jupiter.api.Test; +import static com.kingsrook.qqq.backend.javalin.QJavalinAccessLogger.DISABLED_PROPERTY; /******************************************************************************* ** Unit test for QJavalinAccessLogger + ** + ** Note - we're not injecting any kind of logger mock, so we aren't making any + ** assertions here - we're just verifying we don't blow up - other than that, + ** manually verify results by reviewing log *******************************************************************************/ class QJavalinAccessLoggerTest { + /******************************************************************************* ** *******************************************************************************/ @Test - void testTurnedOff() throws QInstanceValidationException + void testDefaultOn() throws QInstanceValidationException { QInstance qInstance = TestUtils.defineInstance(); - new QJavalinImplementation(qInstance, new QJavalinMetaData() - .withLogAllAccessStarts(false) - .withLogAllAccessEnds(false)); + new QJavalinImplementation(qInstance, new QJavalinMetaData()); + System.out.println("All should log"); QJavalinAccessLogger.logStart("test"); QJavalinAccessLogger.logEndSuccess(); QJavalinAccessLogger.logEndFail(new Exception()); - QJavalinAccessLogger.logEndSuccessIfSlow(1000); + + QJavalinAccessLogger.logStart("testSlow"); + QJavalinAccessLogger.logEndSuccessIfSlow(-1); + QJavalinAccessLogger.logProcessSummary("testProcess", UUID.randomUUID().toString(), new RunProcessOutput()); } + /******************************************************************************* + ** + *******************************************************************************/ + @Test + void testTurnedOffByCode() throws QInstanceValidationException + { + QInstance qInstance = TestUtils.defineInstance(); + new QJavalinImplementation(qInstance, new QJavalinMetaData() + .withLoggerDisabled(true)); + + System.out.println("Nothing should log"); + QJavalinAccessLogger.logStart("test"); + QJavalinAccessLogger.logEndSuccess(); + QJavalinAccessLogger.logEndFail(new Exception()); + + QJavalinAccessLogger.logStart("testSlow"); + QJavalinAccessLogger.logEndSuccessIfSlow(-1); + + QJavalinAccessLogger.logProcessSummary("testProcess", UUID.randomUUID().toString(), new RunProcessOutput()); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + @Test + void testTurnedOffBySystemPropertyWithJavalinMetaData() throws QInstanceValidationException + { + System.setProperty(DISABLED_PROPERTY, "true"); + QInstance qInstance = TestUtils.defineInstance(); + new QJavalinImplementation(qInstance, new QJavalinMetaData()); + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("test"); + System.clearProperty(DISABLED_PROPERTY); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + @Test + void testTurnedOffBySystemPropertyWithoutJavalinMetaData() throws QInstanceValidationException + { + System.setProperty(DISABLED_PROPERTY, "true"); + QInstance qInstance = TestUtils.defineInstance(); + new QJavalinImplementation(qInstance); + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("test"); + System.clearProperty(DISABLED_PROPERTY); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + @Test + void testFilter() throws QInstanceValidationException + { + QInstance qInstance = TestUtils.defineInstance(); + new QJavalinImplementation(qInstance, new QJavalinMetaData() + .withLoggerDisabled(false) + .withLogFilter(logEntry -> + switch(logEntry.logType()) + { + case START, PROCESS_SUMMARY -> false; + case END_SUCCESS, END_SUCCESS_SLOW -> true; + case END_FAIL -> logEntry.actionName().startsWith("yes"); + })); + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("test"); // shouldn't log + System.out.println("should log"); + QJavalinAccessLogger.logEndSuccess(); // SHOULD log + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("no"); // shouldn't log + System.out.println("shouldn't log"); + QJavalinAccessLogger.logEndFail(new Exception()); // shouldn't log + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("yes"); // shouldn't log + System.out.println("should log"); + QJavalinAccessLogger.logEndFail(new Exception()); // SHOULD log + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logStart("testSlow"); // shouldn't log + System.out.println("should log"); + QJavalinAccessLogger.logEndSuccessIfSlow(-1); // SHOULD log + + System.out.println("shouldn't log"); + QJavalinAccessLogger.logProcessSummary("testProcess", UUID.randomUUID().toString(), new RunProcessOutput()); // shouldn't log + } + + + /******************************************************************************* ** *******************************************************************************/ @Test void testSlow() { + System.out.println("should log"); QJavalinAccessLogger.logStart("test"); + + System.out.println("should log"); SleepUtils.sleep(2, TimeUnit.MILLISECONDS); QJavalinAccessLogger.logEndSuccessIfSlow(1); } @@ -85,12 +196,14 @@ class QJavalinAccessLoggerTest runProcessOutput.addValue(StreamedETLWithFrontendProcess.FIELD_VALIDATION_SUMMARY, new ArrayList<>(List.of( new ProcessSummaryLine(Status.OK, 5, "Test") ))); + System.out.println("should log"); QJavalinAccessLogger.logProcessSummary("testProcess", UUID.randomUUID().toString(), runProcessOutput); runProcessOutput = new RunProcessOutput(); runProcessOutput.addValue(StreamedETLWithFrontendProcess.FIELD_PROCESS_SUMMARY, new ArrayList<>(List.of( new ProcessSummaryLine(Status.OK, 5, "Test") ))); + System.out.println("should log"); QJavalinAccessLogger.logProcessSummary("testProcess", UUID.randomUUID().toString(), runProcessOutput); }