You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@nifi.apache.org by ma...@apache.org on 2022/04/12 15:14:45 UTC
[nifi] branch main updated: NIFI-9871 Correct Component Stack Trace Logging (#5945)
This is an automated email from the ASF dual-hosted git repository.
markap14 pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/nifi.git
The following commit(s) were added to refs/heads/main by this push:
new 27e78c6f0c NIFI-9871 Correct Component Stack Trace Logging (#5945)
27e78c6f0c is described below
commit 27e78c6f0cd380830e964c2e98774b1e12889050
Author: exceptionfactory <ex...@apache.org>
AuthorDate: Tue Apr 12 10:14:36 2022 -0500
NIFI-9871 Correct Component Stack Trace Logging (#5945)
- Refactored SimpleProcessLogger to avoid sending stack trace causes to SLF4J Logger
- Refactored SimpleProcessLogger to minimize duplication of component message formatting
- Updated ConnectableTask logging to avoid repeating Throwable class in message string
- Refactored TestSimpleProcessLogger to improve coverage and confirm consistent argument handling
- Corrected handling of exception strings in argument arrays
---
.../apache/nifi/processor/SimpleProcessLogger.java | 479 +++++++++++----------
.../nifi/processor/TestSimpleProcessLogger.java | 249 ++++++++---
.../nifi/controller/tasks/ConnectableTask.java | 26 +-
3 files changed, 459 insertions(+), 295 deletions(-)
diff --git a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/main/java/org/apache/nifi/processor/SimpleProcessLogger.java b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/main/java/org/apache/nifi/processor/SimpleProcessLogger.java
index 49b4dd541d..7262724dd4 100644
--- a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/main/java/org/apache/nifi/processor/SimpleProcessLogger.java
+++ b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/main/java/org/apache/nifi/processor/SimpleProcessLogger.java
@@ -16,7 +16,7 @@
*/
package org.apache.nifi.processor;
-import org.apache.commons.lang3.StringUtils;
+import org.apache.commons.lang3.ArrayUtils;
import org.apache.nifi.logging.ComponentLog;
import org.apache.nifi.logging.LogLevel;
import org.apache.nifi.logging.LogMessage;
@@ -32,6 +32,8 @@ public class SimpleProcessLogger implements ComponentLog {
private static final String CAUSED_BY = String.format("%n- Caused by: ");
+ private static final Throwable NULL_THROWABLE = null;
+
private final Logger logger;
private final LogRepository logRepository;
private final Object component;
@@ -46,75 +48,62 @@ public class SimpleProcessLogger implements ComponentLog {
this.component = component;
}
- private Object[] addProcessor(final Object[] originalArgs) {
- return prependToArgs(originalArgs, component);
- }
-
- private Object[] prependToArgs(final Object[] originalArgs, final Object... toAdd) {
- final Object[] newArgs = new Object[originalArgs.length + toAdd.length];
- System.arraycopy(toAdd, 0, newArgs, 0, toAdd.length);
- System.arraycopy(originalArgs, 0, newArgs, toAdd.length, originalArgs.length);
- return newArgs;
- }
-
- private boolean lastArgIsException(final Object[] os) {
- return (os != null && os.length > 0 && (os[os.length - 1] instanceof Throwable));
- }
-
@Override
- public void warn(String msg, final Throwable t) {
- if (!isWarnEnabled()) {
- return;
- }
+ public void warn(final String msg, final Throwable t) {
+ if (isWarnEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] repositoryArguments = getRepositoryArguments(t);
- msg = "{} " + msg;
- final Object[] os = {component, getCauses(t), t};
- logger.warn(msg, os);
- logRepository.addLogMessage(LogLevel.WARN, msg, os, t);
+ if (t == null) {
+ logger.warn(componentMessage, component);
+ logRepository.addLogMessage(LogLevel.WARN, componentMessage, repositoryArguments);
+ } else {
+ logger.warn(componentMessage, component, t);
+ logRepository.addLogMessage(LogLevel.WARN, getCausesMessage(msg), repositoryArguments, t);
+ }
+ }
}
@Override
- public void warn(String msg, Object[] os) {
- if (!isWarnEnabled()) {
- return;
- }
+ public void warn(final String msg, final Object[] os) {
+ if (isWarnEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- if (lastArgIsException(os)) {
- warn(msg, os, (Throwable) os[os.length - 1]);
- } else {
- msg = "{} " + msg;
- os = addProcessor(os);
- logger.warn(msg, os);
- logRepository.addLogMessage(LogLevel.WARN, msg, os);
+ final Throwable lastThrowable = findLastThrowable(os);
+ if (lastThrowable == null) {
+ logger.warn(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.WARN, componentMessage, arguments);
+ } else {
+ logger.warn(componentMessage, setFormattedThrowable(arguments, lastThrowable));
+ logRepository.addLogMessage(LogLevel.WARN, getCausesMessage(msg), addCauses(arguments, lastThrowable), lastThrowable);
+ }
}
}
@Override
- public void warn(String msg, Object[] os, final Throwable t) {
- if (!isWarnEnabled()) {
- return;
- }
+ public void warn(final String msg, final Object[] os, final Throwable t) {
+ if (isWarnEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- os = addProcessorAndThrowable(os, t);
- msg = "{} " + msg + ": {}";
- logger.warn(msg, os);
- logRepository.addLogMessage(LogLevel.WARN, msg, os, t);
+ if (t == null) {
+ logger.warn(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.WARN, componentMessage, arguments);
+ } else {
+ logger.warn(componentMessage, arguments, t);
+ logRepository.addLogMessage(LogLevel.WARN, getCausesMessage(msg), addCauses(arguments, t), t);
+ }
+ }
}
@Override
- public void warn(String msg) {
- if (!isWarnEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component};
- logger.warn(msg, component);
- logRepository.addLogMessage(LogLevel.WARN, msg, os);
+ public void warn(final String msg) {
+ warn(msg, NULL_THROWABLE);
}
@Override
- public void warn(LogMessage logMessage) {
+ public void warn(final LogMessage logMessage) {
if (isWarnEnabled()) {
log(LogLevel.WARN, logMessage);
logRepository.addLogMessage(logMessage);
@@ -122,56 +111,61 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void trace(String msg, Throwable t) {
- if (!isTraceEnabled()) {
- return;
- }
+ public void trace(final String msg, final Throwable t) {
+ if (isTraceEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] repositoryArguments = getRepositoryArguments(t);
- msg = "{} " + msg;
- final Object[] os = {component, getCauses(t), t};
- logger.trace(msg, os);
- logRepository.addLogMessage(LogLevel.TRACE, msg, os, t);
+ if (t == null) {
+ logger.trace(componentMessage, component);
+ logRepository.addLogMessage(LogLevel.TRACE, componentMessage, repositoryArguments);
+ } else {
+ logger.trace(componentMessage, component, t);
+ logRepository.addLogMessage(LogLevel.TRACE, getCausesMessage(msg), repositoryArguments, t);
+ }
+ }
}
@Override
- public void trace(String msg, Object[] os) {
- if (!isTraceEnabled()) {
- return;
- }
+ public void trace(final String msg, final Object[] os) {
+ if (isTraceEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- msg = "{} " + msg;
- os = addProcessor(os);
- logger.trace(msg, os);
- logRepository.addLogMessage(LogLevel.TRACE, msg, os);
+ final Throwable lastThrowable = findLastThrowable(os);
+ if (lastThrowable == null) {
+ logger.trace(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.TRACE, componentMessage, arguments);
+ } else {
+ logger.trace(componentMessage, setFormattedThrowable(arguments, lastThrowable));
+ logRepository.addLogMessage(LogLevel.TRACE, getCausesMessage(msg), addCauses(arguments, lastThrowable), lastThrowable);
+ }
+ }
}
@Override
- public void trace(String msg) {
- if (!isTraceEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component};
- logger.trace(msg, os);
- logRepository.addLogMessage(LogLevel.TRACE, msg, os);
+ public void trace(final String msg) {
+ trace(msg, NULL_THROWABLE);
}
@Override
- public void trace(String msg, Object[] os, Throwable t) {
- if (!isTraceEnabled()) {
- return;
- }
-
- os = addProcessorAndThrowable(os, t);
- msg = "{} " + msg + ": {}";
+ public void trace(final String msg, final Object[] os, final Throwable t) {
+ if (isTraceEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.trace(msg, os);
- logRepository.addLogMessage(LogLevel.TRACE, msg, os, t);
+ if (t == null) {
+ logger.trace(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.TRACE, componentMessage, arguments);
+ } else {
+ logger.trace(componentMessage, arguments, t);
+ logRepository.addLogMessage(LogLevel.TRACE, getCausesMessage(msg), addCauses(arguments, t), t);
+ }
+ }
}
@Override
- public void trace(LogMessage logMessage) {
+ public void trace(final LogMessage logMessage) {
if (isTraceEnabled()) {
log(LogLevel.TRACE, logMessage);
logRepository.addLogMessage(logMessage);
@@ -204,58 +198,57 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void info(String msg, Throwable t) {
- if (!isInfoEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component, getCauses(t)};
+ public void info(final String msg, final Throwable t) {
+ if (isInfoEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] repositoryArguments = getRepositoryArguments(t);
- logger.info(msg, os);
- if (logger.isDebugEnabled()) {
- logger.info("", t);
+ if (t == null) {
+ logger.info(componentMessage, component);
+ logRepository.addLogMessage(LogLevel.INFO, componentMessage, repositoryArguments);
+ } else {
+ logger.info(componentMessage, component, t);
+ logRepository.addLogMessage(LogLevel.INFO, getCausesMessage(msg), repositoryArguments, t);
+ }
}
- logRepository.addLogMessage(LogLevel.INFO, msg, os, t);
}
@Override
- public void info(String msg, Object[] os) {
- if (!isInfoEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- os = addProcessor(os);
+ public void info(final String msg, final Object[] os) {
+ if (isInfoEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.info(msg, os);
- logRepository.addLogMessage(LogLevel.INFO, msg, os);
+ final Throwable lastThrowable = findLastThrowable(os);
+ if (lastThrowable == null) {
+ logger.info(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.INFO, componentMessage, arguments);
+ } else {
+ logger.info(componentMessage, setFormattedThrowable(arguments, lastThrowable));
+ logRepository.addLogMessage(LogLevel.INFO, getCausesMessage(msg), addCauses(arguments, lastThrowable), lastThrowable);
+ }
+ }
}
@Override
- public void info(String msg) {
- if (!isInfoEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component};
-
- logger.info(msg, os);
- logRepository.addLogMessage(LogLevel.INFO, msg, os);
+ public void info(final String msg) {
+ info(msg, NULL_THROWABLE);
}
@Override
- public void info(String msg, Object[] os, Throwable t) {
- if (!isInfoEnabled()) {
- return;
- }
-
- os = addProcessorAndThrowable(os, t);
- msg = "{} " + msg + ": {}";
+ public void info(final String msg, final Object[] os, final Throwable t) {
+ if (isInfoEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.info(msg, os);
- logRepository.addLogMessage(LogLevel.INFO, msg, os, t);
+ if (t == null) {
+ logger.info(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.INFO, componentMessage, arguments);
+ } else {
+ logger.info(componentMessage, arguments, t);
+ logRepository.addLogMessage(LogLevel.INFO, getCausesMessage(msg), addCauses(arguments, t), t);
+ }
+ }
}
@Override
@@ -272,138 +265,123 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void error(String msg, Throwable t) {
- if (!isErrorEnabled()) {
- return;
- }
-
- if (t == null) {
- msg = "{} " + msg;
- final Object[] os = new Object[]{component};
- logger.error(msg, os);
- logRepository.addLogMessage(LogLevel.ERROR, msg, os);
- } else {
- msg = "{} " + msg + ": {}";
- final Object[] os = new Object[]{component, getCauses(t), t};
- logger.error(msg, os);
- logRepository.addLogMessage(LogLevel.ERROR, msg, os, t);
- }
+ public void error(final String msg) {
+ error(msg, NULL_THROWABLE);
}
@Override
- public void error(String msg, Object[] os) {
- if (!isErrorEnabled()) {
- return;
- }
+ public void error(final String msg, final Throwable t) {
+ if (isErrorEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] repositoryArguments = getRepositoryArguments(t);
- if (lastArgIsException(os)) {
- error(msg, os, (Throwable) os[os.length - 1]);
- } else {
- os = addProcessor(os);
- msg = "{} " + msg;
- logger.error(msg, os);
- logRepository.addLogMessage(LogLevel.ERROR, msg, os);
+ if (t == null) {
+ logger.error(componentMessage, component);
+ logRepository.addLogMessage(LogLevel.ERROR, componentMessage, repositoryArguments);
+ } else {
+ logger.error(componentMessage, component, t);
+ logRepository.addLogMessage(LogLevel.ERROR, getCausesMessage(msg), repositoryArguments, t);
+ }
}
}
@Override
- public void error(String msg) {
- this.error(msg, (Throwable) null);
- }
+ public void error(final String msg, final Object[] os) {
+ if (isErrorEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- @Override
- public void error(String msg, Object[] os, Throwable t) {
- if (!isErrorEnabled()) {
- return;
+ final Throwable lastThrowable = findLastThrowable(os);
+ if (lastThrowable == null) {
+ logger.error(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.ERROR, componentMessage, arguments);
+ } else {
+ logger.error(componentMessage, setFormattedThrowable(arguments, lastThrowable));
+ logRepository.addLogMessage(LogLevel.ERROR, getCausesMessage(msg), addCauses(arguments, lastThrowable), lastThrowable);
+ }
}
+ }
- os = addProcessorAndThrowable(os, t);
- msg = "{} " + msg + ": {}";
+ @Override
+ public void error(final String msg, final Object[] os, final Throwable t) {
+ if (isErrorEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.error(msg, os);
- logRepository.addLogMessage(LogLevel.ERROR, msg, os, t);
+ if (t == null) {
+ logger.error(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.ERROR, componentMessage, arguments);
+ } else {
+ logger.error(componentMessage, arguments, t);
+ logRepository.addLogMessage(LogLevel.ERROR, getCausesMessage(msg), addCauses(arguments, t), t);
+ }
+ }
}
@Override
- public void error(LogMessage logMessage) {
+ public void error(final LogMessage logMessage) {
if (isErrorEnabled()) {
log(LogLevel.ERROR, logMessage);
logRepository.addLogMessage(logMessage);
}
}
- private Object[] addProcessorAndThrowable(final Object[] os, final Throwable t) {
- final Object[] modifiedArgs;
- if (t == null) {
- modifiedArgs = new Object[os.length + 2];
- modifiedArgs[0] = component.toString();
- System.arraycopy(os, 0, modifiedArgs, 1, os.length);
- modifiedArgs[modifiedArgs.length - 1] = StringUtils.EMPTY;
- } else {
- modifiedArgs = new Object[os.length + 3];
- modifiedArgs[0] = component.toString();
- System.arraycopy(os, 0, modifiedArgs, 1, os.length);
- modifiedArgs[modifiedArgs.length - 2] = getCauses(t);
- modifiedArgs[modifiedArgs.length - 1] = t;
- }
-
- return modifiedArgs;
- }
-
@Override
- public void debug(String msg, Throwable t) {
- if (!isDebugEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component};
+ public void debug(final String msg, final Throwable t) {
+ if (isDebugEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] repositoryArguments = getRepositoryArguments(t);
- logger.debug(msg, os, t);
- logRepository.addLogMessage(LogLevel.DEBUG, msg, os, t);
+ if (t == null) {
+ logger.debug(componentMessage, component);
+ logRepository.addLogMessage(LogLevel.DEBUG, componentMessage, repositoryArguments);
+ } else {
+ logger.debug(componentMessage, component, t);
+ logRepository.addLogMessage(LogLevel.DEBUG, getCausesMessage(msg), repositoryArguments, t);
+ }
+ }
}
@Override
- public void debug(String msg, Object[] os) {
- if (!isDebugEnabled()) {
- return;
- }
-
- os = addProcessor(os);
- msg = "{} " + msg;
+ public void debug(final String msg, final Object[] os) {
+ if (isDebugEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.debug(msg, os);
- logRepository.addLogMessage(LogLevel.DEBUG, msg, os);
+ final Throwable lastThrowable = findLastThrowable(os);
+ if (lastThrowable == null) {
+ logger.debug(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.DEBUG, componentMessage, arguments);
+ } else {
+ logger.debug(componentMessage, setFormattedThrowable(arguments, lastThrowable));
+ logRepository.addLogMessage(LogLevel.DEBUG, getCausesMessage(msg), addCauses(arguments, lastThrowable), lastThrowable);
+ }
+ }
}
@Override
- public void debug(String msg, Object[] os, Throwable t) {
- if (!isDebugEnabled()) {
- return;
- }
-
- os = addProcessorAndThrowable(os, t);
- msg = "{} " + msg + ": {}";
+ public void debug(final String msg, final Object[] os, final Throwable t) {
+ if (isDebugEnabled()) {
+ final String componentMessage = getComponentMessage(msg);
+ final Object[] arguments = insertComponent(os);
- logger.debug(msg, os);
- logRepository.addLogMessage(LogLevel.DEBUG, msg, os, t);
+ if (t == null) {
+ logger.debug(componentMessage, arguments);
+ logRepository.addLogMessage(LogLevel.DEBUG, componentMessage, arguments);
+ } else {
+ logger.debug(componentMessage, arguments, t);
+ logRepository.addLogMessage(LogLevel.DEBUG, getCausesMessage(msg), addCauses(arguments, t), t);
+ }
+ }
}
@Override
- public void debug(String msg) {
- if (!isDebugEnabled()) {
- return;
- }
-
- msg = "{} " + msg;
- final Object[] os = {component};
-
- logger.debug(msg, os);
- logRepository.addLogMessage(LogLevel.DEBUG, msg, os);
+ public void debug(final String msg) {
+ debug(msg, NULL_THROWABLE);
}
@Override
- public void debug(LogMessage logMessage) {
+ public void debug(final LogMessage logMessage) {
if (isDebugEnabled()) {
log(LogLevel.DEBUG, logMessage);
logRepository.addLogMessage(logMessage);
@@ -411,7 +389,7 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void log(LogLevel level, String msg, Throwable t) {
+ public void log(final LogLevel level, final String msg, final Throwable t) {
switch (level) {
case DEBUG:
debug(msg, t);
@@ -433,7 +411,7 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void log(LogLevel level, String msg, Object[] os) {
+ public void log(final LogLevel level, final String msg, final Object[] os) {
switch (level) {
case DEBUG:
debug(msg, os);
@@ -455,7 +433,7 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void log(LogLevel level, String msg) {
+ public void log(final LogLevel level, final String msg) {
switch (level) {
case DEBUG:
debug(msg);
@@ -477,7 +455,7 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void log(LogLevel level, String msg, Object[] os, Throwable t) {
+ public void log(final LogLevel level, final String msg, final Object[] os, final Throwable t) {
switch (level) {
case DEBUG:
debug(msg, os, t);
@@ -499,7 +477,7 @@ public class SimpleProcessLogger implements ComponentLog {
}
@Override
- public void log(LogMessage message) {
+ public void log(final LogMessage message) {
switch (message.getLogLevel()) {
case DEBUG:
debug(message);
@@ -520,6 +498,29 @@ public class SimpleProcessLogger implements ComponentLog {
}
}
+ /**
+ * Get arguments for Log Repository including a summary of Throwable causes when Throwable is found
+ *
+ * @param throwable Throwable instance or null
+ * @return Arguments containing the component or the component and summary of Throwable causes
+ */
+ private Object[] getRepositoryArguments(final Throwable throwable) {
+ return throwable == null ? new Object[]{component} : getComponentAndCauses(throwable);
+ }
+
+ private String getCausesMessage(final String message) {
+ return String.format("{} %s: {}", message);
+ }
+
+ private String getComponentMessage(final String message) {
+ return String.format("{} %s", message);
+ }
+
+ private Object[] getComponentAndCauses(final Throwable throwable) {
+ final String causes = getCauses(throwable);
+ return new Object[]{component, causes};
+ }
+
private String getCauses(final Throwable throwable) {
final List<String> causes = new ArrayList<>();
for (Throwable cause = throwable; cause != null; cause = cause.getCause()) {
@@ -527,4 +528,28 @@ public class SimpleProcessLogger implements ComponentLog {
}
return String.join(CAUSED_BY, causes);
}
+
+ private Object[] insertComponent(final Object[] originalArgs) {
+ return ArrayUtils.insert(0, originalArgs, component);
+ }
+
+ private Object[] addCauses(final Object[] arguments, final Throwable throwable) {
+ final String causes = getCauses(throwable);
+ return ArrayUtils.add(arguments, causes);
+ }
+
+ private Object[] setFormattedThrowable(final Object[] arguments, final Throwable throwable) {
+ final int lastIndex = arguments.length - 1;
+ final Object[] argumentsThrowableRemoved = ArrayUtils.remove(arguments, lastIndex);
+ return ArrayUtils.addAll(argumentsThrowableRemoved, throwable.toString(), throwable);
+ }
+
+ private Throwable findLastThrowable(final Object[] arguments) {
+ final Object lastArgument = (arguments == null || arguments.length == 0) ? null : arguments[arguments.length - 1];
+ Throwable lastThrowable = null;
+ if (lastArgument instanceof Throwable) {
+ lastThrowable = (Throwable) lastArgument;
+ }
+ return lastThrowable;
+ }
}
diff --git a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/test/java/org/apache/nifi/processor/TestSimpleProcessLogger.java b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/test/java/org/apache/nifi/processor/TestSimpleProcessLogger.java
index 97a0ba15f5..0ef86821b0 100644
--- a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/test/java/org/apache/nifi/processor/TestSimpleProcessLogger.java
+++ b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-components/src/test/java/org/apache/nifi/processor/TestSimpleProcessLogger.java
@@ -16,22 +16,22 @@
*/
package org.apache.nifi.processor;
+import org.apache.commons.lang3.reflect.FieldUtils;
+import org.apache.nifi.components.ConfigurableComponent;
import org.apache.nifi.logging.LogLevel;
-import org.apache.nifi.reporting.ReportingTask;
-import org.junit.Before;
-import org.junit.Test;
+import org.apache.nifi.logging.LogRepository;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.mockito.Mock;
+import org.mockito.junit.jupiter.MockitoExtension;
import org.slf4j.Logger;
-import java.lang.reflect.Field;
-
-import static org.junit.Assert.fail;
-import static org.mockito.ArgumentMatchers.anyString;
import static org.mockito.ArgumentMatchers.eq;
-import static org.mockito.Mockito.mock;
-import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
+@ExtendWith(MockitoExtension.class)
public class TestSimpleProcessLogger {
private static final String FIRST_MESSAGE = "FIRST";
@@ -44,71 +44,210 @@ public class TestSimpleProcessLogger {
String.format("- Caused by: %s: %s", SecurityException.class.getName(), THIRD_MESSAGE)
);
- private final Exception e = new IllegalArgumentException(FIRST_MESSAGE, new RuntimeException(SECOND_MESSAGE, new SecurityException(THIRD_MESSAGE)));
+ private static final Exception EXCEPTION = new IllegalArgumentException(FIRST_MESSAGE, new RuntimeException(SECOND_MESSAGE, new SecurityException(THIRD_MESSAGE)));
- private ReportingTask task;
+ private static final String EXCEPTION_STRING = EXCEPTION.toString();
- private SimpleProcessLogger componentLog;
+ private static final Throwable NULL_THROWABLE = null;
+
+ private static final String FIRST = "FIRST";
+
+ private static final int SECOND = 2;
+
+ private static final Object[] VALUE_ARGUMENTS = new Object[]{FIRST, SECOND};
+
+ private static final Object[] VALUE_EXCEPTION_ARGUMENTS = new Object[]{FIRST, SECOND, EXCEPTION};
+
+ private static final String LOG_MESSAGE = "Processed";
+
+ private static final String LOG_MESSAGE_WITH_COMPONENT = String.format("{} %s", LOG_MESSAGE);
+
+ private static final String LOG_MESSAGE_WITH_COMPONENT_AND_CAUSES = String.format("{} %s: {}", LOG_MESSAGE);
+
+ private static final String LOG_ARGUMENTS_MESSAGE = "Processed {} {}";
+
+ private static final String LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT = String.format("{} %s", LOG_ARGUMENTS_MESSAGE);
+
+ private static final String LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT_AND_CAUSES = String.format("{} %s: {}", LOG_ARGUMENTS_MESSAGE);
+
+ @Mock
+ private ConfigurableComponent component;
+ @Mock
+ private LogRepository logRepository;
+
+ @Mock
private Logger logger;
- @Before
- public void before() {
- task = mock(ReportingTask.class);
- when(task.getIdentifier()).thenReturn("foo");
- when(task.toString()).thenReturn("MyTask");
- componentLog = new SimpleProcessLogger(task.getIdentifier(), task);
- try {
- Field loggerField = componentLog.getClass().getDeclaredField("logger");
- loggerField.setAccessible(true);
- logger = mock(Logger.class);
-
- when(logger.isDebugEnabled()).thenReturn(true);
- when(logger.isInfoEnabled()).thenReturn(true);
- when(logger.isWarnEnabled()).thenReturn(true);
- when(logger.isErrorEnabled()).thenReturn(true);
- when(logger.isTraceEnabled()).thenReturn(true);
-
- loggerField.set(componentLog, logger);
- } catch (Exception e) {
- e.printStackTrace();
- fail(e.getMessage());
- }
+ private Object[] componentArguments;
+
+ private Object[] componentValueArguments;
+
+ private Object[] componentValueExceptionStringCausesArguments;
+
+ private Object[] componentCausesArguments;
+
+ private SimpleProcessLogger componentLog;
+
+ @BeforeEach
+ public void setLogger() throws IllegalAccessException {
+ componentLog = new SimpleProcessLogger(component, logRepository);
+ FieldUtils.writeDeclaredField(componentLog, "logger", logger, true);
+
+ componentArguments = new Object[]{component};
+ componentValueArguments = new Object[]{component, FIRST, SECOND};
+ componentValueExceptionStringCausesArguments = new Object[]{component, FIRST, SECOND, EXCEPTION, EXPECTED_CAUSES};
+ componentCausesArguments = new Object[]{component, EXPECTED_CAUSES};
+
+ when(logger.isTraceEnabled()).thenReturn(true);
+ when(logger.isDebugEnabled()).thenReturn(true);
+ when(logger.isInfoEnabled()).thenReturn(true);
+ when(logger.isWarnEnabled()).thenReturn(true);
+ when(logger.isErrorEnabled()).thenReturn(true);
}
@Test
- public void validateDelegateLoggerReceivesThrowableToStringOnError() {
- componentLog.error("Hello {}", e);
- verify(logger, times(1)).error(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
+ public void testLogLevelMessage() {
+ for (final LogLevel logLevel : LogLevel.values()) {
+ componentLog.log(logLevel, LOG_MESSAGE);
+
+ switch (logLevel) {
+ case TRACE:
+ verify(logger).trace(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component));
+ break;
+ case DEBUG:
+ verify(logger).debug(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component));
+ break;
+ case INFO:
+ verify(logger).info(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component));
+ break;
+ case WARN:
+ verify(logger).warn(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component));
+ break;
+ case ERROR:
+ verify(logger).error(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component));
+ break;
+ default:
+ continue;
+ }
+
+ verify(logRepository).addLogMessage(eq(logLevel), eq(LOG_MESSAGE_WITH_COMPONENT), eq(componentArguments));
+ }
}
@Test
- public void validateDelegateLoggerReceivesThrowableToStringOnInfo() {
- componentLog.info("Hello {}", e);
- verify(logger, times(1)).info(anyString(), eq(e));
+ public void testLogLevelMessageArguments() {
+ for (final LogLevel logLevel : LogLevel.values()) {
+ componentLog.log(logLevel, LOG_ARGUMENTS_MESSAGE, VALUE_ARGUMENTS);
+
+ switch (logLevel) {
+ case TRACE:
+ verify(logger).trace(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case DEBUG:
+ verify(logger).debug(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case INFO:
+ verify(logger).info(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case WARN:
+ verify(logger).warn(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case ERROR:
+ verify(logger).error(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ default:
+ continue;
+ }
+
+ verify(logRepository).addLogMessage(eq(logLevel), eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(componentValueArguments));
+ }
}
@Test
- public void validateDelegateLoggerReceivesThrowableToStringOnTrace() {
- componentLog.trace("Hello {}", e);
- verify(logger, times(1)).trace(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
+ public void testLogLevelMessageThrowable() {
+ for (final LogLevel logLevel : LogLevel.values()) {
+ componentLog.log(logLevel, LOG_MESSAGE, EXCEPTION);
+
+ switch (logLevel) {
+ case TRACE:
+ verify(logger).trace(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component), eq(EXCEPTION));
+ break;
+ case DEBUG:
+ verify(logger).debug(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component), eq(EXCEPTION));
+ break;
+ case INFO:
+ verify(logger).info(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component), eq(EXCEPTION));
+ break;
+ case WARN:
+ verify(logger).warn(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component), eq(EXCEPTION));
+ break;
+ case ERROR:
+ verify(logger).error(eq(LOG_MESSAGE_WITH_COMPONENT), eq(component), eq(EXCEPTION));
+ break;
+ default:
+ continue;
+ }
+
+ verify(logRepository).addLogMessage(eq(logLevel), eq(LOG_MESSAGE_WITH_COMPONENT_AND_CAUSES), eq(componentCausesArguments), eq(EXCEPTION));
+ }
}
@Test
- public void validateDelegateLoggerReceivesThrowableToStringOnWarn() {
- componentLog.warn("Hello {}", e);
- verify(logger, times(1)).warn(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
+ public void testLogLevelMessageArgumentsThrowable() {
+ for (final LogLevel logLevel : LogLevel.values()) {
+ componentLog.log(logLevel, LOG_ARGUMENTS_MESSAGE, VALUE_EXCEPTION_ARGUMENTS);
+
+ switch (logLevel) {
+ case TRACE:
+ verify(logger).trace(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND), eq(EXCEPTION_STRING), eq(EXCEPTION));
+ break;
+ case DEBUG:
+ verify(logger).debug(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND), eq(EXCEPTION_STRING), eq(EXCEPTION));
+ break;
+ case INFO:
+ verify(logger).info(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND), eq(EXCEPTION_STRING), eq(EXCEPTION));
+ break;
+ case WARN:
+ verify(logger).warn(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND), eq(EXCEPTION_STRING), eq(EXCEPTION));
+ break;
+ case ERROR:
+ verify(logger).error(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND), eq(EXCEPTION_STRING), eq(EXCEPTION));
+ break;
+ default:
+ continue;
+ }
+
+ verify(logRepository).addLogMessage(eq(logLevel), eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT_AND_CAUSES), eq(componentValueExceptionStringCausesArguments), eq(EXCEPTION));
+ }
}
@Test
- public void validateDelegateLoggerReceivesThrowableToStringOnLogWithLevel() {
- componentLog.log(LogLevel.WARN, "Hello {}", e);
- verify(logger, times(1)).warn(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
- componentLog.log(LogLevel.ERROR, "Hello {}", e);
- verify(logger, times(1)).error(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
- componentLog.log(LogLevel.INFO, "Hello {}", e);
- verify(logger, times(1)).info(anyString(), eq(e));
- componentLog.log(LogLevel.TRACE, "Hello {}", e);
- verify(logger, times(1)).trace(anyString(), eq(task), eq(EXPECTED_CAUSES), eq(e));
+ public void testLogLevelMessageArgumentsThrowableNull() {
+ for (final LogLevel logLevel : LogLevel.values()) {
+ componentLog.log(logLevel, LOG_ARGUMENTS_MESSAGE, VALUE_ARGUMENTS, NULL_THROWABLE);
+
+ switch (logLevel) {
+ case TRACE:
+ verify(logger).trace(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case DEBUG:
+ verify(logger).debug(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case INFO:
+ verify(logger).info(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case WARN:
+ verify(logger).warn(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ case ERROR:
+ verify(logger).error(eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(component), eq(FIRST), eq(SECOND));
+ break;
+ default:
+ continue;
+ }
+
+ verify(logRepository).addLogMessage(eq(logLevel), eq(LOG_ARGUMENTS_MESSAGE_WITH_COMPONENT), eq(componentValueArguments));
+ }
}
}
diff --git a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-core/src/main/java/org/apache/nifi/controller/tasks/ConnectableTask.java b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-core/src/main/java/org/apache/nifi/controller/tasks/ConnectableTask.java
index 9b2a5552d8..bc947f659e 100644
--- a/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-core/src/main/java/org/apache/nifi/controller/tasks/ConnectableTask.java
+++ b/nifi-nar-bundles/nifi-framework-bundle/nifi-framework/nifi-framework-core/src/main/java/org/apache/nifi/controller/tasks/ConnectableTask.java
@@ -242,19 +242,16 @@ public class ConnectableTask {
shouldRun = repositoryContext.isRelationshipAvailabilitySatisfied(requiredNumberOfAvailableRelationships);
}
}
- } catch (final TerminatedTaskException tte) {
- final ComponentLog procLog = new SimpleProcessLogger(connectable.getIdentifier(), connectable.getRunnableComponent());
- procLog.info("Failed to process session due to task being terminated", new Object[] {tte});
- } catch (final ProcessException pe) {
- final ComponentLog procLog = new SimpleProcessLogger(connectable.getIdentifier(), connectable.getRunnableComponent());
- procLog.error("Failed to process session due to {}", new Object[] {pe});
- } catch (final Throwable t) {
- // Use ComponentLog to log the event so that a bulletin will be created for this processor
- final ComponentLog procLog = new SimpleProcessLogger(connectable.getIdentifier(), connectable.getRunnableComponent());
- procLog.error("Failed to process session due to {}; Processor Administratively Yielded for {}",
- new Object[] {t, schedulingAgent.getAdministrativeYieldDuration()}, t);
- logger.warn("Administratively Yielding {} due to uncaught Exception: {}", connectable.getRunnableComponent(), t.toString(), t);
-
+ } catch (final TerminatedTaskException e) {
+ final ComponentLog componentLog = getComponentLog();
+ componentLog.info("Processing terminated", e);
+ } catch (final ProcessException e) {
+ final ComponentLog componentLog = getComponentLog();
+ componentLog.error("Processing failed", e);
+ } catch (final Throwable e) {
+ final ComponentLog componentLog = getComponentLog();
+ componentLog.error("Processing halted: yielding [{}]", schedulingAgent.getAdministrativeYieldDuration(), e);
+ logger.warn("Processing halted: uncaught exception in Component [{}]", connectable.getRunnableComponent(), e);
connectable.yield(schedulingAgent.getAdministrativeYieldDuration(TimeUnit.NANOSECONDS), TimeUnit.NANOSECONDS);
}
} finally {
@@ -291,4 +288,7 @@ public class ConnectableTask {
return InvocationResult.DO_NOT_YIELD;
}
+ private ComponentLog getComponentLog() {
+ return new SimpleProcessLogger(connectable.getIdentifier(), connectable.getRunnableComponent());
+ }
}