Merge branch 'dev' into feature/CTLE-434-oms-update-business-logic

This commit is contained in:
2023-06-06 09:06:34 -05:00
6 changed files with 273 additions and 64 deletions

View File

@ -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<Long> requestStartTime = new ThreadLocal<>();
private static ThreadLocal<String> requestActionName = new ThreadLocal<>();
private static ThreadLocal<LogPair[]> 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<LogPair> 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<LogPair> 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<LogPair> 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<LogPair> 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<LogPair> pairList)
private static void logEnd(LogType logType, String accessType, List<LogPair> 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)
{

View File

@ -1178,21 +1178,13 @@ public class QJavalinImplementation
try
{
//////////////////////////////////////////
// read params from the request context //
//////////////////////////////////////////
String format = context.queryParam("format");
String filter = context.queryParam("filter");
Integer limit = QJavalinUtils.integerQueryParam(context, "limit");
String format = context.queryParam("format");
ReportFormat reportFormat = getReportFormat(context, optionalFilename, format);
if(reportFormat == null)
{
return;
}
String filename = optionalFilename.orElse(tableName + "." + reportFormat.toString().toLowerCase(Locale.ROOT));
/////////////////////////////////////////////
// set up the report action's input object //
/////////////////////////////////////////////
@ -1201,18 +1193,33 @@ public class QJavalinImplementation
exportInput.setTableName(tableName);
exportInput.setReportFormat(reportFormat);
String filename = optionalFilename.orElse(tableName + "." + reportFormat.toString().toLowerCase(Locale.ROOT));
exportInput.setFilename(filename);
Integer limit = QJavalinUtils.integerQueryParam(context, "limit");
exportInput.setLimit(limit);
PermissionsHelper.checkTablePermissionThrowing(exportInput, TablePermissionSubType.READ);
String fields = QJavalinUtils.stringQueryParam(context, "fields");
if(!StringUtils.hasContent(fields))
{
fields = context.formParam("fields");
}
if(StringUtils.hasContent(fields))
{
exportInput.setFieldNames(List.of(fields.split(",")));
}
if(filter != null)
String filter = context.queryParam("filter");
if(!StringUtils.hasContent(filter))
{
filter = context.formParam("filter");
}
if(StringUtils.hasContent(filter))
{
exportInput.setQueryFilter(JsonUtils.toObject(filter, QQueryFilter.class));
}
@ -1226,17 +1233,18 @@ public class QJavalinImplementation
return (exportAction);
};
String finalFilter = filter;
UnsafeConsumer<ExportAction, Exception> execute = (ExportAction exportAction) ->
{
QJavalinAccessLogger.logStart("export", logPair("table", tableName));
try
{
ExportOutput exportOutput = exportAction.execute(exportInput);
QJavalinAccessLogger.logEndSuccess(logPair("recordCount", exportOutput.getRecordCount()), logPairIfSlow("filter", filter, SLOW_LOG_THRESHOLD_MS));
QJavalinAccessLogger.logEndSuccess(logPair("recordCount", exportOutput.getRecordCount()), logPairIfSlow("filter", finalFilter, SLOW_LOG_THRESHOLD_MS));
}
catch(Exception e)
{
QJavalinAccessLogger.logEndFail(e, logPair("filter", filter));
QJavalinAccessLogger.logEndFail(e, logPair("filter", finalFilter));
throw (e);
}
};

View File

@ -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<QJavalinAccessLogger.LogEntry, Boolean> 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<QJavalinAccessLogger.LogEntry, Boolean> getLogFilter()
{
return (this.logAllAccessEnds);
return (this.logFilter);
}
/*******************************************************************************
** Setter for logAllAccessEnds
** Setter for logFilter
*******************************************************************************/
public void setLogAllAccessEnds(boolean logAllAccessEnds)
public void setLogFilter(Function<QJavalinAccessLogger.LogEntry, Boolean> logFilter)
{
this.logAllAccessEnds = logAllAccessEnds;
this.logFilter = logFilter;
}
/*******************************************************************************
** Fluent setter for logAllAccessEnds
** Fluent setter for logFilter
*******************************************************************************/
public QJavalinMetaData withLogAllAccessEnds(boolean logAllAccessEnds)
public QJavalinMetaData withLogFilter(Function<QJavalinAccessLogger.LogEntry, Boolean> logFilter)
{
this.logAllAccessEnds = logAllAccessEnds;
this.logFilter = logFilter;
return (this);
}

View File

@ -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);
}