There are JVM properties to reduce both the number of slot of the ring
buffer, and the maximum size of the StringBuilder used inside each slot.
Tuning these should help to lower the extra memory footprint. I don't
remember them (and cannot do the search right now) but they are documented
on log4j website.
Using async loggers is a tradeoff, you hide the disk storage latency and
reduce object allocations at the cost of some extra memory footprint. If
this is a limiting factor, maybe you should re-evaluate your options to see
if async loggers are the best configuration for your use case, especially
if your application does not log massively.
Le mar. 20 févr. 2024 à 11:24, Ganesh S <ganesh123.g...@gmail.com> a écrit :
> Hello,
> I'm using asynchronous Rolling file appender by passing
> *-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector*
> as VM argument, which internally uses lmax disruptor.
> *Load test specs:*
> 1000 threads, 0 ramp-up period, 1 loop count.
> Business application which will log 197 KB json for each log message
> and each request thread will log 2 MB considering all the log statements in
> the application. Similarly there will be 1000 simultaneous request threads
> coming to the tomcat server.
> When we compare asynchronous logging with synchronous logging the memory
> consumption is too high in asynchronous logging.
>
> The major memory contributor is the byte[] object, which is 2.02 GB and
> instance count is 1,73,734.
> Whereas in synchronous logging the byte[] object took 900 MB max.
> [image: image.png]
>
> If we check the incoming reference to the byte[] object,
> RingBufferLogEvent is pointing to the byte[] object through SimpleMessage
> class.
> [image: image.png]
>
> *RingBufferLogEvent is pointing to SimpleMessage which is storing the log
> message as byte[], which is of the size 197 kB (equal to single log message
> size).*
>
> [image: image.png]
> *Similar to that, there are 1,73,534 instances.*
>
> *If we see the shallow size of RingBufferLogEvent, it is 27 MB, but
> including the external reference object, i.e., byte[], it reaches 2.02 GB.*
> [image: image.png]
> *In Async logging, number of waiting thread are high, since lmax
> disruptor is based on inter-thread messaging*
>
> [image: image.png]
>
> *In sync logging number of blocking threads are high, since it uses lock
> based logging*
>
> [image: image.png]
>
> Waiting and runnable threads are more in async logging therefore the
> memory consumed could be high. If we see the throughput of request threads,
> sync took 32 sec and async took 5 sec for 1000 concurrent requests. Async
> logging took an extra 5 sec in the background, since the daemon thread was
> pushing remaining logs to the file, which won't affect the business thread
> throughput.
>
> *Problem:*
> But the problem is, we can't afford extra 2 GB memory on top of the memory
> required for running the business logic. Atleast async logging should take
> reasonable memory near to synchronous logging with good throughput. If we
> allocate reasonable memory, due to a spike in the memory (though GC will
> collect the unreferred objects after the load is less), application will
> return the heap memory issue.
>
> Below is the programmatic initialization of the rolling file appender that
> we are using.
>
> ConfigurationBuilder<BuiltConfiguration> builder =
> ConfigurationBuilderFactory.newConfigurationBuilder();
> LayoutComponentBuilder layoutBuilder = builder.newLayout("PatternLayout")
> .addAttribute("pattern", "%m%n");
> AppenderComponentBuilder appenderBuilder = builder.newAppender("rolling",
> "RollingFile")
> .addAttribute("fileName", path)
> .addAttribute("filePattern", name + "-%i.log")
> .add(layoutBuilder);
> appenderBuilder.addComponent(builder.newComponent("Policies")
>
> .addComponent(builder.newComponent("SizeBasedTriggeringPolicy")
> .addAttribute("size", maxFileSize)));
> appenderBuilder.addComponent(builder.newComponent("DefaultRolloverStrategy")
> .addAttribute("max", maxBackUpFile)
> .addAttribute("fileIndex", "max"));
> appenderBuilder.add(builder.newFilter("ThresholdFilter",
> Filter.Result.ACCEPT, Filter.Result.DENY)
> .addAttribute("level", fileLevel));
> builder.add(appenderBuilder);
> builder.add(builder.newRootLogger(fileLevel)
> .add(builder.newAppenderRef("rolling")));
> Configurator.reconfigure(builder.build());
>
> Which is similar to
>
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration status="INFO">
> <Appenders>
> <RollingFile
> name="rolling"
> fileName="path"
> filePattern="name-%i.log">
> <PatternLayout pattern="%m%n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10MB"/>
> </Policies>
> <DefaultRolloverStrategy max="5" fileIndex="max"/>
> <Filters>
> <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/>
> </Filters>
> </RollingFile>
> </Appenders>
>
> <Loggers>
> <Root level="debug">
> <AppenderRef ref="rolling"/>
> </Root>
> </Loggers>
> </Configuration>
>
> logger = LogManager.getLogger();
> logger.info("message1");
> logger.debug("message2");
> logger.error("message3");
>
> Any input or solution is appreciated. Thanks in advance.
>
> Thanks,
> Ganesh S
>
>
>
>
