logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Robin Coe <rcoe.java...@gmail.com>
Subject Re: Fast and Furious
Date Wed, 02 Mar 2016 19:58:11 GMT
I recently started work on a listener interface to log4j2, intended to
provide off-stack apps with the features of log4j2.  I intended it to be a
streaming processor that could pipe messages upstream to log4j2 routes.
One of the intended behaviours was to be a pre-processor.  Effectively,
it's like logstash/fluentd but with log4j2 features, like failover (and
recovery).  It's pretty early in its implementation but might serve the
purpose you're discussing.  I am hopingto get my company interested in open
sourcing it.  Would there be interest?

On Wed, Mar 2, 2016 at 1:15 PM, 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>
>

Mime
View raw message