From 20607bbf9bab825ce8c07b05c6bc82271240c7a4 Mon Sep 17 00:00:00 2001 From: Tim Chamberlain Date: Mon, 14 Nov 2022 17:37:47 -0600 Subject: [PATCH] SPRINT-15: added initial version of the QLogger class --- .../RecordAutomationStatusUpdater.java | 11 +- .../core/actions/tables/InsertAction.java | 2 +- .../core/actions/tables/UpdateAction.java | 4 +- .../backend/core/model/session/QSession.java | 36 ++++- .../AbstractLoadStep.java | 8 +- .../qqq/backend/core/utils/QLogger.java | 138 ++++++++++++++++++ .../module/api/actions/AbstractAPIAction.java | 4 + .../module/api/actions/BaseAPIActionUtil.java | 54 ++++--- .../javalin/QJavalinProcessHandler.java | 2 +- 9 files changed, 222 insertions(+), 37 deletions(-) create mode 100755 qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/utils/QLogger.java diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/automation/RecordAutomationStatusUpdater.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/automation/RecordAutomationStatusUpdater.java index 8177eae0..22035129 100644 --- a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/automation/RecordAutomationStatusUpdater.java +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/automation/RecordAutomationStatusUpdater.java @@ -37,9 +37,8 @@ import com.kingsrook.qqq.backend.core.model.metadata.tables.automation.TableAuto import com.kingsrook.qqq.backend.core.model.metadata.tables.automation.TriggerEvent; import com.kingsrook.qqq.backend.core.model.session.QSession; import com.kingsrook.qqq.backend.core.utils.CollectionUtils; +import com.kingsrook.qqq.backend.core.utils.QLogger; import org.apache.commons.lang.NotImplementedException; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; /******************************************************************************* @@ -47,7 +46,7 @@ import org.apache.logging.log4j.Logger; *******************************************************************************/ public class RecordAutomationStatusUpdater { - private static final Logger LOG = LogManager.getLogger(RecordAutomationStatusUpdater.class); + private static final QLogger LOG = QLogger.getLogger(RecordAutomationStatusUpdater.class); @@ -55,7 +54,7 @@ public class RecordAutomationStatusUpdater ** for a list of records from a table, set their automation status - based on ** how the table is configured. *******************************************************************************/ - public static boolean setAutomationStatusInRecords(QTableMetaData table, List records, AutomationStatus automationStatus) + public static boolean setAutomationStatusInRecords(QSession session, QTableMetaData table, List records, AutomationStatus automationStatus) { if(table == null || table.getAutomationDetails() == null || CollectionUtils.nullSafeIsEmpty(records)) { @@ -77,7 +76,7 @@ public class RecordAutomationStatusUpdater String className = stackTraceElement.getClassName(); if(className.contains("com.kingsrook.qqq.backend.core.actions.automation") && !className.equals(RecordAutomationStatusUpdater.class.getName()) && !className.endsWith("Test")) { - LOG.debug("Avoiding re-setting automation status to PENDING_UPDATE while running an automation"); + LOG.debug(session, "Avoiding re-setting automation status to PENDING_UPDATE while running an automation"); return (false); } } @@ -135,7 +134,7 @@ public class RecordAutomationStatusUpdater QTableAutomationDetails automationDetails = table.getAutomationDetails(); if(automationDetails != null && AutomationStatusTrackingType.FIELD_IN_TABLE.equals(automationDetails.getStatusTracking().getType())) { - boolean didSetStatusField = setAutomationStatusInRecords(table, records, automationStatus); + boolean didSetStatusField = setAutomationStatusInRecords(session, table, records, automationStatus); if(didSetStatusField) { UpdateInput updateInput = new UpdateInput(instance); diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/InsertAction.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/InsertAction.java index f7dc6869..30dd9186 100644 --- a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/InsertAction.java +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/InsertAction.java @@ -67,7 +67,7 @@ public class InsertAction *******************************************************************************/ private void setAutomationStatusField(InsertInput insertInput) { - RecordAutomationStatusUpdater.setAutomationStatusInRecords(insertInput.getTable(), insertInput.getRecords(), AutomationStatus.PENDING_INSERT_AUTOMATIONS); + RecordAutomationStatusUpdater.setAutomationStatusInRecords(insertInput.getSession(), insertInput.getTable(), insertInput.getRecords(), AutomationStatus.PENDING_INSERT_AUTOMATIONS); } diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/UpdateAction.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/UpdateAction.java index 4f925411..0dcad463 100644 --- a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/UpdateAction.java +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/actions/tables/UpdateAction.java @@ -47,7 +47,7 @@ public class UpdateAction setAutomationStatusField(updateInput); QBackendModuleDispatcher qBackendModuleDispatcher = new QBackendModuleDispatcher(); - QBackendModuleInterface qModule = qBackendModuleDispatcher.getQBackendModule(updateInput.getBackend()); + QBackendModuleInterface qModule = qBackendModuleDispatcher.getQBackendModule(updateInput.getBackend()); // todo pre-customization - just get to modify the request? UpdateOutput updateResult = qModule.getUpdateInterface().execute(updateInput); // todo post-customization - can do whatever w/ the result if you want @@ -61,7 +61,7 @@ public class UpdateAction *******************************************************************************/ private void setAutomationStatusField(UpdateInput updateInput) { - RecordAutomationStatusUpdater.setAutomationStatusInRecords(updateInput.getTable(), updateInput.getRecords(), AutomationStatus.PENDING_UPDATE_AUTOMATIONS); + RecordAutomationStatusUpdater.setAutomationStatusInRecords(updateInput.getSession(), updateInput.getTable(), updateInput.getRecords(), AutomationStatus.PENDING_UPDATE_AUTOMATIONS); } } diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/model/session/QSession.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/model/session/QSession.java index f0ba6a22..5755b568 100644 --- a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/model/session/QSession.java +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/model/session/QSession.java @@ -25,6 +25,7 @@ package com.kingsrook.qqq.backend.core.model.session; import java.io.Serializable; import java.util.HashMap; import java.util.Map; +import java.util.UUID; /******************************************************************************* @@ -33,13 +34,25 @@ import java.util.Map; public class QSession implements Serializable { private String idReference; - private QUser user; + private QUser user; + private String uuid; // implementation-specific custom values private Map values; + /******************************************************************************* + ** Default constructor, puts a uuid in the session + ** + *******************************************************************************/ + public QSession() + { + this.uuid = UUID.randomUUID().toString(); + } + + + /******************************************************************************* ** Getter for idReference ** @@ -145,4 +158,25 @@ public class QSession implements Serializable this.values = values; } + + + /******************************************************************************* + ** Getter for uuid + ** + *******************************************************************************/ + public String getUuid() + { + return uuid; + } + + + + /******************************************************************************* + ** Setter for uuid + ** + *******************************************************************************/ + public void setUuid(String uuid) + { + this.uuid = uuid; + } } diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/processes/implementations/etl/streamedwithfrontend/AbstractLoadStep.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/processes/implementations/etl/streamedwithfrontend/AbstractLoadStep.java index 6d47e3dd..6940e194 100644 --- a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/processes/implementations/etl/streamedwithfrontend/AbstractLoadStep.java +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/processes/implementations/etl/streamedwithfrontend/AbstractLoadStep.java @@ -28,6 +28,7 @@ import com.kingsrook.qqq.backend.core.actions.processes.BackendStep; import com.kingsrook.qqq.backend.core.exceptions.QException; import com.kingsrook.qqq.backend.core.model.actions.processes.RunBackendStepInput; import com.kingsrook.qqq.backend.core.model.actions.processes.RunBackendStepOutput; +import com.kingsrook.qqq.backend.core.model.session.QSession; /******************************************************************************* @@ -43,7 +44,8 @@ import com.kingsrook.qqq.backend.core.model.actions.processes.RunBackendStepOutp *******************************************************************************/ public abstract class AbstractLoadStep implements BackendStep { - private Optional transaction = Optional.empty(); + private Optional transaction = Optional.empty(); + protected QSession session; @@ -53,9 +55,7 @@ public abstract class AbstractLoadStep implements BackendStep *******************************************************************************/ public void preRun(RunBackendStepInput runBackendStepInput, RunBackendStepOutput runBackendStepOutput) throws QException { - //////////////////////// - // noop in base class // - //////////////////////// + this.session = runBackendStepInput.getSession(); } diff --git a/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/utils/QLogger.java b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/utils/QLogger.java new file mode 100755 index 00000000..305a4c21 --- /dev/null +++ b/qqq-backend-core/src/main/java/com/kingsrook/qqq/backend/core/utils/QLogger.java @@ -0,0 +1,138 @@ +/* + * QQQ - Low-code Application Framework for Engineers. + * Copyright (C) 2021-2022. Kingsrook, LLC + * 651 N Broad St Ste 205 # 6917 | Middletown DE 19709 | United States + * contact@kingsrook.com + * https://github.com/Kingsrook/ + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as + * published by the Free Software Foundation, either version 3 of the + * License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +package com.kingsrook.qqq.backend.core.utils; + + +import java.util.HashMap; +import java.util.Map; +import com.kingsrook.qqq.backend.core.model.session.QSession; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; + + +/******************************************************************************* + ** Utility class for logging + ** + *******************************************************************************/ +public class QLogger +{ + private static Map loggerMap = new HashMap<>(); + private Logger logger; + + + + /******************************************************************************* + ** + *******************************************************************************/ + public QLogger(Logger logger) + { + this.logger = logger; + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public static QLogger getLogger(Class c) + { + return (loggerMap.computeIfAbsent(c.getName(), x -> new QLogger(LogManager.getLogger(c)))); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void debug(QSession session, String message) + { + logger.debug(wrapMessage(session, message)); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void info(QSession session, String message) + { + logger.info(wrapMessage(session, message)); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void warn(QSession session, String message) + { + logger.warn(wrapMessage(session, message)); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void warn(QSession session, String message, Throwable t) + { + logger.warn(wrapMessage(session, message), t); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void error(QSession session, String message) + { + logger.error(wrapMessage(session, message)); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + public void error(QSession session, String message, Throwable t) + { + logger.error(wrapMessage(session, message), t); + } + + + + /******************************************************************************* + ** + *******************************************************************************/ + private String wrapMessage(QSession session, String message) + { + String propertyName = "qqq.logger.logSessionId.disabled"; + String propertyValue = System.getProperty(propertyName, ""); + if(propertyValue.equals("true")) + { + return (message); + } + + String sessionString = (session != null) ? session.getUuid() : "Not provided"; + return ("Session [" + sessionString + "] | " + message); + } +} diff --git a/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/AbstractAPIAction.java b/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/AbstractAPIAction.java index 737eb253..284a71f1 100644 --- a/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/AbstractAPIAction.java +++ b/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/AbstractAPIAction.java @@ -25,6 +25,7 @@ package com.kingsrook.qqq.backend.module.api.actions; import com.kingsrook.qqq.backend.core.actions.customizers.QCodeLoader; import com.kingsrook.qqq.backend.core.model.actions.AbstractTableActionInput; import com.kingsrook.qqq.backend.core.model.metadata.QBackendMetaData; +import com.kingsrook.qqq.backend.core.model.session.QSession; import com.kingsrook.qqq.backend.module.api.model.metadata.APIBackendMetaData; @@ -35,6 +36,7 @@ public abstract class AbstractAPIAction { protected APIBackendMetaData backendMetaData; protected BaseAPIActionUtil apiActionUtil; + protected QSession session; @@ -45,6 +47,7 @@ public abstract class AbstractAPIAction { QBackendMetaData baseBackendMetaData = actionInput.getInstance().getBackendForTable(actionInput.getTableName()); this.backendMetaData = (APIBackendMetaData) baseBackendMetaData; + this.session = actionInput.getSession(); if(backendMetaData.getActionUtil() != null) { @@ -57,6 +60,7 @@ public abstract class AbstractAPIAction apiActionUtil.setBackendMetaData(this.backendMetaData); apiActionUtil.setActionInput(actionInput); + apiActionUtil.setSession(session); } } diff --git a/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/BaseAPIActionUtil.java b/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/BaseAPIActionUtil.java index 2c8e0144..606e0da6 100644 --- a/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/BaseAPIActionUtil.java +++ b/qqq-backend-module-api/src/main/java/com/kingsrook/qqq/backend/module/api/actions/BaseAPIActionUtil.java @@ -50,8 +50,10 @@ import com.kingsrook.qqq.backend.core.model.actions.tables.update.UpdateOutput; import com.kingsrook.qqq.backend.core.model.data.QRecord; import com.kingsrook.qqq.backend.core.model.metadata.fields.QFieldMetaData; import com.kingsrook.qqq.backend.core.model.metadata.tables.QTableMetaData; +import com.kingsrook.qqq.backend.core.model.session.QSession; import com.kingsrook.qqq.backend.core.utils.CollectionUtils; import com.kingsrook.qqq.backend.core.utils.JsonUtils; +import com.kingsrook.qqq.backend.core.utils.QLogger; import com.kingsrook.qqq.backend.core.utils.SleepUtils; import com.kingsrook.qqq.backend.core.utils.StringUtils; import com.kingsrook.qqq.backend.core.utils.ValueUtils; @@ -67,8 +69,6 @@ import org.apache.http.entity.AbstractHttpEntity; import org.apache.http.entity.StringEntity; import org.apache.http.impl.client.CloseableHttpClient; import org.apache.http.impl.client.HttpClientBuilder; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; import org.json.JSONArray; import org.json.JSONObject; @@ -79,8 +79,9 @@ import org.json.JSONObject; *******************************************************************************/ public class BaseAPIActionUtil { - protected static final Logger LOG = LogManager.getLogger(BaseAPIActionUtil.class); + private final QLogger LOG = QLogger.getLogger(BaseAPIActionUtil.class); + protected QSession session; protected APIBackendMetaData backendMetaData; protected AbstractTableActionInput actionInput; @@ -107,7 +108,7 @@ public class BaseAPIActionUtil } catch(Exception e) { - LOG.warn("Error in API count", e); + LOG.error(session, "Error in API count", e); throw new QException("Error executing count: " + e.getMessage(), e); } } @@ -138,7 +139,7 @@ public class BaseAPIActionUtil } catch(Exception e) { - LOG.warn("Error in API get", e); + LOG.error(session, "Error in API get", e); throw new QException("Error executing get: " + e.getMessage(), e); } } @@ -155,7 +156,7 @@ public class BaseAPIActionUtil if(CollectionUtils.nullSafeIsEmpty(insertInput.getRecords())) { - LOG.debug("Insert request called with 0 records. Returning with no-op"); + LOG.debug(session, "Insert request called with 0 records. Returning with no-op"); return (insertOutput); } @@ -196,7 +197,7 @@ public class BaseAPIActionUtil } catch(Exception e) { - LOG.warn("Error in API Insert for [" + table.getName() + "]", e); + LOG.error(session, "Error in API Insert for [" + table.getName() + "]", e); throw new QException("Error executing insert: " + e.getMessage(), e); } @@ -254,7 +255,7 @@ public class BaseAPIActionUtil /////////////////////////////////////////////////////////////////// if(queryInput.getAsyncJobCallback().wasCancelRequested()) { - LOG.info("Breaking query job, as requested."); + LOG.info(session, "Breaking query job, as requested."); return (queryOutput); } @@ -269,7 +270,7 @@ public class BaseAPIActionUtil } catch(Exception e) { - LOG.warn("Error in API Query", e); + LOG.error(session, "Error in API Query", e); throw new QException("Error executing query: " + e.getMessage(), e); } } @@ -287,7 +288,7 @@ public class BaseAPIActionUtil if(CollectionUtils.nullSafeIsEmpty(updateInput.getRecords())) { - LOG.debug("Update request called with 0 records. Returning with no-op"); + LOG.debug(session, "Update request called with 0 records. Returning with no-op"); return (updateOutput); } @@ -314,7 +315,7 @@ public class BaseAPIActionUtil catch(Exception e) { String errorMessage = "An unexpected error occurred updating entities."; - LOG.warn(errorMessage, e); + LOG.error(session, errorMessage, e); throw (new QException(errorMessage, e)); } @@ -332,7 +333,7 @@ public class BaseAPIActionUtil } catch(Exception e) { - LOG.warn("Error in API Update for [" + table.getName() + "]", e); + LOG.error(session, "Error in API Update for [" + table.getName() + "]", e); throw new QException("Error executing update: " + e.getMessage(), e); } } @@ -469,8 +470,8 @@ public class BaseAPIActionUtil { int statusCode = response.getStatusCode(); String resultString = response.getContent(); - String errorMessage = "HTTP " + request.getMethod() + " for table + [" + table.getName() + "] failed with status " + statusCode + ": " + resultString; - LOG.warn(errorMessage); + String errorMessage = "HTTP " + request.getMethod() + " for table [" + table.getName() + "] failed with status " + statusCode + ": " + resultString; + LOG.error(session, errorMessage); if("GET".equals(request.getMethod())) { @@ -614,7 +615,6 @@ public class BaseAPIActionUtil body.put(tablePath, new JSONObject(json)); json = body.toString(); } - LOG.debug(json); return (new StringEntity(json)); } @@ -644,7 +644,6 @@ public class BaseAPIActionUtil body.put(tablePath, new JSONArray(json)); json = body.toString(); } - LOG.debug(json); return (new StringEntity(json)); } catch(Exception e) @@ -745,10 +744,10 @@ public class BaseAPIActionUtil setupContentTypeInRequest(request); setupAdditionalHeaders(request); - LOG.info("Making [" + request.getMethod() + "] request to URL [" + request.getURI() + "] on table [" + table.getName() + "]."); + LOG.info(session, "Making [" + request.getMethod() + "] request to URL [" + request.getURI() + "] on table [" + table.getName() + "]."); if("POST".equals(request.getMethod())) { - LOG.info("POST contents [" + ((HttpPost) request).getEntity().toString() + "]"); + LOG.info(session, "POST contents [" + ((HttpPost) request).getEntity().toString() + "]"); } try(CloseableHttpResponse response = httpClient.execute(request)) @@ -765,7 +764,7 @@ public class BaseAPIActionUtil handleResponseError(table, request, qResponse); } - LOG.info("Received successful response with code [" + qResponse.getStatusCode() + "] and content [" + qResponse.getContent() + "]."); + LOG.info(session, "Received successful response with code [" + qResponse.getStatusCode() + "] and content [" + qResponse.getContent() + "]."); return (qResponse); } } @@ -774,18 +773,18 @@ public class BaseAPIActionUtil rateLimitsCaught++; if(rateLimitsCaught > getMaxAllowedRateLimitErrors()) { - LOG.warn("Giving up POST to [" + table.getName() + "] after too many rate-limit errors (" + getMaxAllowedRateLimitErrors() + ")"); + LOG.error(session, "Giving up POST to [" + table.getName() + "] after too many rate-limit errors (" + getMaxAllowedRateLimitErrors() + ")"); throw (new QException(rle)); } - LOG.info("Caught RateLimitException [#" + rateLimitsCaught + "] during HTTP request to [" + request.getURI() + "] on table [" + table.getName() + "] - sleeping [" + sleepMillis + "]..."); + LOG.warn(session, "Caught RateLimitException [#" + rateLimitsCaught + "] during HTTP request to [" + request.getURI() + "] on table [" + table.getName() + "] - sleeping [" + sleepMillis + "]..."); SleepUtils.sleep(sleepMillis, TimeUnit.MILLISECONDS); sleepMillis *= 2; } catch(Exception e) { String message = "An unknown error occurred trying to make an HTTP request to [" + request.getURI() + "] on table [" + table.getName() + "]."; - LOG.warn(message, e); + LOG.error(session, message, e); throw (new QException(message, e)); } } @@ -861,6 +860,17 @@ public class BaseAPIActionUtil + /******************************************************************************* + ** Setter for session + ** + *******************************************************************************/ + public void setSession(QSession session) + { + this.session = session; + } + + + /******************************************************************************* ** *******************************************************************************/ diff --git a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinProcessHandler.java b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinProcessHandler.java index 4bb8f71b..b79cd703 100644 --- a/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinProcessHandler.java +++ b/qqq-middleware-javalin/src/main/java/com/kingsrook/qqq/backend/javalin/QJavalinProcessHandler.java @@ -168,7 +168,7 @@ public class QJavalinProcessHandler // run the process as an async action // //////////////////////////////////////// Integer timeout = getTimeoutMillis(context); - RunProcessOutput runProcessOutput = new AsyncJobManager().startJob(timeout, TimeUnit.MILLISECONDS, (callback) -> + RunProcessOutput runProcessOutput = new AsyncJobManager().startJob(processName, timeout, TimeUnit.MILLISECONDS, (callback) -> { runProcessInput.setAsyncJobCallback(callback); return (new RunProcessAction().execute(runProcessInput));