The only bug-vector I see in the current predicate approach is that
when used incorrectly it cause the size of methods to explode. There
are some hard-coded thresholds for the method size in bytecodes that
turn off some or all JIT optimizations; there are also a whole host of
compilation parameters which are optimized with smaller methods in
mind.
Unless someone can offer a great syntactic improvement I recommend
against home-brew frameworks. Aspects may be able to clean things up
nicely though, I'd be very curious to see some examples.
On Fri, Mar 23, 2012 at 9:56 PM, Zlatin Balevsky <zlat...@gmail.com> wrote:
> Not really. Here, I'll change my call to allocate everything on one level:
>
> while (true) {
> log(" list size is {1} ",
> new Integer(listToLog.size()));
> }
>
> I don't see how using this you can log primitive values without garbage.
>
> On Fri, Mar 23, 2012 at 9:33 PM, Ximin Luo <infini...@gmx.com> wrote:
>> That is because in your example you're allocating all those new Object()s in
>> the same stack frame, so the allocator runs out of space on the stack.
>>
>> If you put the call to log(x, new Object()) inside its only function call,
>> each
>> Object will be destroyed once that call exits, and no GC occurs.
>>
>> Example code here:
>> https://gist.github.com/2177070
>>
>> The "real use case" just adds one simple operation with each logging call
>> (since you're never logging without doing something else as well) to show how
>> little of a difference it makes in real terms (<5%).
>>
>> X
>>
>> On 24/03/12 01:15, Zlatin Balevsky wrote:
>>> You're right, the example you gave will put the arguments on the
>>> stack. I wanted to clarify Escape Analysis in its current form works
>>> only if a new object doesn't exit the stack frame where it's created.
>>> Because of that, the moment you do something slightly more complicated
>>> you will create garbage like this:
>>>
>>> private static void logListSize ( final List<?> listToLog ) {
>>> LOG.log(" list size is {1} ",
>>> new Object() {
>>> public String toString() {
>>> return String.valueOf(listToLog.size());
>>> }
>>> });
>>> }
>>>
>>> Here is the tricky part - if you can guarantee that everywhere in the
>>> jvm the LOG.log method is disabled by the logging system, then the
>>> entire call will compile to noop and no objects will be created.
>>> However, if even one call site enables logging you will end up
>>> creating the temp objects even if they don't get logged. Below is a
>>> full example, compile and run passing "-verbosegc -XX:+PrintGC" and
>>> watch it GC all the time.
>>>
>>> ===== LazyEvalTest.java ===
>>> import java.util.*;
>>>
>>> public class LazyEvalTest {
>>>
>>> // only if this is is always false does logging produce no garbage.
>>> private static boolean shouldLog = true;
>>>
>>> private static void log(String ar1, Object ar2) {
>>> if (shouldLog)
>>> System.out.println(ar1 + ar2.toString());
>>> shouldLog = false;
>>> }
>>>
>>> public static void main(String []ar) {
>>>
>>> final List<Object> listToLog = new ArrayList<Object>(1000);;
>>>
>>> while (true) {
>>> log(" list size is {1} ",
>>> new Object() {
>>> public String toString() {
>>> return String.valueOf(listToLog.size());
>>> }
>>> });
>>> }
>>> }
>>> }
>>> ======
>>>
>>> As far as garbage collection times go, they are a function of the
>>> count of live objects and on how easy it is to scan them in parallel
>>> and a whole bunch of other factors. Others can answer better what
>>> values are common for Fred.
>>>
>>> Zlatin
>>>
>>> On Thu, Mar 22, 2012 at 11:47 PM, Ximin Luo <infini...@gmx.com> wrote:
>>>> LOL, are you kidding me?
>>>>
>>>> Please point to the exact lines of code that results in "double-digit
>>>> millisecond pauses"?
>>>>
>>>> Talk is cheap, show us some numbers.
>>>>
>>>> BTW, the "example" I gave is not real code, and contains no variable
>>>> declarations, so your challenge makes no sense. Since you apparently didn't
>>>> understand my implicit argument, here it is in more detail: a typical
>>>> method
>>>> that computes something simply for the purpose of logging it somewhere,
>>>> usually
>>>> only allocates local variables that are not stored anywhere in the long
>>>> term.
>>>> Escape analysis can turn these into stack allocations, saving GC overhead.
>>>> (If
>>>> they do use more long-term variables, they will need to be stored on the
>>>> heap,
>>>> but then GC doesn't need to clean these up anyway.)
>>>>
>>>> Why are you even looking at blog entries? Escape analysis has been around
>>>> for
>>>> years. http://hg.openjdk.java.net/jdk6/jdk6/hotspot/rev/357d4e2eb4dd
>>>>
>>>> On 23/03/12 02:06, Zlatin Balevsky wrote:
>>>>> My claim is based on day-to-day observations of hundreds of JVMs under
>>>>> various
>>>>> load scenarios.
>>>>>
>>>>> Your claim that modern JVMs "do escape analysis" is worthless as it shows
>>>>> that
>>>>> you have merely read some blog posts, and even those you've read only
>>>>> partially. Please point to the exact lines of code in hotspot or any
>>>>> other
>>>>> modern jvm that will optimize the specific lazy evaluation example you
>>>>> presented, together with the opto-assembly that their JITs produce.
>>>>> Failing
>>>>> that, take your attitude elsewhere.
>>>>>
>>>>> On Thu, Mar 22, 2012 at 8:49 PM, Ximin Luo <infini...@gmx.com
>>>>> <mailto:infini...@gmx.com>> wrote:
>>>>>
>>>>> The "drastically cleaner syntax" is a red herring. Most of the time
>>>>> when you
>>>>> are doing a complex calculation, you are not going to put it on one
>>>>> line
>>>>> anyway. In such cases, the function you are using to do the
>>>>> calculation might
>>>>> as well be the toString() method of some object.
>>>>>
>>>>> Your claim of "double-digit millisecond" pauses is worthless without
>>>>> some
>>>>> benchmarking and actual numbers. Modern JVMs do escape analysis to
>>>>> avoid heap
>>>>> allocation and this helps especially for transient computations like
>>>>> in
>>>>> logging.
>>>>>
>>>>> On 22/03/12 21:59, Zlatin Balevsky wrote:
>>>>> > Double-digit millisecond pauses are not nothing. They may be
>>>>> acceptable
>>>>> right
>>>>> > now but unless you can offer a drastically cleaner syntax Fred
>>>>> should stick
>>>>> > with predicates as they are handled much better by the hotspot jit.
>>>>> >
>>>>> > On Mar 22, 2012 5:36 PM, "Ximin Luo" <infini...@gmx.com
>>>>> <mailto:infini...@gmx.com>
>>>>> > <mailto:infini...@gmx.com <mailto:infini...@gmx.com>>> wrote:
>>>>> >
>>>>> > Lazy evaluation is trivial.
>>>>> >
>>>>> > Log.info("{1} did {2}",
>>>>> > new Object(){ public String toString() { return ITEM_1; } },
>>>>> > new Object(){ public String toString() { return ITEM_2; } }
>>>>> > );
>>>>> >
>>>>> > Garbage collection with short-lived objects costs next to
>>>>> nothing.
>>>>> >
>>>>> > On 22/03/12 21:15, Zlatin Balevsky wrote:
>>>>> > > Constructing the logging strings is half of the problem. The
>>>>> amount of
>>>>> > garbage
>>>>> > > they will generate will result in significantly more time in
>>>>> garbage
>>>>> > collection
>>>>> > > pauses.
>>>>> > >
>>>>> > > Unless you figure out a way to mimic lazy evaluation you have
>>>>> to live
>>>>> > with the
>>>>> > > isLoggable predicates. varargs are not an option either
>>>>> because
>>>>> they also
>>>>> > > create garbage.
>>>>> > >
>>>>> > > On Mar 22, 2012 8:11 AM, "Marco Schulze"
>>>>> <marco.c.schu...@gmail.com
>>>>> <mailto:marco.c.schu...@gmail.com>
>>>>> > <mailto:marco.c.schu...@gmail.com
>>>>> <mailto:marco.c.schu...@gmail.com>>
>>>>> > > <mailto:marco.c.schu...@gmail.com
>>>>> <mailto:marco.c.schu...@gmail.com> <mailto:marco.c.schu...@gmail.com
>>>>> <mailto:marco.c.schu...@gmail.com>>>> wrote:
>>>>> > >
>>>>> > >
>>>>> > >
>>>>> > > On 22-03-2012 08:50, Matthew Toseland wrote:
>>>>> > >
>>>>> > > On Wednesday 21 Mar 2012 21:18:37 Marco Schulze wrote:
>>>>> > >
>>>>> > > There are basically two big concerns regarding
>>>>> logging
>>>>> in fred:
>>>>> > >
>>>>> > > - Readability and code clutter, which was my
>>>>> original
>>>>> > questioning;
>>>>> > > - Raw throughput, as raised by toad.
>>>>> > >
>>>>> > > Point 1 could mostly be solved by removing any
>>>>> traces of
>>>>> > logMINOR and
>>>>> > > logDEBUG on all but the few places where
>>>>> generating
>>>>> messages
>>>>> > to be
>>>>> > > logged brings noticeable slowdown. That'd be
>>>>> enough, but,
>>>>> > personally,
>>>>> > > the mess that the logging backend is does warrant
>>>>> a
>>>>> replacement.
>>>>> > > According to toad, the current system needs
>>>>> log{MINOR,DEBUG} to
>>>>> > > function
>>>>> > > in a timely manner. Based on this, I think we all
>>>>> agree a
>>>>> > > replacement is
>>>>> > > desirable.
>>>>> > >
>>>>> > > Logging has a few additional requirements:
>>>>> > >
>>>>> > > - Log rotation (possibly live);
>>>>> > > - Reentrant;
>>>>> > > - Per-class filtering;
>>>>> > > - Specific information in log (class-name, for
>>>>> example).
>>>>> > >
>>>>> > > Now, _any_ library which fits would make me
>>>>> happy, as
>>>>> long as
>>>>> > they
>>>>> > > agree
>>>>> > > to two points:
>>>>> > >
>>>>> > > - Either lightweight or with optional features.
>>>>> Else, it
>>>>> > would only
>>>>> > > transfer bloat to freenet-ext.jar. For example:
>>>>> log2socket,
>>>>> > config
>>>>> > > management and multiple logging instances;
>>>>> > > - Implementable in a few LoC. Specially, it
>>>>> shouldn't need
>>>>> > specialized
>>>>> > > Formatter and Writer.
>>>>> > >
>>>>> > > Plus, it should be fast.
>>>>> > >
>>>>> > > From the quick research I made (yep, too many
>>>>> lists):
>>>>> > >
>>>>> > > - SLF4J already fails on point one: it is simply
>>>>> a wrapper;
>>>>> > > - The Java logging API fails on point two:
>>>>> specialized
>>>>> > classes would
>>>>> > > have to be written to deal with log rotation,
>>>>> per-class
>>>>> > filtering and
>>>>> > > formatting, plus a wrapper for
>>>>> Logger.{info,warning,...}()
>>>>> > methods.
>>>>> > > Exactly the same as a custom logger, with one more
>>>>> dependency
>>>>> > and using
>>>>> > > more LoC;
>>>>> > >
>>>>> > > No dependancies, it's part of the JDK, isn't it?
>>>>> > >
>>>>> > > More classes need to be loaded at startup. It's just me
>>>>> thinking too
>>>>> > much.
>>>>> > >
>>>>> > >
>>>>> > > However, if it's not a clearer/simpler API, it
>>>>> probably
>>>>> doesn't make
>>>>> > > much sense.
>>>>> > >
>>>>> > > - Log4J seems to fail on point one - it only
>>>>> lacks a button
>>>>> > that brings
>>>>> > > back the dead. It seems interesting, and I
>>>>> haven't dropped
>>>>> > this yet.
>>>>> > >
>>>>> > > In either case (custom or external), log* would be
>>>>> banished.
>>>>> > Forever.
>>>>> > >
>>>>> > > I don't follow. You object to using a separate logs
>>>>> folder?
>>>>> > >
>>>>> > > log* == log{MINOR,DEBUG}, not the logs folder.
>>>>> > > _________________________________________________
>>>>> > > Devl mailing list
>>>>> > > Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> <mailto:Devl@freenetproject.org <mailto:Devl@freenetproject.org>>
>>>>> > <mailto:Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> <mailto:Devl@freenetproject.org <mailto:Devl@freenetproject.org>>>
>>>>> > >
>>>>> https://emu.freenetproject.__org/cgi-bin/mailman/listinfo/__devl
>>>>> > >
>>>>> <https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl>
>>>>> > >
>>>>> > >
>>>>> > >
>>>>> > > _______________________________________________
>>>>> > > Devl mailing list
>>>>> > > Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> <mailto:Devl@freenetproject.org <mailto:Devl@freenetproject.org>>
>>>>> > > https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>>>> >
>>>>> >
>>>>> > --
>>>>> > GPG: 4096R/5FBBDBCE
>>>>> > https://github.com/infinity0
>>>>> > https://bitbucket.org/infinity0
>>>>> > https://launchpad.net/~infinity0
>>>>> <https://launchpad.net/%7Einfinity0>
>>>>> >
>>>>> >
>>>>> > _______________________________________________
>>>>> > Devl mailing list
>>>>> > Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> <mailto:Devl@freenetproject.org <mailto:Devl@freenetproject.org>>
>>>>> > https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>>>> >
>>>>> >
>>>>> >
>>>>> > _______________________________________________
>>>>> > Devl mailing list
>>>>> > Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> > https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>>>>
>>>>>
>>>>> --
>>>>> GPG: 4096R/5FBBDBCE
>>>>> https://github.com/infinity0
>>>>> https://bitbucket.org/infinity0
>>>>> https://launchpad.net/~infinity0 <https://launchpad.net/%7Einfinity0>
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> Devl mailing list
>>>>> Devl@freenetproject.org <mailto:Devl@freenetproject.org>
>>>>> https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> Devl mailing list
>>>>> Devl@freenetproject.org
>>>>> https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>>>
>>>>
>>>> --
>>>> GPG: 4096R/5FBBDBCE
>>>> https://github.com/infinity0
>>>> https://bitbucket.org/infinity0
>>>> https://launchpad.net/~infinity0
>>>>
>>>>
>>>> _______________________________________________
>>>> Devl mailing list
>>>> Devl@freenetproject.org
>>>> https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>> _______________________________________________
>>> Devl mailing list
>>> Devl@freenetproject.org
>>> https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
>>
>>
>> --
>> GPG: 4096R/5FBBDBCE
>> https://github.com/infinity0
>> https://bitbucket.org/infinity0
>> https://launchpad.net/~infinity0
>>
>>
>> _______________________________________________
>> Devl mailing list
>> Devl@freenetproject.org
>> https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
_______________________________________________
Devl mailing list
Devl@freenetproject.org
https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
