[
https://issues.apache.org/jira/browse/LOG4J2-1409?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15314094#comment-15314094
]
Remko Popma commented on LOG4J2-1409:
-------------------------------------
Actually, this can happen even without a lambda, whenever a parameter array of
length less than 10 is specified. For example:
{code}
logger.info("Hello {}", new Object[]{1});
logger.info("Hello {} {} {}", 1, 2,3);
logger.info("Hello {} {} {}", 1, 2,3);
gives
Exception in thread "main" java.lang.ArrayIndexOutOfBoundsException: 1
at
org.apache.logging.log4j.message.ReusableParameterizedMessage.set(ReusableParameterizedMessage.java:129)
at
org.apache.logging.log4j.message.ReusableMessageFactory.newMessage(ReusableMessageFactory.java:112)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2030)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1906)
at
org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1445)
at LOG4J2_1409.main(LOG4J2_1409.java:16)
{code}
It has to do with the mechanism introduced to preserve parameters
(LOG4J2-1342): the swapParameters() method.
Essentially, explicitly specifying a small parameter array will mean that this
small array ends up being swapped in.
Unit test that reproduces the issue:
{code}
package org.apache.logging.log4j.message;
// test must be in log4j-core but in org.apache.logging.log4j.message package
because it calls package-private methods
import org.apache.logging.log4j.core.impl.MutableLogEvent;
import org.junit.Test;
public class MutableLogEventWithReusableParamMsgTest {
@Test
public void testInteractionWithReusableParameterizedMessage() {
MutableLogEvent evt = new MutableLogEvent();
ReusableParameterizedMessage msg = new ReusableParameterizedMessage();
msg.set("Hello {} {} {}", 1, 2, 3);
evt.setMessage(msg);
evt.clear();
msg.set("Hello {}", new Object[]{1});
evt.setMessage(msg);
evt.clear();
msg.set("Hello {}", 1);
evt.setMessage(msg);
evt.clear();
// Uncomment out this log event and the params gets reset correctly (No
exception occurs)
// msg.set("Hello {}", 1);
// evt.setMessage(msg);
// evt.clear();
// Exception at this log event - as the params is set to 1!
msg.set("Hello {} {} {}", 1, 2, 3);
evt.setMessage(msg);
evt.clear();
}
}
{code}
Fix
{code}
Index:
log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
---
log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
(revision )
+++
log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
(revision )
@@ -62,10 +62,32 @@
Object[] result;
if (varargs == null) {
result = params;
- params = Objects.requireNonNull(emptyReplacement);
+ if (emptyReplacement.length < 10) { // Bad replacement! Too small,
may blow up future 10-arg messages.
+ if (argCount <= emptyReplacement.length) {
+ // copy params into the specified replacement array and
return that
+ System.arraycopy(params, 0, emptyReplacement, 0, argCount);
+ result = emptyReplacement;
- } else {
+ } else {
+ // replacement array is too small for current content and
future content: discard it
+ params = new Object[10];
+ }
+ } else {
+ params = emptyReplacement;
+ }
+ } else {
+ // Whatever array we return, the caller will likely try to reuse
it in future swapParameter() calls.
+ // However, if the vararg array is less than 10 params it is not
reusable.
+ // If we ignore this fact and still *swap* with the specified
array, then the specified array will likely
+ // be discarded (even though it had 10 slots and was perfectly
reusable).
+ // Instead, we
+ if (argCount <= emptyReplacement.length) {
+ // copy params into the specified replacement array and return
that
+ System.arraycopy(varargs, 0, emptyReplacement, 0, argCount);
+ result = emptyReplacement;
+ } else {
- result = varargs;
- varargs = Objects.requireNonNull(emptyReplacement);
+ result = varargs;
+ varargs = Objects.requireNonNull(emptyReplacement);
+ }
}
return result;
}
{code}
> ArrayIndexOutOfBoundsException in ReusableParameterizedMessage
> ---------------------------------------------------------------
>
> Key: LOG4J2-1409
> URL: https://issues.apache.org/jira/browse/LOG4J2-1409
> Project: Log4j 2
> Issue Type: Bug
> Components: API, Core
> Affects Versions: 2.6
> Reporter: Shahan
> Assignee: Remko Popma
> Priority: Critical
>
> A specific set of parameterised logging messages produces an Array Index Out
> of Bounds exception. It occurs due to the params array (initially set to 10)
> being reset to a lower number due to a lambda function passed in as an
> parameter. Then the subsequent logging messages don't reset this number.
> Best to explain in an example:
> {code}
> static Logger logger = LogManager.getLogger();
> public static void main(String[] args) {
> logger.info("Hello {} {} {}", 1, 2,3);
> logger.info("Hello {}", () -> "World");
> logger.info("Hello {}", 1);
>
> // Uncomment out this log event and the params gets reset correctly
> // No exception occurs
> // logger.info("Hello {}", 1);
> // Exception at this log event - as the params is set to 1!
> logger.info("Hello {} {} {}", 1, 2,3);
> }
> {code}
> Work around for this is not to use the ReusableParameterizedMessage. Instead
> to specify the legacy Message Factory of ParameterizedMessageFactory as a
> property of the program and no exception occurs.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
