Feedback/Suggestions for std.log

[Gary M]

Hi Jose,

Thanks for your response! I imagine you're quite busy so I appreciate 
you spending the time to respond.


On 11-05-28 05:29 PM, Jose Armando Garcia wrote:
> Hi Gary.
>
> You should take a look at the proposed logging module for phobos at
> http://jsancio.github.com/phobos/phobos/std_log.html and
> https://github.com/jsancio/phobos/blob/master/std/log.d. Please
> comment.

I read the proposed interface and am impressed!

Comments:

* The write method signature uses the source file and line for the message:
"write(string file = __FILE__, int line = __LINE__, T...) ..."
I saw in an earlier newsgroup message you asked Walter if it was 
appropriate to include the __MODULE__ name.
I'd go further and suggest even optional inclusion of the function name!
 From our team's experience, any extra information while debugging or 
viewing logs means we troubleshoot issues that much quicker. If that 
info can be automatically included, we get a free boost in productivity!

* Love the moduleFilter thing. Hopefully I'm referring to it correctly. 
Comments below.

* I want to say this is in the C++ Coding Standards book: I think it's 
recommended to use nouns in names of classes. Perhaps it's consistent to 
use "VerbosityConfig" as opposed to "VerboseConfig"?

* Abstracting out the "LogFilter" from the Logger strikes me as a good 
design decision.

Responses to your responses:

>> - Must be scalable with respect to project size
>> -- Feature: Allow custom log destinations specified at compile or run-time,
>> and log level options specified at logger instantiation (compile time) or at
>> run-time.
> This is not actually a requirement but more of an implementation
> suggest. What are you trying to achieve? With std.log you can enable
> and disable verbose logging in a module at run time with --vmodule.
> You can also disable logging at a specific severity for the entire
> process at compile time and run time.

You must forgive my horrible attempt to organize these points. What I 
meant to convey was the high level requirements and possible features 
which achieve them as sub-bullets, and examples as sub-bullets of those.

Happily, I see std.log achieves the fine grained control of filtering 
log messages based on severity and verbosity level. Awesome.

The prior point is a suggestion for multiple log message destinations.
I see the "SharedLogger" in the current proposal sends messages to 
different files based on severity.
Do I perceive correctly that the "abstract interface Logger" can be 
extended by users of std.log? This is an excellent idea! It's also an 
effective way to manage feature requests. Can users choose to log to 
their own sub-types of loggers somehow?
This can be an effective way to allow folks to point their log messages 
at whichever different files they'd like, or to some email destination, 
all while keeping the std.log interface relatively simple.


>> -- Feature: Allow loggers to exist in a hierarchy, in which properties of
>> parent loggers are shared with children.
> Again, this is a implementation detail and not a requirement. What do
> you plan to do with a hierarchy? Look at vlog, it is much more
> flexible than a tree of loggers.

I believe the "moduleFilter" allows the core of functionality I was 
shooting for. Apologies for not just stating that.

>> --- Our team of 18 developers must make judgments about what to log and
>> when. Depending on the diagnostic activity, it is necessary to
>> enable/disable logging in specific domains of the application. The ability
>> to shut off logging in certain parts of the program at run time is paramount
>> to success in debugging certain issues, from our experiences.
> You can use verbose logging and the command line flag --vmodule.

I see, agreed!

It seems the verbose level has similar behavior to the severity level. 
If this is true, could someone define their own spectrum of levels out 
of an enumeration set, if they find the 5 regular levels are too coarse 
grained?

>> --- The hierarchy helps in being able to shut off a large branch of loggers
>> by specifying the level for just one ancestor. Also the hierarchy format (at
>> least in our case) maps well to the organization of objects across our
>> domains.
>> From my experience you never really know how to organize your loggers
> at dev time. You realize you want to turn something only at debug time
> which in many cases it is too late (E.g. you already shipped a binary
> to QA or customer). std.log gives you the ability to enable and
> disable logging based on glob match on the source file.

I believe I see this "glob" ability in the "moduleFilter" part of the 
VerboseConfig! Bravo! I was going to point out: the power of the 
hierarchy was in the efficient configuration of which parts of the 
program log and which do not. It appears the moduleFilter achieves this, 
though with more expressiveness!
Organization of loggers is definitely a brain exercise, I think partly 
because there's an implicit desire not to make a log message appear too 
alien if a customer must view it for any reason.
I've settled on roughly matching the logger organization to component 
organization.

>> -- Feature: Allow code/logic to be run inside the conditional block of a log
>> call.
>> --- An example of our need for this is the need to print specific data from
>> each member of a list of objects. Rather than incur log call overhead on
>> each iteration over a list (much less not being able to compile away that
>> logic), the most efficient solution seems to be allowing logic in the log
>> conditional block.
>> --- Of course, somebody somewhere will misuse this and put "business" logic
>> in there, and compile out a small but necessary tidbit which made their
>> program function.
>> --- From my very rough understanding after reading the Lazy Evaluation
>> article on "d-programming-language.org", this can be possible with the
>> current std.log interface:
>>                 Sample pseudo-code:
>>                 logInfo({
>>                 auto msg = "Video modes found: ";
>>                 foreach( mode, videoModes )
>>                 {
>>                 msg ~= to!string( mode.width ) ~ "x" ~ to!string( mode.height
>> ) ~ ";";
>>                 }
>>                 return msg
>>                 });
> Yes! but your example has a small bug...

Ha! I've been trying to achieve this "lazy implicit conversion of 
function literal to string" thing in my D "mini-test" suite. Haven't 
ironed it out just yet.

>> --- log4cxx simply allows a query to the logger at run-time to find out the
>> current log level.
> This currently not exposed but it is trivial to add support for it...

To start this point, I call upon the "Contract Programming" chapter of 
TDPL. Andrei notes that it is dangerous to place modifying code in code 
which should only be observing.
As it pertains to this case, I'd hope revealing the log level, or rather 
if the log filter will log, won't encourage putting "business logic" in 
a block meant only for logging.
To that end, all the same dangers exist for the method I described 
above. Hmmm, it may win if it can be stripped at compile time... I admit 
my ignorance regarding that stripping technique.


>>
>> I can provide success stories (well, success in finding and debugging
>> issues) from having a few of these features in our logging library, but that
>> could be boring so I'll hold back (available on request).
>>
>> 3. Suggestions
>> Well, the suggestions for std.log are basically the features described above
>> :-) . It'd be an injustice to express a desire to recreate log4cxx/log4j in
>> D, but certain features which log4cxx provides greatly enhance development
>> on large teams.
>>
>> I haven't thought through it, but I get the feeling D might accommodate
>> creating the logger hierarchy at compile time, or rather avoid string
>> (logger name) computations at run-time (log4cxx does all the string
>> manipulation at run-time).
> We can talk about how to improve performance at a later point but it
> should be possible to cache the results of vmodule filtering.

Right on!