Thanks. Will take another look. On Monday, 21 March 2016, Gary Gregory <[email protected]> wrote:
> FYI: Yourkit has three profiling modes: sampling, counting and tracing. > On Mar 20, 2016 11:47 PM, "Remko Popma" <[email protected] > <javascript:_e(%7B%7D,'cvml','[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] >> <javascript:_e(%7B%7D,'cvml','[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] >>> <javascript:_e(%7B%7D,'cvml','[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] >>> <javascript:_e(%7B%7D,'cvml','[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] >>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>>>>>>> <javascript:_e(%7B%7D,'cvml','[email protected]');>> >>>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> -- >>>>>>>>> Matt Sicker <[email protected] >>>>>>>>> <javascript:_e(%7B%7D,'cvml','[email protected]');>> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> E-Mail: [email protected] >>>>>>>> <javascript:_e(%7B%7D,'cvml','[email protected]');> | >>>>>>>> [email protected] >>>>>>>> <javascript:_e(%7B%7D,'cvml','[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] >>>>> <javascript:_e(%7B%7D,'cvml','[email protected]');>> >>>>> >>>> >>>> >>> >>> >>
