FYI: Yourkit has three profiling modes: sampling, counting and tracing. On Mar 20, 2016 11:47 PM, "Remko Popma" <[email protected]> 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 <[email protected]> > 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 <[email protected]> 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 <[email protected]> >> wrote: >> >>> I think you're right, that one should not leak. >>> >>> On Thu, Mar 10, 2016 at 2:40 AM, Matt Sicker <[email protected]> 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 <[email protected]> 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 < >>>>> [email protected]> 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 <[email protected]> >>>>>> 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 <[email protected]> >>>>>> 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 <[email protected]> >>>>>>> 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 <[email protected]> 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 < >>>>>>>>> [email protected]> 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 < >>>>>>>>>> [email protected]> 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 <[email protected]> >>>>>>>>>>> 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 <[email protected]> >>>>>>>>>>>> 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 <[email protected] >>>>>>>>>>>>> > wrote: >>>>>>>>>>>>> >>>>>>>>>>>>>> I think we'd need to provide all LogEvent fields. >>>>>>>>>>>>>> >>>>>>>>>>>>>> Gary >>>>>>>>>>>>>> >>>>>>>>>>>>>> On Wed, Mar 2, 2016 at 9:13 AM, Remko Popma < >>>>>>>>>>>>>> [email protected]> 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 <[email protected]> >>>>>>>>>>>>>>> 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 <[email protected] >>>>>>>>>>>>>>> > 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 < >>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>> [email protected]> 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 <[email protected]> >>>>>>>>>>>>>>>>> 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 <[email protected]> >>>>>>>>>>>>>>>>>> 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 < >>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>> [email protected]> 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" < >>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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" < >>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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 < >>>>>>>>>>>>>>>>>>>>>>>>>>>> [email protected]> 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: [email protected] | >>>>>>>>>>>>>>>>>>>>>>>>>>>> [email protected] >>>>>>>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>>>>>>>> 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* >>>>>>>>>>>>>>>>>>>>>>>>>> [email protected] >>>>>>>>>>>>>>>>>>>>>>>>>> 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 <[email protected]> >>>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>>>>>>>> Matt Sicker <[email protected]> >>>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>>>>>> Matt Sicker <[email protected]> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>>>>> Matt Sicker <[email protected]> >>>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>>>> Matt Sicker <[email protected]> >>>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>>> Matt Sicker <[email protected]> >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> -- >>>>>>>>>>>>>>>> E-Mail: [email protected] | [email protected] >>>>>>>>>>>>>>>> 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 <[email protected]> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> -- >>>>>>>>>>>>>> E-Mail: [email protected] | [email protected] >>>>>>>>>>>>>> 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 <[email protected]> >>>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> -- >>>>>>>>>> [image: MagineTV] >>>>>>>>>> >>>>>>>>>> *Mikael Ståldal* >>>>>>>>>> Senior software developer >>>>>>>>>> >>>>>>>>>> *Magine TV* >>>>>>>>>> [email protected] >>>>>>>>>> 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 <[email protected]> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> Matt Sicker <[email protected]> >>>>>>>> >>>>>>> >>>>>>> >>>>>>> >>>>>>> -- >>>>>>> E-Mail: [email protected] | [email protected] >>>>>>> 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 <[email protected]> >>>> >>> >>> >> >> >
