Closed chrissydee closed 5 years ago
vy
commented
5 years ago Hey @chrissydee, thanks for the report. I will see if I can find time to work on it sometime this week. In the meantime, if you can create a narrowed down case that reproduces the problem for me, it would be really helpful.
chrissydee
commented
5 years ago Hey @vy, I adapt your LogstashLayoutDemo. Maybe you have to run the code multiple times before you see the wrong JSON lines. If you increase the num of log messages or threads, you can see your Exception from the LogstashLayout.class. Replace the log4j2.xml and add JSONEventLayoutV0.json too.
Thanks, for your fast reply.
Best,
Christian
log4j2-logstash-layout/layout-demo/src/main/java/com/vlkan/log4j2/logstash/layout/demo/LogstashLayoutDemo.java
package com.vlkan.log4j2.logstash.layout.demo;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import java.util.Arrays;
import java.util.List;
import java.util.Random;
public class LogstashLayoutDemo {
private static Logger LOGGER= LogManager.getLogger(LogstashLayoutDemo.class);
private static String LOREM= "Lorem ipsum dolor sit amet, consectetur adipiscing elit. Ut molestie in sapien vestibulum varius. Donec malesuada lacinia leo sit amet posuere. Praesent a odio ut felis elementum gravida ut id risus. Ut egestas et dolor at varius. Donec placerat interdum vulputate. Cras tellus dui, pretium lacinia feugiat in, mollis ut nulla. Praesent eu elementum nunc, eu elementum urna. Vestibulum malesuada vulputate nulla faucibus dapibus. In hac habitasse platea dictumst. Duis tempor suscipit leo in ornare.";
private static int NUM_THREADS= 10;
private static int NUM_LOGS_PER_THREAD= 15;
public static void main(String[] args) {
Runnable runnable= () -> {
for (int i= 0; i < NUM_LOGS_PER_THREAD; i++) {
String logMessage = generateRandomLogMessage();
switch((new Random()).nextInt(2)) {
case 0:
LOGGER.info(logMessage);
break;
case 1:
LOGGER.debug(logMessage);
break;
default:
LOGGER.error(logMessage, new RuntimeException("Error!"));
break;
}
}
};
for (int i= 0; i < NUM_THREADS; i++) {
Thread thread= new Thread(runnable);
thread.start();
}
}
public static String generateRandomLogMessage() {
List<String> list= Arrays.asList(LOREM.split("\\s*?\\.\\s*"));
Random rnd= new Random();
return String.join(". ", list.subList(0, 1+Math.abs(rnd.nextInt(list.size()-1))));
}
}log4j2-logstash-layout/layout-demo/src/main/resources/log4j2.xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">
<Appenders>
<Console name="CONSOLE" target="SYSTEM_OUT">
<LogstashLayout dateTimeFormatPattern="yyyy-MM-dd'T'HH:mm:ss.SSS'Z'"
timeZoneId="UTC"
eventTemplateUri="classpath:JSONEventLayoutV0.json"
locationInfoEnabled="true"
prettyPrintEnabled="false"
stackTraceEnabled="true"/>
</Console>
</Appenders>
<Loggers>
<Root level="DEBUG">
<AppenderRef ref="CONSOLE"/>
</Root>
</Loggers>
</Configuration>log4j2-logstash-layout/layout-demo/src/main/resources/JSONEventLayoutV0.json
{
"@version": null,
"@message": "${json:message}",
"@timestamp": "${json:timestamp}",
"@source_host": "${hostName}",
"@fields": {
"exception": {
"stacktrace": "${json:exception:stackTrace:text}",
"exception_class": "${json:exception:className}",
"exception_message": "${json:exception:message}"
},
"file": "${json:source:fileName}",
"method": "${json:source:methodName}",
"level": "${json:level}",
"line_number": "${json:source:lineNumber}",
"loggerName": "${json:logger:name}",
"class": "${json:source:className}",
"mdc": "${json:mdc}",
"ndc": "${json:ndc}",
"threadName": "${json:thread:name}"
}
}@chrissydee, I believe you can temporarily work around the issue by disabling TLA via log4j2.enable.threadlocals=false JVM property variable. In the meantime, I am checking the issue. (#27 is taking longer than I expected and sort of related with this issue.)
chrissydee
commented
5 years ago Hi @vy, changing the property log4j2.enable.threadlocals does not work. Even in my provided code example the JSON becomes invalid. I put a breakpoint at LogstashLayoutSerializationContexts
boolean threadLocalEnabled = THREAD_LOCALS_ENABLED;
return threadLocalEnabled
? createThreadLocalSupplier(jsonFactory, maxByteCount, prettyPrintEnabled, emptyPropertyExclusionEnabled)
: createNewInstanceSupplier(jsonFactory, maxByteCount, prettyPrintEnabled, emptyPropertyExclusionEnabled);to check if the property is used. Both supplier, the ThreadLocalSupplier and NewInstanceSupplier, has this issue.
By the way: the documentation of Log4J2 says, that the property is ineffective in web applications (see https://logging.apache.org/log4j/2.x/manual/configuration.html#SystemProperties).
This system property can be used to switch off the use of threadlocals, which will partly disable Log4j's garbage-free behaviour: to be fully garbage-free, Log4j stores objects in ThreadLocal fields to reuse them, otherwise new objects are created for each log event. Note that this property is not effective when Log4j detects it is running in a web application.
vy
commented
5 years ago @chrissydee, I think the fix I pushed for #27 addresses your issue as well via this change. If I am not mistaken, after having that synchronized block, I cannot reproduce the bug anymore. Would you mind testing and verifying the fix, please? In the meantime, I will try to write a unit test for that.
vy
commented
5 years ago @chrissydee, I have pushed LogstashLayoutConcurrentEncodeTest to bakomchik-fix-corrupted-generator-state branch. I also want to add your name to the list of contributors in the README. Shall I just write "chrissydee" or would you rather prefer your real name linked to your GitHub account?
vy
commented
5 years ago Merged the changes to master and cut a release. v0.18 should momentarily arrive in Maven Central.
JupellyRakesh
commented
3 years ago Hi @vy, Please check and confirm Issue still exist for new maven version(
vy
commented
3 years ago @JupellyRakesh, log4j2-logstash-layout is superseded by log4j-template-layout-json. It shouldn't take much effort to migrate to that – replace the artifact name and adapt the template. Is migration to log4j-template-layout-json an option for you?
Hi Volkan,
Since we use the JSONEventLayoutV0 of the Logstash implementation, I created my own template. Within the written log file, the JSON string is fragmented in many places and no longer valid. In our application logs I can see several exceptions. All exceptions refer to the used ByteBuffer.
log4j2.xml
JSONEventLayoutV0.json
Stacktrace