Re: [freenet-dev] Logging in Fred

[Marco Schulze]

Sure. Since the class name lookups will only be used for debugging, they 
can be as generic as necessary, as long it doesn't add any requirements 
to users. Match-on-load and match-on-demand are both fine.

On 23-03-2012 13:19, Matthew Toseland wrote:
On Friday 23 Mar 2012 16:00:15 Marco Schulze wrote:
Yes, and yes.
On 23-03-2012 12:43, Matthew Toseland wrote:
On Friday 23 Mar 2012 15:29:44 you wrote:
Right now, the map is only used to list class thresholds which are
different from the global threshold, which means it is empty 99% of the
time. This is the simplest solution, but it also means that the
possibility of lock contention is way higher. However, unless this
proves to be very bad in a real run, I'll stick with it.
Sounds like you need to use a volatile.

Also your design implies that the log level details will be changed to not 
support wildcards/prefixes?
Is there any way to avoid this? Prefixes are really handy in some debugging 
situations. Possibly we could hook into the classloader and apply the wildcards 
on loading?

On 23-03-2012 10:39, Matthew Toseland wrote:
On Friday 23 Mar 2012 00:18:02 Marco Schulze wrote:
I already have all but log rotation and async ready, and haven't yet
found a single benchmark supporting the use of a branch as the
performance holy grail. For example (outputting to /dev/null):

public static void main (String[] args) {
            for (int i = 0; i<    1000000; i++) {
                    Log.fatal (Log.class, Log.class, "akd\n\n", i, '\n',
out, ' ');
                    Log.trace (Log.class, Log.class, "akd\n\n", i, '\n',
out, ' ');
            }
}

Every call means, minimally, varargs boxing, another call (since fatal()
and trace() are simple convenience methods) and an isLoggable() check
composed by a ConcurrentHashMap lookup against the class name and
(possibly) a synchronized read on the global threshold. trace() is
filtered but fatal() is not.
Don't do a synchronized read on the global threshold. Don't do synchronized 
anything. Just recompute all the classes when the thresholds change.

However, you still haven't told me how you're going to ensure all classes are 
paged in when you do set all the thresholds in the map?
This snipped ran in an average 6.482 seconds. If the call to trace() is
commented out (thus removing the filtering overhead), the average falls
to 6.366 seconds. Disabling JIT, the figures became 1:37.952 and
1:35.880, respectively. Over a million calls, checking costs only a few
milliseconds.

To be sure, this is a fairly simple example: it all runs on a single
thread, the hash table is empty and the pressure on the GC is low.
Still, differences are very small. Plus, there's no overhead due to a
dedicated logging thread.

On 22-03-2012 18: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>>    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>>>    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
https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl