I removed System.setProperty("AsyncLoggerContextSelector",
"org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
No change in CPU, but going from FastRollingFile to RollingFile I got back 10%
of my lost CPU. Still at 40% CPU where v1 runs at 20%.
I would like to get down to the equivalent behavior as we got from log4j v1,
then try v2 features to get it better. Since I'm still seeing worse
performance, I'm guessing that there's still one or more threads under the hood
vs V1 with: sync Logger and RollingFile.
Any guesses for me to try?
Tnx curt
_____________________________________________
From: SMITH, CURTIS
Sent: Friday, July 26, 2013 1:16 PM
To: [email protected]
Subject: async logger on slow single core env performs 50% worse than log4j v1
I suspect a slow single core env is a new scenario for v2 and async logger.
My view is that there's a mis match between v2's async logger thread design
that works great on multi-core envs and this embedded slow single core env...
Sooo I need to try a few different configurations to see what does run best on
a slow single core...
But I need your tips as to what I might change / tune to get v2 to perform as
good or better than v1 in a single core env.
FWIW: log4j v1 ran my standard use case test averaging 20% CPU. Log4j v2 ran
at 50% CPU, so more than 2x worse.
Our business logic is highly threaded so any subsystem that has a "hot" thread
like this config that has 5 loggers and 3 appenders I might be shooting myself
in the foot. You know this new design the best so I'm open as to what to pick
and choose from v2 that is likely to perform the best?
FYI: I feel using system properties vs exclusively using declarative
configuration all within the log4j2.xml separates out configuration. I'd
prefer to not have to use system properties for any configuration.
My first experiment will be to remove the async logger property.
Any thoughts re the FastRollingFile appender or any other tuning that might be
better for a single core env. It's a slow Arm v5 or so, pretty old and lacking
the better context switching features of newer chips. The VM is also slow,
IBM J9 J2ME JDK1.6. Benchmarking the J9 vs Oracle J2ME, J9 is real slow and
poor at thread context switching. But you get what you pay for, J9 is also
real cheap.
******
******
Note: the log files are on /tmp a memory FS in our env. So the worst case of
a synchronous logger from the same thread as the logger.debug call may not
perform that badly thanks to Linux FS buffering and memfs having low latency.
Just mentioning.
// Manually set the log4j v2 async logger tuning parameters here. DLA does not
have a system property
// property file
System.setProperty("AsyncLoggerContextSelector",
"org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
System.setProperty("AsyncLogger.RingBufferSize", "128");
// min size permissable to keep memory low
System.setProperty("AsyncLogger.WaitStrategy", "Block");
// less CPU, better for embedded env
System.setProperty("log4j2.disable.jmx", "true");
// saves on a jmx jar and we don't use JMX anyway
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="trace" level="trace" > <!-- log4j v2 debug add these:
status="trace" level="trace" -->
<appenders>
<FastRollingFile name="DLA"
fileName="/tmp/att/sync/log/dla.log"
filePattern="/tmp/att/sync/log/dla.log.%i"
append="true">
<PatternLayout>
<pattern>[%d][%-5p][%-15t][%-15c{1}]:%m%n</pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="3 MB" />
</Policies>
<DefaultRolloverStrategy max="2" />
</FastRollingFile>
<FastRollingFile name="DEVICES"
fileName="/tmp/att/sync/log/dla_devices.log"
filePattern="/tmp/att/sync/log/dla_devices.log.%i"
append="true">
<PatternLayout>
<pattern>[%d][%-5p][%-15t][%-15c{1}]:%m%n</pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="3 MB" />
</Policies>
<DefaultRolloverStrategy max="1" />
</FastRollingFile>
<FastRollingFile name="VIDEO"
fileName="/tmp/att/sync/log/dla_video.log"
filePattern="/tmp/att/sync/log/dla_video.log.%i"
append="true">
<PatternLayout>
<pattern>[%d][%-5p][%-15t][%-15c{1}]:%m%n</pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="3 MB" />
</Policies>
<DefaultRolloverStrategy max="1" />
</FastRollingFile>
<Console name="CO" target="SYSTEM_OUT">
<PatternLayout pattern="%d %-5p [%t] %C{2} (%F:%L) -
%m%n" />
</Console>
</appenders>
<loggers>
<logger name="com.att.dlc.afm" additivity="false" >
<appender-ref ref="DLA" />
</logger>
<logger name="com.att.dlc.devices" additivity="false"
level="debug">
<appender-ref ref="DEVICES" />
</logger>
<logger name="com.att.dlc.util.serialport" additivity="false"
level="debug">
<appender-ref ref="DEVICES" />
</logger>
<logger name="com.att.dlc.webcamserver" additivity="false"
level="debug">
<appender-ref ref="VIDEO" />
</logger>
<logger name="com.att.dlc.devices.cameras" additivity="false"
level="debug">
<appender-ref ref="VIDEO" />
</logger>
<root level="debug">
<appender-ref ref="DLA" />
</root>
</loggers>
</configuration>
Curt Smith
AT&T Digital Life
DLC Software Development
404-499-7013
(cell) 678-365-6508
