Marian Barton created LOG4J2-3585:
-------------------------------------
Summary: Exception in Parameterized Message not logged using
LocationAwareLogger API
Key: LOG4J2-3585
URL: https://issues.apache.org/jira/browse/LOG4J2-3585
Project: Log4j 2
Issue Type: Bug
Components: SLF4J Bridge
Affects Versions: 2.17.1
Environment: Windows 10, Tomcat 9, Java 8
Reporter: Marian Barton
+Versions:+
* slf4j-api version 1.7.36
* log4j-core/log4j-slf4j-impl: 2.17.1
+Action:+
Logging a message using LocationAwareLogger.log including an exception as
unused last parameter in the params array.
+Result:+
The message is constructed correctly but the exception is being ignored and not
logged.
+Expected:+
According to the SLF4J FAQ, passing an exception as unused parameter in the
last place should result in it being interpreted as Exception and logged as
such.
+Example:+
{code:java}
// Method in wrapping custom logger
public void error(final String message, final Object... argArray) {
logger.log(null, FQCN, LocationAwareLogger.ERROR_INT, message, argArray,
null);
}
// Call from another class to that method
String someString = "insertedString";
LOGGER.log("Test {}", someString, someException);
// Result - no exception logged, only message
2022-Aug.-31 12:41:59,829 [https-openssl-nio-443-exec-4] some.Class
ERROR Test insertedString
// this works though
public void error(final String message, final Object... argArray) {
logger.error(message, argArray);
}{code}
The same call works when not using the LocationAwareLogger log method but the
standard logger.error(String message, Object... argArray) method. But since I
am using a wrapping logger I have to use the LocationAwareLogger interface in
order to conserve the location information.
+Possible solution:+
I debugged a bit to try and find the issue and I might have found the problem
inside the org.apache.logging.slf4j.Log4jLogger.log method:
{code:java}
@Override
public void log(final Marker marker, final String fqcn, final int level, final
String message, final Object[] params, Throwable throwable) {
final Level log4jLevel = getLevel(level);
final org.apache.logging.log4j.Marker log4jMarker = getMarker(marker);
if (!logger.isEnabled(log4jLevel, log4jMarker, message, params)) {
return;
}
final Message msg;
if (CONVERTER != null && eventLogger && marker != null &&
marker.contains(EVENT_MARKER)) {
msg = CONVERTER.convertEvent(message, params, throwable);
} else if (params == null) {
msg = new SimpleMessage(message);
} else {
msg = new ParameterizedMessage(message, params, throwable);
if (throwable != null) {
throwable = msg.getThrowable();
}
}
logger.logMessage(fqcn, log4jLevel, log4jMarker, msg, throwable);
}
{code}
The problem here specifically being this part:
{code:java}
} else {
msg = new ParameterizedMessage(message, params, throwable);
if (throwable != null) {
throwable = msg.getThrowable();
}
}
{code}
Log4J successfully detects this as and creates a ParameterizedMessage. This
instance also correctly found the Throwable from the parameters and set it to
its throwable property.
Now I think the bug here is that the if condition is inverted. As I have no
Throwable explicitly passed to this method (because it is passed via the
params), it is currently null. In this case SLF4J should check if a Throwable
is set and if not try to get it from the ParameterizedMessage, because there it
was successfully detected inside the constructor.
The correct implementation would therefore be:
{code:java}
} else {
msg = new ParameterizedMessage(message, params, throwable);
if (throwable == null) {
throwable = msg.getThrowable();
}
}
{code}
If the throwable is not set here, it remains inside the ParameterizedMessage
and is ignored by Log4J, as Log4J appears to only respect the explicit
Throwable parameter.
Any questions, feedback and help are/is appreciated.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
