logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gary Gregory <garydgreg...@gmail.com>
Subject Re: Fast and Furious
Date Mon, 21 Mar 2016 07:08:34 GMT
FYI: Yourkit has three profiling modes: sampling, counting and tracing.
On Mar 20, 2016 11:47 PM, "Remko Popma" <remko.popma@gmail.com> wrote:

> I did try profiling with YourKit and MissionControl but they did not tell
> me much. I suppose a sampling profiler does not help much for problems like
> this when we are not spending a lot of time in certain methods... I'm
> thinking to experiment further with the different event options for perf
> stat, and take a look at Oracle Solaris Studio Performance Analyzer.
>
> There were many changes in 2.4 but most of the performance-related changes
> were downstream from the Disruptor in layout etc. They should not matter
> since I'm only measuring how fast an application can add simple string log
> events in to the ring buffer. (The perf test is with a No-Op appender.) The
> only thing that jumps out to me is the nano time support change... I will
> experiment with how performance changes if I roll back that feature.
>
> I'm not giving up just yet.
>
>
> On Mon, Mar 21, 2016 at 5:17 PM, Ralph Goers <ralph.goers@dslextreme.com>
> wrote:
>
>> Unfortunately there were a lot of changes in 2.4, many of which said they
>> were to improve performance. We also switched from Java 6 to Java 7.
>>
>> Did you try profiling with YourKit?
>>
>> Ralph
>>
>> On Mar 20, 2016, at 11:07 PM, Remko Popma <remko.popma@gmail.com> wrote:
>>
>> Quick update on the ongoing investigation in the performance regression:
>> I tried running SimplePerfTest on linux with perf stat and got these
>> results:
>> <investigation20160319_23898_image002.png>
>> ​How to read this:
>> * Throughput is number of messages logged per second (1.0 ~= 7 million
>> msg/sec)
>> * Instr/cycle is instructions per clock cycle
>> * Branch miss% is the number of branch prediction misses as a percentage
>> of all branches
>>
>> Analysis:
>> Throughput of log4j 2.0-2.3 on this machine is about 5.3 million msg/sec
>> on average.
>> From 2.4, this suddenly gaps down to 3.9 million msg/sec.
>> At the same time, the number of branch misses jump up from 0.27% to
>> 0.63%, correlating with a much less efficient execution: from 1.47 to 1.06
>> instructions per clock cycle.
>>
>> Conclusion:
>> It seems that one or more of the changes made in log4j 2.4 resulted in an
>> increase in branch misses during execution.
>> This may not be the only problem but it may help to give some direction
>> in the search.
>>
>> Remko
>>
>> On Thu, Mar 10, 2016 at 3:06 AM, Remko Popma <remko.popma@gmail.com>
>> wrote:
>>
>>> I think you're right, that one should not leak.
>>>
>>> On Thu, Mar 10, 2016 at 2:40 AM, Matt Sicker <boards@gmail.com> wrote:
>>>
>>>> I know it's Java 1.8+, but does ThreadLocal.withInitial(Supplier<S>)
>>>> prevent that memory leak? They use their own JDK class to subclass
>>>> ThreadLocal, so that shouldn't leak.
>>>>
>>>> On 8 March 2016 at 22:43, Remko Popma <remko.popma@gmail.com> wrote:
>>>>
>>>>> ThreadLocals containing JDK classes (StringBuilder, etc) are not a
>>>>> problem. Their classloader is the system classloader, not the web app
>>>>> classloader, so these ThreadLocals do not have a reference to the web app
>>>>> classes and do not prevent web app classes from being garbage collected.
>>>>>
>>>>> This idiom is safe:
>>>>>
>>>>> class SafeClass {
>>>>>     // The type of this field is java.lang.ThreadLocal, and
>>>>>     // both the key (ThreadLocal) and the value (StringBuilder) are JDK classes.    // This idiom is safe and will not cause memory leaks in web apps.
>>>>>     static ThreadLocal<StringBuilder> safe = new ThreadLocal<StringBuilder>();
>>>>>
>>>>>     private StringBuilder getThreadLocalStringBuilder() {
>>>>>         StringBuilder value = safe.get();
>>>>>         if (value == null) {
>>>>>             value = new StringBuilder(1024);
>>>>>             safe.set(value);
>>>>>         }
>>>>>         return value;
>>>>>     }
>>>>> }
>>>>>
>>>>> However, as soon as we create an anonymous subclass like below we
>>>>> cause memory leaks again:
>>>>>
>>>>> class MemoryLeakingClass {
>>>>>     // The type of this field is MemoryLeakingClass$1, an anonymous subclass of java.lang.ThreadLocal!
>>>>>     // In a web app, the classloader of this class is the web app class loader: may cause memory leak...
>>>>>     static ThreadLocal<StringBuilder> anonymousSubclass = new ThreadLocal<StringBuilder>() {
>>>>>
>>>>>         @Override
>>>>>         protected StringBuilder initialValue() {
>>>>>             return new StringBuilder(1024);
>>>>>         }
>>>>>     };
>>>>> }
>>>>>
>>>>>
>>>>>
>>>>> On Wed, Mar 9, 2016 at 11:32 AM, Ralph Goers <
>>>>> ralph.goers@dslextreme.com> wrote:
>>>>>
>>>>>> I still am unclear as to why you are thinking GC-free mode won’t work
>>>>>> in web apps.  What is the issue with ThreadLocals that causes the problem?
>>>>>> We are using ThreadLocals for other things that seem to be working.
>>>>>>
>>>>>> Ralph
>>>>>>
>>>>>> On Mar 8, 2016, at 3:05 PM, Remko Popma <remko.popma@gmail.com>
>>>>>> wrote:
>>>>>>
>>>>>> Some of the recent changes were to fix issues introduced by the
>>>>>> reusable message idea. It is good that we are not rushing this release, and
>>>>>> thanks everyone for your patience.
>>>>>>
>>>>>> I originally wanted to make GC-free mode the default to begin with,
>>>>>> but it may be smart to initially require that users switch GC-free mode on
>>>>>> explicitly, and only make it the default after it has gained a track
>>>>>> record. (Even so, it would only be switched on automatically for non-web
>>>>>> apps.)
>>>>>>
>>>>>> The async logger performance investigation is still ongoing. I hope
>>>>>> to be able to resolve it and do the GC-free write-up including performance
>>>>>> test results in the next few weeks. I am currently on a business trip,
>>>>>> working with people creating low latency trading systems, and they have
>>>>>> good ideas on how to investigate the performance regression, so that is
>>>>>> helpful.
>>>>>>
>>>>>> On Wed, Mar 9, 2016 at 4:01 AM, Gary Gregory <garydgregory@gmail.com>
>>>>>> wrote:
>>>>>>
>>>>>>> I'm even more concerned now that more of the no-GC changes are
>>>>>>> coming in, still, fast and furious.
>>>>>>>
>>>>>>> I see what smells like a lot of non-OO code fly by here and there:
>>>>>>> lots if-else-if-else-if-else, as opposed to subclassing or delegation if
>>>>>>> appropriate.
>>>>>>>
>>>>>>> Are we rushing toward this no-GC goal without considering speed
>>>>>>> performance?
>>>>>>>
>>>>>>> Where are we on the async logger slow down investigation?
>>>>>>>
>>>>>>> Concerned and glad to see to much activity all at the same time,
>>>>>>> Gary
>>>>>>>
>>>>>>> On Thu, Mar 3, 2016 at 1:23 PM, Matt Sicker <boards@gmail.com>
>>>>>>> wrote:
>>>>>>>
>>>>>>>> Remko (and anyone else who wants to try and solve this regression):
>>>>>>>>
>>>>>>>> https://www.jclarity.com/product/censum-free-trial/
>>>>>>>>
>>>>>>>> Go ahead and get the trial and the guys at JClarity will give us
>>>>>>>> licenses. I'd use your apache.org email to be safe.
>>>>>>>>
>>>>>>>> On 3 March 2016 at 11:27, Matt Sicker <boards@gmail.com> wrote:
>>>>>>>>
>>>>>>>>> So far, Remko's proposal is language-neutral since he defined
>>>>>>>>> endianness (big endian like java, but we could use either since ByteBuffer
>>>>>>>>> supports both) and field widths..
>>>>>>>>>
>>>>>>>>> On 3 March 2016 at 03:15, Mikael Ståldal <
>>>>>>>>> mikael.staldal@magine.com> wrote:
>>>>>>>>>
>>>>>>>>>> If we are to design a new binary log event format, then I think
>>>>>>>>>> that we should make sure that it is not Java / JVM specific, and that it
>>>>>>>>>> will be reasonably easy to implement reading and writing of it on other
>>>>>>>>>> platforms.
>>>>>>>>>>
>>>>>>>>>> On Thu, Mar 3, 2016 at 5:14 AM, Remko Popma <
>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>
>>>>>>>>>>> I created https://issues.apache.org/jira/browse/LOG4J2-1305 as
>>>>>>>>>>> a write up of my current thinking on the topic and a place to discuss
>>>>>>>>>>> ideas. Still need to add some things we discussed here (tools,
>>>>>>>>>>> endianness, versioning etc).
>>>>>>>>>>>
>>>>>>>>>>> It's a fascinating topic but I still have a lot of work to do on
>>>>>>>>>>> the GC-free epic before I can start working on this one.
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> On Thursday, 3 March 2016, Remko Popma <remko.popma@gmail.com>
>>>>>>>>>>> wrote:
>>>>>>>>>>>
>>>>>>>>>>>> Not Java Serialization, I was thinking simple
>>>>>>>>>>>> ByteBuffer.putLong, putInt, putBytes. This is much more performant (
>>>>>>>>>>>> http://mechanical-sympathy.blogspot.jp/2012/07/native-cc-like-performance-for-java.html).
>>>>>>>>>>>> SBE (Simple Binary Encoding) seems overkill, but open to other opinions.
>>>>>>>>>>>>
>>>>>>>>>>>> The less conditional logic in there the better, so I'm not that
>>>>>>>>>>>> interested in configurability. All log event fields,
>>>>>>>>>>>> ok. ThreadContextMap/Stack keys and values: similarly to other repeating
>>>>>>>>>>>> strings like logger names: write to separate mapping file & only write int
>>>>>>>>>>>> values (for count as well as key/value indices) to the "main" log file.
>>>>>>>>>>>>
>>>>>>>>>>>> Two things we would need to decide is how to handle versioning,
>>>>>>>>>>>> and what Endianness to use.
>>>>>>>>>>>>
>>>>>>>>>>>> Version information (possibly with schema info) could be
>>>>>>>>>>>> written to the log file header.
>>>>>>>>>>>>
>>>>>>>>>>>> Endianness could also be written to the header, or we could
>>>>>>>>>>>> simply say we use network byte order (big endian). Intel chips use little
>>>>>>>>>>>> endian, but apparently swapping is implemented with an intrinsic and is
>>>>>>>>>>>> very fast.
>>>>>>>>>>>>
>>>>>>>>>>>> On Thursday, 3 March 2016, Matt Sicker <boards@gmail.com>
>>>>>>>>>>>> wrote:
>>>>>>>>>>>>
>>>>>>>>>>>>> At that point, it would be nice if it were extensible. There
>>>>>>>>>>>>> are some neat binary formats we could use that would allow for that.
>>>>>>>>>>>>>
>>>>>>>>>>>>> On 2 March 2016 at 12:09, Gary Gregory <garydgregory@gmail.com
>>>>>>>>>>>>> > wrote:
>>>>>>>>>>>>>
>>>>>>>>>>>>>> I think we'd need to provide all LogEvent fields.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Gary
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> On Wed, Mar 2, 2016 at 9:13 AM, Remko Popma <
>>>>>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> That's what I meant, I didn't make myself clear. For
>>>>>>>>>>>>>>> example, we could offer a simple binary layout:
>>>>>>>>>>>>>>> time stamp (8 bytes)
>>>>>>>>>>>>>>> level int (4 bytes)
>>>>>>>>>>>>>>> thread ID (4 bytes) - Thread names in separate file
>>>>>>>>>>>>>>> Logger ID (4 bytes) - Logger names in separate file.
>>>>>>>>>>>>>>> message length (4 bytes)
>>>>>>>>>>>>>>> message type (2 bytes)
>>>>>>>>>>>>>>> message data (variable length)
>>>>>>>>>>>>>>> throwable length (4 bytes)
>>>>>>>>>>>>>>> throwable data (variable length)
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> It's a very different approach to logging. On the plus side,
>>>>>>>>>>>>>>> this would be extremely compact and very fast to write.
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> On the other hand it would require a separate tool to
>>>>>>>>>>>>>>> decode/display the data in human readable form. Such a tool should handle
>>>>>>>>>>>>>>> text messages out of the box, but for custom messages I image there could
>>>>>>>>>>>>>>> be some plugin mechanism for custom decoders.
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> All very interesting...
>>>>>>>>>>>>>>> :-)
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> Sent from my iPhone
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> On 2016/03/03, at 0:01, Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>> wrote:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> That's what I thought at first, but he means non-human
>>>>>>>>>>>>>>> readable formats since we all use tools to parse logs as it is (Splunk and
>>>>>>>>>>>>>>> ELK are the big two I know of).
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> On 2 March 2016 at 02:15, Remko Popma <remko.popma@gmail.com
>>>>>>>>>>>>>>> > wrote:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Re: binary logging, I think he's talking about providing an
>>>>>>>>>>>>>>>> API to log objects directly into byte buffers without turning them into
>>>>>>>>>>>>>>>> Strings first.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> https://issues.apache.org/jira/browse/LOG4J2-1274 and
>>>>>>>>>>>>>>>> https://issues.apache.org/jira/browse/LOG4J2-506
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> were created with that in mind and should be a good step in
>>>>>>>>>>>>>>>> that direction.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Sent from my iPhone
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> On 2016/03/02, at 15:11, Gary Gregory <
>>>>>>>>>>>>>>>> garydgregory@gmail.com> wrote:
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Well, I've often wondered about creating a binary format
>>>>>>>>>>>>>>>> but it seems that you could use JSON+ZIP or BSON and get most of the
>>>>>>>>>>>>>>>> advantages.
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> Gary
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> On Tue, Mar 1, 2016 at 9:12 PM, Matt Sicker <
>>>>>>>>>>>>>>>> boards@gmail.com> wrote:
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> One other interesting thing I learned is that improper use
>>>>>>>>>>>>>>>>> of logging is a huge source of performance problems. The GC-free
>>>>>>>>>>>>>>>>> parameterized message factory will help with one aspect of that (I
>>>>>>>>>>>>>>>>> suggested parameterized messages, but he countered with the Object[] that
>>>>>>>>>>>>>>>>> is created), and encouraging users to use a Supplier<String> instead of
>>>>>>>>>>>>>>>>> passing parameters should help as well (especially when those parameters
>>>>>>>>>>>>>>>>> have to be computed). He had some strong criticisms of logging APIs
>>>>>>>>>>>>>>>>> promoting bad practices which stems all the way back to log4j1 and affects
>>>>>>>>>>>>>>>>> pretty much every logging API in Java (some criticisms were actually
>>>>>>>>>>>>>>>>> outdated or didn't consider newer features of the API like markers and the
>>>>>>>>>>>>>>>>> huge amount of filters available).
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> His other big idea was promoting the use of binary logging
>>>>>>>>>>>>>>>>> formats because humans rarely read the raw log files as it is, but it's not
>>>>>>>>>>>>>>>>> like there's a standard way to do that.
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> Now I kinda wonder if he'll find this thread one day and
>>>>>>>>>>>>>>>>> tell me how I misinterpreted him or something. ;)
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> On 1 March 2016 at 22:28, Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>> wrote:
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>> Alright, I learned some interesting things. I'm going to
>>>>>>>>>>>>>>>>>> get us some tools we can use to try and profile this. Otherwise, he did
>>>>>>>>>>>>>>>>>> suggest trying out this project:
>>>>>>>>>>>>>>>>>> https://github.com/RichardWarburton/honest-profiler
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>> On 1 March 2016 at 19:31, Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>> wrote:
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> So far he's said something about using lambdas for lazy
>>>>>>>>>>>>>>>>>>> evaluation (though I don't think that would actually help us at all). I'll
>>>>>>>>>>>>>>>>>>> try to talk to him one-on-one afterward to delve more into this.
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> On 1 March 2016 at 18:13, Ralph Goers <
>>>>>>>>>>>>>>>>>>> ralph.goers@dslextreme.com> wrote:
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> Actually, most of the tests have the commands in the
>>>>>>>>>>>>>>>>>>>> comments right in the class. Just cut and past.
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> Ralph
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> On Mar 1, 2016, at 1:43 PM, Matt Sicker <
>>>>>>>>>>>>>>>>>>>> boards@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> I can't even figure out how to execute the simple perf
>>>>>>>>>>>>>>>>>>>> test class. IntelliJ gives me some annotation processing error, and doing
>>>>>>>>>>>>>>>>>>>> it from the command line is turning into a classpath nightmare to figure
>>>>>>>>>>>>>>>>>>>> out what jars are needed to execute the test manually.
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> On 1 March 2016 at 11:34, Gary Gregory <
>>>>>>>>>>>>>>>>>>>> garydgregory@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>> Before the talk: Hi, I'm Remko, I help on Apache
>>>>>>>>>>>>>>>>>>>>> Log4j, are you available after the preso to talk about some issue we are
>>>>>>>>>>>>>>>>>>>>> seeing?
>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>> Gary
>>>>>>>>>>>>>>>>>>>>> On Mar 1, 2016 8:29 AM, "Matt Sicker" <
>>>>>>>>>>>>>>>>>>>>> boards@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>> I'm attending a JUG meetup tonight with Kirk
>>>>>>>>>>>>>>>>>>>>>> Pepperdine presenting. It's supposed to be a Java performance workshop type
>>>>>>>>>>>>>>>>>>>>>> of thing, so if you've got a decent way to ask about it, I could see if he
>>>>>>>>>>>>>>>>>>>>>> can help figure out this regression. I can at least show off the
>>>>>>>>>>>>>>>>>>>>>> SimplePerfTest and any microbenchmarks we have.
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>> On 28 February 2016 at 11:54, Matt Sicker <
>>>>>>>>>>>>>>>>>>>>>> boards@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>> Take a look at the git bisect command. Might help
>>>>>>>>>>>>>>>>>>>>>>> you find which changes caused the problem.
>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>> On Sunday, 28 February 2016, Gary Gregory <
>>>>>>>>>>>>>>>>>>>>>>> garydgregory@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>> Thank you for digging in Remko. This is will be a
>>>>>>>>>>>>>>>>>>>>>>>> nice theme to publicize when you get it figured out.
>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>> Gary
>>>>>>>>>>>>>>>>>>>>>>>> On Feb 28, 2016 4:08 AM, "Remko Popma" <
>>>>>>>>>>>>>>>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>> After removing the potential impact of appenders
>>>>>>>>>>>>>>>>>>>>>>>>> and layouts by testing with
>>>>>>>>>>>>>>>>>>>>>>>>> log4j-core\src\test\resources\perf-CountingNoOpAppender.xml and
>>>>>>>>>>>>>>>>>>>>>>>>> org.apache.logging.log4j.core.async.perftest.SimplePerfTest, I've confirmed
>>>>>>>>>>>>>>>>>>>>>>>>> my initial numbers:
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>> 2.0: 7.5M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.1: 6M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.2: 6M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.3: 6M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.4: 4.5M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.5: 4M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>> 2.6: 2M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>> I tried reverting various changes made to
>>>>>>>>>>>>>>>>>>>>>>>>> AsyncLogger since 2.0, performance improves a little up to 4M ops/sec.
>>>>>>>>>>>>>>>>>>>>>>>>> However, when completely reverting AsyncLogger
>>>>>>>>>>>>>>>>>>>>>>>>> source to the 2.0 version, performance is back to 7.5M ops/sec.
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>> I'll try starting from the 2.0 source and getting
>>>>>>>>>>>>>>>>>>>>>>>>> back to 2.6 functionality without losing performance...
>>>>>>>>>>>>>>>>>>>>>>>>> (Lengthy process...)
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>> On Sat, Feb 27, 2016 at 12:18 PM, Remko Popma <
>>>>>>>>>>>>>>>>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> This is the PerfTestDriver test class (in
>>>>>>>>>>>>>>>>>>>>>>>>>> log4j-core/test, package ...async.perf).
>>>>>>>>>>>>>>>>>>>>>>>>>> Mainly perf3PlainNoLocation.xml:
>>>>>>>>>>>>>>>>>>>>>>>>>> RollingRandomAccessFileAppender, PatternLayout,
>>>>>>>>>>>>>>>>>>>>>>>>>> all loggers are AsyncLoggers, logging a simple string without parameters.
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> Profiling with YourKit did not tell me anything
>>>>>>>>>>>>>>>>>>>>>>>>>> useful.
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> I'm now eliminating the effect of
>>>>>>>>>>>>>>>>>>>>>>>>>> Layouts/Appenders, using CountingNoOpAppender, and seeing similar numbers.
>>>>>>>>>>>>>>>>>>>>>>>>>> So this seems to be mostly an issue in AsyncLogger.
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> I'll let you know when I find out more.
>>>>>>>>>>>>>>>>>>>>>>>>>> There's a lot of trial and error here, so this
>>>>>>>>>>>>>>>>>>>>>>>>>> may take a while...
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> Remko
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> Sent from my iPhone
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> On 2016/02/26, at 21:02, Mikael Ståldal <
>>>>>>>>>>>>>>>>>>>>>>>>>> mikael.staldal@magine.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> Which components (appenders, layouts) are
>>>>>>>>>>>>>>>>>>>>>>>>>> involved in the tests? Would it be possible to do some profiling to see if
>>>>>>>>>>>>>>>>>>>>>>>>>> there is any particular component which is to blame?
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> On Fri, Feb 26, 2016 at 12:51 PM, Remko Popma <
>>>>>>>>>>>>>>>>>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>> To give you some rough impression on concrete
>>>>>>>>>>>>>>>>>>>>>>>>>>> numbers for this trend:
>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.0: ~6M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.1-2.2: ~5M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.3-2.4: ~3-4M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.5: ~3M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.6: ~2M ops/sec
>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>> On Friday, 26 February 2016, Remko Popma <
>>>>>>>>>>>>>>>>>>>>>>>>>>> remko.popma@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> You're absolutely right. I still have quite a
>>>>>>>>>>>>>>>>>>>>>>>>>>>> few unit tests to add.
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Initial perf testing shows a downward trend in
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Async Logger performance with every release. (Logging simple
>>>>>>>>>>>>>>>>>>>>>>>>>>>> string messages without params.) This is worrisome and I'm focusing on
>>>>>>>>>>>>>>>>>>>>>>>>>>>> figuring that out first: this will likely involve additional code changes
>>>>>>>>>>>>>>>>>>>>>>>>>>>> and I'll add more tests after that.
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Sent from my iPhone
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> On 2016/02/26, at 10:38, Gary Gregory <
>>>>>>>>>>>>>>>>>>>>>>>>>>>> garydgregory@gmail.com> wrote:
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Wow, I love the activity we are seeing toward
>>>>>>>>>>>>>>>>>>>>>>>>>>>> 2.6! All the perf work on top of an existing sizable change set. Very
>>>>>>>>>>>>>>>>>>>>>>>>>>>> exciting indeed.
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> There sure are a lot of changes coming in. I
>>>>>>>>>>>>>>>>>>>>>>>>>>>> hope that we all can pitch in to make sure most if not all of these changes
>>>>>>>>>>>>>>>>>>>>>>>>>>>> get code coverage from unit tests. I've not checked closely, but it seems
>>>>>>>>>>>>>>>>>>>>>>>>>>>> like we may not have good coverage _yet_, or do I have the wrong impression?
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> I want to make sure we keep our stability in
>>>>>>>>>>>>>>>>>>>>>>>>>>>> tip top shape :-) and that we have no regression from previous releases.
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Gary
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>>>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>>>>>>>>>>>>>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> JUnit in Action, Second Edition
>>>>>>>>>>>>>>>>>>>>>>>>>>>> <http://www.manning.com/tahchiev/>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Spring Batch in Action
>>>>>>>>>>>>>>>>>>>>>>>>>>>> <http://www.manning.com/templier/>
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>>>>>>>>>>>>>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>>>>>>>>> [image: MagineTV]
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> *Mikael Ståldal*
>>>>>>>>>>>>>>>>>>>>>>>>>> Senior software developer
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> *Magine TV*
>>>>>>>>>>>>>>>>>>>>>>>>>> mikael.staldal@magine.com
>>>>>>>>>>>>>>>>>>>>>>>>>> Grev Turegatan 3  | 114 46 Stockholm, Sweden  |
>>>>>>>>>>>>>>>>>>>>>>>>>> www.magine.com
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>> Privileged and/or Confidential Information may be
>>>>>>>>>>>>>>>>>>>>>>>>>> contained in this message. If you are not the addressee indicated in this
>>>>>>>>>>>>>>>>>>>>>>>>>> message
>>>>>>>>>>>>>>>>>>>>>>>>>> (or responsible for delivery of the message to
>>>>>>>>>>>>>>>>>>>>>>>>>> such a person), you may not copy or deliver this message to anyone. In such
>>>>>>>>>>>>>>>>>>>>>>>>>> case,
>>>>>>>>>>>>>>>>>>>>>>>>>> you should destroy this message and kindly notify
>>>>>>>>>>>>>>>>>>>>>>>>>> the sender by reply email.
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>>>>>>>>> JUnit in Action, Second Edition
>>>>>>>>>>>>>>>> <http://www.manning.com/tahchiev/>
>>>>>>>>>>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>>>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> --
>>>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> --
>>>>>>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>>>>>>> JUnit in Action, Second Edition
>>>>>>>>>>>>>> <http://www.manning.com/tahchiev/>
>>>>>>>>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> --
>>>>>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> --
>>>>>>>>>> [image: MagineTV]
>>>>>>>>>>
>>>>>>>>>> *Mikael Ståldal*
>>>>>>>>>> Senior software developer
>>>>>>>>>>
>>>>>>>>>> *Magine TV*
>>>>>>>>>> mikael.staldal@magine.com
>>>>>>>>>> Grev Turegatan 3  | 114 46 Stockholm, Sweden  |   www.magine.com
>>>>>>>>>>
>>>>>>>>>> Privileged and/or Confidential Information may be contained in
>>>>>>>>>> this message. If you are not the addressee indicated in this message
>>>>>>>>>> (or responsible for delivery of the message to such a person),
>>>>>>>>>> you may not copy or deliver this message to anyone. In such case,
>>>>>>>>>> you should destroy this message and kindly notify the sender by
>>>>>>>>>> reply email.
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> --
>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> --
>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>> Home: http://garygregory.com/
>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>>
>>>> --
>>>> Matt Sicker <boards@gmail.com>
>>>>
>>>
>>>
>>
>>
>

Mime
View raw message