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.po...@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.po...@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 <boa...@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 <garydgreg...@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.po...@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 <boa...@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.po...@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 <garydgreg...@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 <boa...@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 <boa...@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 <boa...@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.go...@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 <boa...@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 <garydgreg...@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" <boa...@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 <boa...@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 < >>>>>>>>>>>>> garydgreg...@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.po...@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.po...@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.stal...@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.po...@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.po...@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 < >>>>>>>>>>>>>>>>>> garydgreg...@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: garydgreg...@gmail.com | ggreg...@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.stal...@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 <boa...@gmail.com> >>>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> -- >>>>>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> -- >>>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> -- >>>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> -- >>>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>>> >>>>>>> >>>>>>> >>>>>>> >>>>>>> -- >>>>>>> Matt Sicker <boa...@gmail.com> >>>>>>> >>>>>> >>>>>> >>>>>> >>>>>> -- >>>>>> E-Mail: garydgreg...@gmail.com | ggreg...@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 <boa...@gmail.com> >>>>> >>>>> >>>> >>>> >>>> -- >>>> E-Mail: garydgreg...@gmail.com | ggreg...@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 <boa...@gmail.com> >>> >> -- [image: MagineTV] *Mikael Ståldal* Senior software developer *Magine TV* mikael.stal...@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.
