Log and thread name adjustments - trying to make loggly more useful

This commit is contained in:
2022-11-08 09:08:15 -06:00
parent 236eff523e
commit 1a287fe35a
15 changed files with 57 additions and 14 deletions

View File

@ -91,7 +91,7 @@ public class AsyncJobManager
}
catch(TimeoutException e)
{
LOG.info("Job going async " + uuidAndTypeStateKey.getUuid());
LOG.debug("Job going async " + uuidAndTypeStateKey.getUuid());
throw (new JobGoingAsyncException(uuidAndTypeStateKey.getUuid().toString()));
}
}

View File

@ -55,6 +55,7 @@ import com.kingsrook.qqq.backend.core.model.metadata.tables.automation.Automatio
import com.kingsrook.qqq.backend.core.model.metadata.tables.automation.TableAutomationAction;
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.scheduler.StandardScheduledExecutor;
import com.kingsrook.qqq.backend.core.utils.CollectionUtils;
import com.kingsrook.qqq.backend.core.utils.StringUtils;
import org.apache.commons.lang.NotImplementedException;
@ -173,7 +174,8 @@ public class PollingAutomationPerTableRunner implements Runnable
@Override
public void run()
{
Thread.currentThread().setName(name);
String originalThreadName = Thread.currentThread().getName();
Thread.currentThread().setName(name + StandardScheduledExecutor.newThreadNameRandomSuffix());
LOG.debug("Running " + this.getClass().getSimpleName() + "[" + name + "]");
try
@ -185,6 +187,10 @@ public class PollingAutomationPerTableRunner implements Runnable
{
LOG.warn("Error running automations", e);
}
finally
{
Thread.currentThread().setName(originalThreadName);
}
}

View File

@ -38,6 +38,7 @@ import com.kingsrook.qqq.backend.core.model.metadata.QInstance;
import com.kingsrook.qqq.backend.core.model.metadata.queues.QQueueMetaData;
import com.kingsrook.qqq.backend.core.model.metadata.queues.SQSQueueProviderMetaData;
import com.kingsrook.qqq.backend.core.model.session.QSession;
import com.kingsrook.qqq.backend.core.scheduler.StandardScheduledExecutor;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
@ -66,6 +67,10 @@ public class SQSQueuePoller implements Runnable
@Override
public void run()
{
String originalThreadName = Thread.currentThread().getName();
Thread.currentThread().setName("SQSPoller>" + queueMetaData.getName() + StandardScheduledExecutor.newThreadNameRandomSuffix());
LOG.debug("Running " + this.getClass().getSimpleName() + "[" + queueMetaData.getName() + "]");
try
{
BasicAWSCredentials credentials = new BasicAWSCredentials(queueProviderMetaData.getAccessKey(), queueProviderMetaData.getSecretKey());
@ -119,6 +124,10 @@ public class SQSQueuePoller implements Runnable
{
LOG.warn("Error receiving SQS Message", e);
}
finally
{
Thread.currentThread().setName(originalThreadName);
}
}

View File

@ -38,7 +38,7 @@ public class QReportField
private String displayFormat;
///////////////////////////////////////////////////////////////////////////
// Noew: new attributes added here probably belong in the toField method //
// Note: new attributes added here probably belong in the toField method //
///////////////////////////////////////////////////////////////////////////
private boolean isVirtual = false;

View File

@ -34,6 +34,8 @@ 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.data.QRecord;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
/*******************************************************************************
@ -43,6 +45,8 @@ import com.kingsrook.qqq.backend.core.model.data.QRecord;
*******************************************************************************/
public class StreamedETLExecuteStep extends BaseStreamedETLStep implements BackendStep
{
private static final Logger LOG = LogManager.getLogger(StreamedETLExecuteStep.class);
private int currentRowCount = 1;
@ -105,6 +109,11 @@ public class StreamedETLExecuteStep extends BaseStreamedETLStep implements Backe
transformStep.postRun(runBackendStepInput, runBackendStepOutput);
loadStep.postRun(runBackendStepInput, runBackendStepOutput);
if(recordCount > 0)
{
LOG.info("Processed [" + recordCount + "] records.");
}
//////////////////////////////////////////////////////////////////////////////
// set the flag to state that the basepull timestamp should be updated now. //
//////////////////////////////////////////////////////////////////////////////

View File

@ -69,7 +69,7 @@ public class StreamedETLPreviewStep extends BaseStreamedETLStep implements Backe
if(runBackendStepInput.getFrontendStepBehavior() != null && runBackendStepInput.getFrontendStepBehavior().equals(RunProcessInput.FrontendStepBehavior.SKIP))
{
LOG.info("Skipping preview because frontent behavior is [" + RunProcessInput.FrontendStepBehavior.SKIP + "].");
LOG.debug("Skipping preview because frontent behavior is [" + RunProcessInput.FrontendStepBehavior.SKIP + "].");
return;
}
@ -78,7 +78,7 @@ public class StreamedETLPreviewStep extends BaseStreamedETLStep implements Backe
/////////////////////////////////////////////////////////////////
if(runningWithinAutomation())
{
LOG.info("Skipping preview step when [" + runBackendStepInput.getProcessName() + "] is running as part of an automation.");
LOG.debug("Skipping preview step when [" + runBackendStepInput.getProcessName() + "] is running as part of an automation.");
return;
}

View File

@ -214,6 +214,10 @@ public class ScheduleManager
{
Runnable runProcess = () ->
{
String originalThreadName = Thread.currentThread().getName();
Thread.currentThread().setName("ScheduledProcess>" + process.getName() + StandardScheduledExecutor.newThreadNameRandomSuffix());
LOG.debug("Running Scheduled Process [" + process.getName() + "]");
try
{
RunProcessInput runProcessInput = new RunProcessInput(qInstance);
@ -228,6 +232,10 @@ public class ScheduleManager
{
LOG.warn("Exception thrown running scheduled process [" + process.getName() + "]", e);
}
finally
{
Thread.currentThread().setName(originalThreadName);
}
};
StandardScheduledExecutor executor = new StandardScheduledExecutor(runProcess);

View File

@ -22,6 +22,7 @@
package com.kingsrook.qqq.backend.core.scheduler;
import java.util.UUID;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
@ -71,6 +72,16 @@ public class StandardScheduledExecutor
/*******************************************************************************
**
*******************************************************************************/
public static String newThreadNameRandomSuffix()
{
return (":" + UUID.randomUUID().toString().split("-")[0]);
}
/*******************************************************************************
**
*******************************************************************************/

View File

@ -64,7 +64,7 @@ public class APIInsertAction extends AbstractAPIAction implements InsertInterfac
if(CollectionUtils.nullSafeIsEmpty(insertInput.getRecords()))
{
LOG.info("Insert request called with 0 records. Returning with no-op");
LOG.debug("Insert request called with 0 records. Returning with no-op");
return (insertOutput);
}

View File

@ -65,7 +65,7 @@ public class APIUpdateAction extends AbstractAPIAction implements UpdateInterfac
if(CollectionUtils.nullSafeIsEmpty(updateInput.getRecords()))
{
LOG.info("Update request called with 0 records. Returning with no-op");
LOG.debug("Update request called with 0 records. Returning with no-op");
return (updateOutput);
}

View File

@ -390,7 +390,7 @@ public abstract class AbstractRDBMSAction implements QActionInterface
{
try
{
LOG.info("Opening transaction");
LOG.debug("Opening transaction");
Connection connection = getConnection(input);
return (new RDBMSTransaction(connection));

View File

@ -59,7 +59,7 @@ public class RDBMSInsertAction extends AbstractRDBMSAction implements InsertInte
if(CollectionUtils.nullSafeIsEmpty(insertInput.getRecords()))
{
LOG.info("Insert request called with 0 records. Returning with no-op");
LOG.debug("Insert request called with 0 records. Returning with no-op");
rs.setRecords(new ArrayList<>());
return (rs);
}

View File

@ -73,9 +73,9 @@ public class RDBMSTransaction extends QBackendTransaction
{
try
{
RDBMSTransaction.LOG.info("Committing transaction");
RDBMSTransaction.LOG.debug("Committing transaction");
connection.commit();
RDBMSTransaction.LOG.info("Commit complete");
RDBMSTransaction.LOG.debug("Commit complete");
}
catch(Exception e)
{

View File

@ -71,7 +71,7 @@ public class RDBMSUpdateAction extends AbstractRDBMSAction implements UpdateInte
if(CollectionUtils.nullSafeIsEmpty(updateInput.getRecords()))
{
LOG.info("Update request called with 0 records. Returning with no-op");
LOG.debug("Update request called with 0 records. Returning with no-op");
rs.setRecords(new ArrayList<>());
return (rs);
}

View File

@ -393,7 +393,7 @@ public class QJavalinProcessHandler
Map<String, Object> resultForCaller = new HashMap<>();
resultForCaller.put("processUUID", processUUID);
LOG.info("Request for status of process " + processUUID + ", job " + jobUUID);
LOG.debug("Request for status of process " + processUUID + ", job " + jobUUID);
Optional<AsyncJobStatus> optionalJobStatus = new AsyncJobManager().getJobStatus(jobUUID);
if(optionalJobStatus.isEmpty())
{
@ -404,7 +404,7 @@ public class QJavalinProcessHandler
AsyncJobStatus jobStatus = optionalJobStatus.get();
resultForCaller.put("jobStatus", jobStatus);
LOG.info("Job status is " + jobStatus.getState() + " for " + jobUUID);
LOG.debug("Job status is " + jobStatus.getState() + " for " + jobUUID);
if(jobStatus.getState().equals(AsyncJobState.COMPLETE))
{