Isn't testing the v1 NDC against v2 MDC comparing apples and oranges? V1 has an MDC and V2 also has a ContextStack if that is what you want
Sent from my iPad On Sep 4, 2013, at 7:09 AM, "SMITH, CURTIS" <[email protected]> wrote: > Just wanting to report my final findings of perf comparison of log4j v1 NDC > vs v2 MDC: > > In my single core, ARM on IBM J9 VM: NDC ran 57% ave CPU where v2 MDC ran > 76% CPU for the same use case test scenario. We are having to stick with v1 > and NDC. This app can't afford loosing CPU. > > My 2 cents: I think a benchmark that measures bytes/sec or log lines/sec > and code that tunes for higher throughput might give a false sense of > accomplishment. Just a thought. My preferred benchmark for a logging > library after my experience testing v1 vs v2 would be: run the logging at a > typical rate of logging lines per second then tune the code for the lowest > CPU lost to the logging function. The java implementation may be different > for lowest CPU vs highest byte rate. Just a possibility. My testing > results finds something like this is in play. Too bad I can't test this app > on a fast multi core env to see if my results hold for the Oracle VM on fast > multi core... > > Some guesses: a design change (v2) that is benchmarked on an (effective) > infinite number of free cores env may give a false metric for improved > performance vs if run on a typical application env that has a shortage of > cores and the application already has the CPU running high. My single core > env is the extreme of CPU starved app env, where if logging has to wait for a > thread to schedule onto the core more cpu maybe burned up to accomplish the > same logging volume. I now feel that bytes per sec run on an idle multi > core test env gives false perf metrics. I suspect a better benchmark would > fix the byte rate to be a constant well below the maximum and tune the design > for minimum CPU. Production environments I've worked on do not have much > spare CPU. :) > > curt > > -----Original Message----- > From: SMITH, CURTIS > Sent: Friday, July 26, 2013 5:55 PM > To: Log4J Users List > Subject: RE: async logger on slow single core env performs 50% worse than > log4j v1 > > LOL well that's obvious now. :) It was more a case of wishful thinking and > why not give it a "try". But it's still odd that my attempts to slim it > down It's still 2x worse than v1. Something else is in play. > > curt > > -----Original Message----- > From: Ralph Goers [mailto:[email protected]] > Sent: Friday, July 26, 2013 5:34 PM > To: Log4J Users List > Subject: Re: async logger on slow single core env performs 50% worse than > log4j v1 > > I'm curious why you are even trying to use Async anything with a single core > environment (unless it is hyper-threaded). Only 1 thread can be active at a > time so when you switch threads the active thread will just stop. This won't > gain you any additional throughput but you will still incur the additional > overhead of thread management and locking. > > Ralph > > On Jul 26, 2013, at 1:55 PM, SMITH, CURTIS wrote: > >> 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 > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
