Another Log implementation

Jose Armando Garcia jsancio at gmail.com
Sun May 29 17:58:00 PDT 2011


Why is verbosity not useful? Or I should ask, why is verbosity as
implemented in std.log and glog not useful? Let me motivate it with a
possible use case.

Lets say that you have a "large" non-deterministic application (in
this case it means that you accept external inputs in the form of IO)
and in the QA or a really generous customer your application keeps
hitting a bug in your program. You try really hard but you are unable
to reproduce it in your environment.

You just remember that the developer that wrote the IO layer was nice
enough to log all IO inputs at verbosity level 3. He didn't log them
at info severity because of performance implications. So you tell QA
or this generous customer to turn on verbose logging for the IO
module. Also, note that the bug is not necessarily in the IO module
but information in the IO module is useful to debug the buggy module.
So QA reruns the app with the command line option --vmodule=io=3 or if
you have a really awesome application you can change this module
filter configuration while still running (you can't do this right now
with std.log but I plan to implement this). Now you are able to see
all the non-deterministic input that came to your application.

You take this log and quickly write a load generator (in D of course)
with a similar timing (time is part of the information in std.log's
log) as that in the QA log and boom you hit the bug and are able to
debug it in your favorite debugger.

-Jose

2011/5/29 Andrei Alexandrescu <SeeWebsiteForEmail at erdani.org>:
> On 05/29/2011 04:52 PM, Vincent wrote:
>>
>> Hello, Andrei! Very appreciate you spent time on my work.
>> I agree with some your critique, sure it's just a question of
>> improvements. My main question is acceptance of my log library as a
>> whole conception, since it's simple and 10 from 10 programmers can
>> understand its sources (I keep it as very serious goal).
>
> Why? 10 out of 10 would be more interested in using the library effectively
> instead of reading its source. Clearly keeping the source readable is
> desirable, but not an overriding goal. It's probably the last thing you care
> about after having taken care of everything.
>
>> Let's discuss doubtful points...
>>
>>> Verbosity is not very often used indeed but I'd guess many people got
>>> used to it because it's present in most libraries.
>>
>> Habit is not the rule. You must remember those days when every DOS
>> editor show time in menu bar. WHY? Just because everybody did it. I see
>> nothing bad to loose this 'verbosity' as archaic feature.
>> As I said before, 'special demands' is the pain of 'special programmers'
>> - if they REALLY cannot live w/o 'verbosity', they can add it in 3 LOC.
>
> You mentioned you don't care about verbosity levels. I added that I haven't
> found a lot of use for them either. Next thing you know, you're presupposing
> your own assumption. Isn't the data set a tad small to draw conclusions
> from?
>
>>> * The library doesn't take care of capturing the origin of the log
>>> (file/module/line) so the user must pass them manually.
>>
>> I've read posts related __LINE__s in log and don't see any reason in
>> this feature. Why?
>> 1. It's not direct task of 'logging'. Log doesn't care about your
>> lines/files just because you're too negligent to control what and where
>> you log - its task is just assemble together runtime info.
>> 2. Nobody prevent you from doing it! Just make 'mixin' with __FILE__ and
>> use.
>> 3. In my practice I didn't see so low-level approach for debugging -
>> well organised log shows enough, why people care about number of code
>> line in editor?? Funny, heh...
>> 4. Logging is not only "We have a problem in line 10!" - it's "trace of
>> life" for our program.
>
> Without automated headers including location of the log line and date/time,
> one can't even call that a logging library. It's an text streaming facility.
>
>>> * The library requires version(logging) to control enabling.
>>> Essentially the client would need to prefix _all_ logging lines
>>
>> Agree completely. But something says to me that it's just a my little
>> knowledge of D (and it's true). Sure there is some feature to make log
>> calls 'invisible' without 'version' prefix - I just used feature I sure
>> about. May be mixins will help? This is the place where I need help of
>> community.
>
> The help can be readily absorbed from reading the existing proposal.
>
>>> * The library always evaluates arguments, even when logging is
>>> dynamically disabled.
>>
>> First, let's remember Knuth's "Premature Optimization" warning - say
>> "it's slow" only when it's really slow down your program.
>
> Evaluating arguments always vs. not at all is a matter of principles.
>
>> Second, remember use case of this "runtime switch": "ALL logging is
>> enabled (read "everywhere it's slow"), but at this place it's disabled
>> (and who cares how slow it is?)".
>
> It is very important that the program is as fast as it can when logging is
> disabled. I don't understand how one could argue sensibly otherwise.
>
>> Third, if you use log, you NEED this info, despite how fast it was
>> calculated. And even if you jump over with 'lazy' arguments, they HAVE
>> to be calculated - you wait 'em anyway! So... what a benefit you have
>> from laziness?
>
> With lazy evaluation you can arrange that complex expressions inside the log
> calls are not evaluated.
>
>> And hell, if you're good programmer, you'll never write critical section
>> like
>> log("a");
>> log("b");
>> ...rather you accumulate log info and output it at once.
>> I agree with usefullness of 'lazy' stuff, but not in this case.
>
> Sometimes you do need to insert log expressions in relatively critical
> places for debugging purposes.
>
>>> * The library does not define a notion of a severity hierarchy
>>
>> If you look at use cases of this 'severity', there is no 'hierarchy'
>> (look at usage of my library) - it's again "habits" of 70-th. Just
>> obvious example from real life:
>> I log all 'info' messages about client actions. But somewhere I get
>> database exception - my fault, logged as 'critical'. Together with two
>> levels above I have 'warning' level about problems like 'this person has
>> no surname'. Question is: "Why I must dig in 'warning' trash, when I
>> just need info what client did and which critical problem happen?". As
>> you see, 'hierarchy' is just "flat" view on problem - there is
>> independed severities and _combination_ of 'em.
>> Again, no apocalypse happen - who need this feature, that must spent
>> time on it.
>
> Your example describes a trivial matter. Often times, the trace leading to a
> critical problem is indicative of the issue in more complicated
> applications.
>
>>> Arguably defining a hierarchy could be considered outside the scope of
>>> a "core" logging library, but that means more work for the casual user
>>> of the library to achieve a common task.
>>
>> Exactly. You cannot include in simple 'string assembler' all
>> functionality (esp. legacy point of view - time is changed!). Simple
>> requirements must lead to simple usage - if you don't use 'verbosity',
>> why you should pass parameters in every log call?
>
> Who does? Did you skim the existing proposal at all?
>
>>> I believe something close to Jose's library (after community feedback)
>>> will become the standard library for logging, so we should at best we
>>> consolidate efforts behind it.
>>
>> What if I don't believe? :) We'll spent time on functions, used by 1% of
>> 'old shoes' and give a bad example for next generations. I don't pretend
>> I wrote the best library ever, but I kept on rule 'implement only
>> necessary stuff' and I have a reason for every decision.
>> Well, I don't want to press anybody, but before you completely give up
>> my implementation I wanna be smashed with serious arguments how bad my
>> design is. :) (may be it'll be good lesson for another designs!)
>>
>> Good luck for all community!
>
> Same here, and welcome. First, this seems to be the third time you are
> referring negatively about age. That is never in good taste, and can at best
> be tolerated if it comes from a position of exceptional achievement.
>
> Second, if you're looking for definitive arguments for or against your
> design, you're unlikely to find them. Design is a subjective endeavor, so
> you can always make a counter-argument to pretty much any argument (as you
> just did).
>
> Third, I find it tenuous to agree that you "implemented only the necessary
> stuff" and that you "have a reason for every decision". If you cast a candid
> eye over your design, you'll notice that it has virtually nothing to do with
> logging aside from using the "log" word here and there. It's barely a design
> at all as it's just a barebones streaming text out glue that assembles an
> external string template engine with an ad-hoc streaming interface
> containing only the Write primitive. So unless you set out to implement
> nothing but simple streaming, you didn't implement only the necessary stuff;
> and if you have a reason for every decision, then by necessity one
> motivating reason was to stay away from anything specific to logging.
>
>
>
> Andrei
>


More information about the Digitalmars-d mailing list