July 24, 2014
Initial review period is closing soon. I will make a summary and start a voting thread this weekend.
July 24, 2014
>> It does the right thing... there is an overload: without additional arguments, the first argument (not necessary a string) is not a format string.
>>
>
> Now if write a bug:
> warning("there was an error because the file %s is missing!");
>
> and I forgot the argument, no problem, it will run without errrors despite I made one. This is not an improvement over writef.
>
> (this particular bug came up in DUB among others, and my last example was a real case too in production software where the users would call things with "%" in the names)

It is easy to make mistakes while producing text.

One nasty example:

  writef("On %s the exchange rate raised with more than 5%%", date);

later changed to:

  if (date == today())
    write("Today the exchange rate raised with more than 5%%");
  else
    writef("On %s the exchange rate raised with more than 5%%", date);

>
> Two different operations conceptually => two names.
>

The logging facility is a high-level utility library. I think, its main
design goal should be: the usage is a no-brainer, it stays out of
the flow of thoughts while using it. The decision whether a message is
a warning, an error, or just an info, it's enough of a burden for the
user already, who anyhow takes a lot of decisions while writing the
actual code.

It is a matter of opinion if warning and warningf are different
operations, both produce a message and warningf with one argument will
be inefficient in best case, or an error, as you described above.

We already have in standard library examples of overloaded functions
for "different operations".

For example "find" in std.algorithm (low-level library): it has an
overload which takes an element as argument and another one which takes
ranges. Some may say that this is conceptually not different, but then
if we look at the predicate of find, we see that they are quite
different: the first overload  matches the argument in the input range,
the second matches successive elements of the argument against
successive elements in the input range. You can say these are
conceptualy the same, but you can also say it is different (probably
this is the reason why findSplit* didn't bother to implement the
Element overload).

As I already said, I think that the analogy with write/writef is wrong
because of at least 2 reasons:
 1. write is a low level function which is part of the flow of thoughts
    for resolving the problem at hand
 2. Contrary to the log functions, write is used sometimes to produce
    non human-readable output, thus write(arg1, arg2, arg3) being a
    valid usage of it.

>>>
>>> Do you realize rolling loggers are not there because they are supposed to be in another layer as subclasses of Logger?
>>>
>>
>> Contrary to the NullLogger, writing a rolling logger is a non-trivial task.
>
> NullLogger is there precisely because it's trivial and needed.
> Of course a rolling logger is not that trivial, but std.logger is there to be orthogonal and a foundation not providing everything non-trivial.

Probably you need a NullLogger, if you use the MultiLogger.
For a big application I think it is better to have a big log file,
and filter afterwards based on module, than the other way around:
you have 3 files and need to merge/correlate them.

Regarding having different log levels per module: ex. the application
has log level warning and a selected module log level trace, I think
there is a simpler solution. Instead of having different loggers for
each module, it would be easier to have an list, similar to an ACL,
generated at compile time, containg the log level of the selected
module(s). This list will be consulted by the log function in addition
to normal log level check.

This will avoid code like (again a decision to make):
  logFoo.warning("Log in my module");
  log.warning("Log in application log");

July 24, 2014
On 7/11/14, 7:36 AM, Dicebot wrote:
> Round of a formal review before proceeding to voting. Subject for Phobos
> inclusion : http://wiki.dlang.org/Review/std.logger authored by Robert
> Schadek.

Preface: (1) We already use the std.logger candidate at Facebook; (2) I really want to get this in, it's been past time already.

Overall: I think std.logger has a passable overall design having simplicity and no-nonsense as compelling advantages. However, there's some serious tactical work needed.

0. There's no way to set the minimal logging level statically, except for an on/off switch. There must be a way to define e.g. -version=logLevel=trace that sets the minimum logging level actually performed. Any logging below that level is a no-op. Which segues into the next problem:

1. There's a bunch of code still generated even with logging statically disabled (per http://d.godbolt.org). I could not find a way to completely eliminate generated code. Unused lazy parameters MUST generate no code at the front end level. This is a performance bug in the D front end that blocks acceptance of this proposal.

2. The three one-letter suffixes don't seem to scale well. They optimize for brevity but at the cost of clarity. Also they establish a precedent - are we sure we recommend future D code in the standard library and beyond to mangle names using one-letter conventions? I think we must find a way to solve things via overloads.

Currently we have: log, logc, logf, logl, logcf, loglf, loglc, loglcf. One would almost expect logwtf to be somewhere in there.

I think an overloading-based solution would be a better choice here. First, I think the logging level must guide all overloads. True, we'd sometimes like to log the logging level itself, but that's easily done by using a formatting function (as shown below). So:

log(A...)(lazy A stuff); // just log whatevs
log(A...)(LogLevel lvl, lazy A stuff); // log at specified level
log(A...)(bool c, LogLevel lvl, lazy A stuff); // conditionally log at specified level

Then three more logf with similar signatures, using the precedent set by write/writef. And we're done.

To log the logging level itself, just use logf(someLevel, "%s", someLevel) and be done with it.

There's no conditional logging without specifying a level, which should be fine seeing as conditional logging is not that frequent to start with.

There should be some shortcuts for logging levels such that one can write log(info, "crap") instead of log(LogLevel.info, "crap").

3. I'm not sure I like the design using defaultLogger in conjunction with free functions using it. It clearly makes for comfortable casual logging by just calling log(whatevs) and it uses a precedent set by stdout. But I wonder if it would be cleaner to just give it a shorter name "log" and then have it have a "write" method:

log("crap");
-> becomes ->
log.write("crap");

Also there'd be log.writef("%s", "crap") etc.

4. Conditional logging must be justified. In my mind the justification is that statically setting the log level makes the code disappear without the condition being ever evaluated, but the current design doesn't allow setting the log level!

5. There was some nice stuff in the previous std.logger work by me and later Jose (I think), which allowed logging every n times/milliseconds so as to allow nice throttling. That's nice to omit/defer for simplification purposes, but I noticed that log noise is a serious matter.

6. The current backend design requires use of classes and references, i.e. garbage collection. Amid the current tendency to make std work without requiring GC, I think a design based on RefCounted would be recommended here.

7. The current backend design fills a struct with data then passes it to the implementation. But if the implementation doesn't use e.g. the timestamp then that work has been wasted. Maybe offer the fields as properties instead, with caching upon first use?

8. Documentation needs work as it has disfluencies and typos.

9. I've also posted a bunch of comments to the code at https://github.com/D-Programming-Language/phobos/pull/1500/files


Andrei

July 24, 2014
On Thursday, 24 July 2014 at 18:51:03 UTC, Andrei Alexandrescu wrote:
> 3. I'm not sure I like the design using defaultLogger in conjunction with free functions using it. It clearly makes for comfortable casual logging by just calling log(whatevs) and it uses a precedent set by stdout. But I wonder if it would be cleaner to just give it a shorter name "log" and then have it have a "write" method:
>
> log("crap");
> -> becomes ->
> log.write("crap");
>
> Also there'd be log.writef("%s", "crap") etc.

It is amusing to see that you don't like D module system too :)

(and no, "write" it is not cleaner at all being different from pretty much any logging system out there)
July 24, 2014
On Thursday, 24 July 2014 at 18:51:03 UTC, Andrei Alexandrescu wrote:
>
> 0. There's no way to set the minimal logging level statically, except for an on/off switch. There must be a way to define e.g. -version=logLevel=trace that sets the minimum logging level actually performed. Any logging below that level is a no-op. Which segues into the next problem:

I'm currently working on this.

>
> 1. There's a bunch of code still generated even with logging statically disabled (per http://d.godbolt.org). I could not find a way to completely eliminate generated code. Unused lazy parameters MUST generate no code at the front end level. This is a performance bug in the D front end that blocks acceptance of this proposal.

that is part of 0. work

>
> 2. The three one-letter suffixes don't seem to scale well. They optimize for brevity but at the cost of clarity. Also they establish a precedent - are we sure we recommend future D code in the standard library and beyond to mangle names using one-letter conventions? I think we must find a way to solve things via overloads.
>
> Currently we have: log, logc, logf, logl, logcf, loglf, loglc, loglcf. One would almost expect logwtf to be somewhere in there.
>
> I think an overloading-based solution would be a better choice here. First, I think the logging level must guide all overloads. True, we'd sometimes like to log the logging level itself, but that's easily done by using a formatting function (as shown below). So:
>
> log(A...)(lazy A stuff); // just log whatevs
> log(A...)(LogLevel lvl, lazy A stuff); // log at specified level
> log(A...)(bool c, LogLevel lvl, lazy A stuff); // conditionally log at specified level

log(A...)(lazy A stuff) matches the next two sigs as well. I tried that.
Maybe some overloading inside the function body may work, but that is just a mess IMo.

>
> Then three more logf with similar signatures, using the precedent set by write/writef. And we're done.
>
> To log the logging level itself, just use logf(someLevel, "%s", someLevel) and be done with it.
>
> There's no conditional logging without specifying a level, which should be fine seeing as conditional logging is not that frequent to start with.

there is. tracec, infoc, ....

>
> There should be some shortcuts for logging levels such that one can write log(info, "crap") instead of log(LogLevel.info, "crap").


there is trace%s, info%s, warning%s .... c|f

>
> 3. I'm not sure I like the design using defaultLogger in conjunction with free functions using it. It clearly makes for comfortable casual logging by just calling log(whatevs) and it uses a precedent set by stdout. But I wonder if it would be cleaner to just give it a shorter name "log" and then have it have a "write" method:
>
> log("crap");
> -> becomes ->
> log.write("crap");
>
> Also there'd be log.writef("%s", "crap") etc.

well, this is by design. I wanted to provide very easy simple looging for hacking a small script. If you want more, you properly want to handle Loggers as variables.

>
> 4. Conditional logging must be justified. In my mind the justification is that statically setting the log level makes the code disappear without the condition being ever evaluated, but the current design doesn't allow setting the log level!
>
> 5. There was some nice stuff in the previous std.logger work by me and later Jose (I think), which allowed logging every n times/milliseconds so as to allow nice throttling. That's nice to omit/defer for simplification purposes, but I noticed that log noise is a serious matter.

I could start std.logger.condition

>
> 6. The current backend design requires use of classes and references, i.e. garbage collection. Amid the current tendency to make std work without requiring GC, I think a design based on RefCounted would be recommended here.

Maybe I'm wrong, but RefCounted does not support polymorphism and that would break not only the MultiLogger and the defaultLogger. I think this is a legitimate use of classes, as Logger properly stay alive the complete run of the program.

>
> 7. The current backend design fills a struct with data then passes it to the implementation. But if the implementation doesn't use e.g. the timestamp then that work has been wasted. Maybe offer the fields as properties instead, with caching upon first use?

hm, but taking the timestamp after the log call seams wrong. Again, I think this is by design from using polymorphism.

>
> 8. Documentation needs work as it has disfluencies and typos.

If have already worked in all of JakovOvrum and you fixes.

>
> 9. I've also posted a bunch of comments to the code at https://github.com/D-Programming-Language/phobos/pull/1500/files
>
>
> Andrei

July 24, 2014
On 7/24/14, 12:23 PM, Robert burner Schadek wrote:
> On Thursday, 24 July 2014 at 18:51:03 UTC, Andrei Alexandrescu wrote:
>> log(A...)(lazy A stuff); // just log whatevs
>> log(A...)(LogLevel lvl, lazy A stuff); // log at specified level
>> log(A...)(bool c, LogLevel lvl, lazy A stuff); // conditionally log at
>> specified level
>
> log(A...)(lazy A stuff) matches the next two sigs as well. I tried that.
> Maybe some overloading inside the function body may work, but that is
> just a mess IMo.

Use template constraints.

I realized after posting that the log level should also be a static parameter so the logging framework can choose to disable it entirely:

log!Loglevel.info("crap");

But wait there are the explicit functions trace, error etc. so... those do implicitly choose the level statically. Noice.

>> There's no conditional logging without specifying a level, which
>> should be fine seeing as conditional logging is not that frequent to
>> start with.
>
> there is. tracec, infoc, ....

I meant in the proposed design.

>> There should be some shortcuts for logging levels such that one can
>> write log(info, "crap") instead of log(LogLevel.info, "crap").
>
>
> there is trace%s, info%s, warning%s .... c|f

Okay.

>> 3. I'm not sure I like the design using defaultLogger in conjunction
>> with free functions using it. It clearly makes for comfortable casual
>> logging by just calling log(whatevs) and it uses a precedent set by
>> stdout. But I wonder if it would be cleaner to just give it a shorter
>> name "log" and then have it have a "write" method:
>>
>> log("crap");
>> -> becomes ->
>> log.write("crap");
>>
>> Also there'd be log.writef("%s", "crap") etc.
>
> well, this is by design. I wanted to provide very easy simple looging
> for hacking a small script. If you want more, you properly want to
> handle Loggers as variables.

I think I'm fine with that after all.

>> 5. There was some nice stuff in the previous std.logger work by me and
>> later Jose (I think), which allowed logging every n times/milliseconds
>> so as to allow nice throttling. That's nice to omit/defer for
>> simplification purposes, but I noticed that log noise is a serious
>> matter.
>
> I could start std.logger.condition

Thing is you must make sure you integrate with statically setting the logging level. Throttling is _especially_ used/useful in intensive loops. Being able to rebuild a large app with a different logging level to debug a pernicious condition at the cost of some speed is pretty awesome. It also makes verbose logging psychologically "free" the same way assert is.

In fact you may want to define an extra logging level e.g. "verbose" or "yap" which is by default disabled and can be enabled explicitly. It would be hierarchically below normal logging.

>> 6. The current backend design requires use of classes and references,
>> i.e. garbage collection. Amid the current tendency to make std work
>> without requiring GC, I think a design based on RefCounted would be
>> recommended here.
>
> Maybe I'm wrong, but RefCounted does not support polymorphism and that
> would break not only the MultiLogger and the defaultLogger. I think this
> is a legitimate use of classes, as Logger properly stay alive the
> complete run of the program.

The use of polymorphism is legit. RefCounted either works with classes or must be made to work with classes.

>> 7. The current backend design fills a struct with data then passes it
>> to the implementation. But if the implementation doesn't use e.g. the
>> timestamp then that work has been wasted. Maybe offer the fields as
>> properties instead, with caching upon first use?
>
> hm, but taking the timestamp after the log call seams wrong. Again, I
> think this is by design from using polymorphism.

Yah, it'd be a tad later but I guess it shouldn't be a large problem. Same goes about the thread id.

>> 8. Documentation needs work as it has disfluencies and typos.
>
> If have already worked in all of JakovOvrum and you fixes.

Cool, thanks.



Andrei

July 24, 2014
>
> In fact you may want to define an extra logging level e.g. "verbose" or "yap" which is by default disabled and can be enabled explicitly. It would be hierarchically below normal logging.


Isn't this what 'trace' level is for?


July 24, 2014
On Friday, 11 July 2014 at 14:36:34 UTC, Dicebot wrote:
> Round of a formal review before proceeding to voting. Subject for Phobos inclusion : http://wiki.dlang.org/Review/std.logger authored by Robert Schadek.

First I want to say that I want this to be *the* logging library, just as I always want a D library to be the best library in the world at what it does, as I believe D allows us to do that. I'm confident std.logger can become that, so thank you Robert for your work.

As for using class-based polymorphism; this doesn't have to mean GC memory. The only part of the library code that should have a need to allocate a logger class is the lazy initialization in `defaultLogger`. If we change this to allocate in global memory, then it's entirely up to the user how to allocate logger instances. Giving up classes here because of GC means giving up classes in no-GC code entirely, which I think is a serious overreaction. I think there are reasons to question the class-based polymorphism, on grounds such as - do we require that `writeLogMsg` is @nogc so we can log in @nogc code? What about nothrow? When it comes to performance and the indirect call involved, I don't think there's a way around that.

When it comes to GC memory, MultiLogger using an associative array is a blocker. However, I don't think it can be elegantly fixed as we don't have pluggable allocators for any of our standard containers yet. Maybe using an array (perhaps sorted) is an acceptable compromise measure if @nogc is deemed a priority.

One thing that really bugs me though, is that `Logger` is an abstract class and not an interface. An abstract class should only be needed when it has both pure virtual functions as well as default functionality that can be conditionally overridden, so `Logger` should not be a candidate. It should be rewritten in terms of an interface, which enables users to implement logger functionality in any of their classes, instead of having to dedicate a new class type just to override one virtual function.

I much prefer overloading over the mess of suffixes for the same reasons Andrei mentioned.

The library's stance on thread safety needs to be clearly defined. Currently, `defaultLogger` is process-wide, which can only mean logger instances must be thread-safe. Yet there is no mention in the documentation that loggers must be thread-safe, and indeed I think most of the default-provided loggers are written with no concern for thread safety.

I suggest one of two approaches: 1) make `defaultLogger` TLS and rework the documentation so it's clear that each thread must manage their own logger, or 2) make it clear that `defaultLogger` must be thread-safe, and take extreme care in the default-provided loggers that they are indeed thread-safe. Maybe a templated base logger class `LockingLogger` or something could help here.

The documentation needs a lot of work, but I think anyone can help with that. I intend to file a pull request to Robert's fork with fixes I could spot; it seems more efficient for both of us than posting an endless stream of line comments.
July 24, 2014
On Thursday, 24 July 2014 at 22:27:34 UTC, Jakob Ovrum wrote:
> On Friday, 11 July 2014 at 14:36:34 UTC, Dicebot wrote:
>> Round of a formal review before proceeding to voting. Subject for Phobos inclusion : http://wiki.dlang.org/Review/std.logger authored by Robert Schadek.
>
> First I want to say that I want this to be *the* logging library, just as I always want a D library to be the best library in the world at what it does, as I believe D allows us to do that. I'm confident std.logger can become that, so thank you Robert for your work.

That is music in my ears...

>
> As for using class-based polymorphism; this doesn't have to mean GC memory. The only part of the library code that should have a need to allocate a logger class is the lazy initialization in `defaultLogger`. If we change this to allocate in global memory, then it's entirely up to the user how to allocate logger instances. Giving up classes here because of GC means giving up classes in no-GC code entirely, which I think is a serious overreaction. I think there are reasons to question the class-based polymorphism, on grounds such as - do we require that `writeLogMsg` is @nogc so we can log in @nogc code? What about nothrow? When it comes to performance and the indirect call involved, I don't think there's a way around that.

I do this lazily in a function, because having it global froze std.concurrency and std.process unittest. I couldn't figure out why.
As said earlier, I think GC and Logger is a none issue. I mean how often has anyone seen a Logger created in a loop over and over again.
nothrow will be hard as std.logger uses format, same for nogc

>
> When it comes to GC memory, MultiLogger using an associative array is a blocker. However, I don't think it can be elegantly fixed as we don't have pluggable allocators for any of our standard containers yet. Maybe using an array (perhaps sorted) is an acceptable compromise measure if @nogc is deemed a priority.

So you're thinking of a stack array?

>
> One thing that really bugs me though, is that `Logger` is an abstract class and not an interface. An abstract class should only be needed when it has both pure virtual functions as well as default functionality that can be conditionally overridden, so `Logger` should not be a candidate. It should be rewritten in terms of an interface, which enables users to implement logger functionality in any of their classes, instead of having to dedicate a new class type just to override one virtual function.

What about the log functions and there implementation as well as the Logger specific LogLevel and name?
>
> I much prefer overloading over the mess of suffixes for the same reasons Andrei mentioned.

I'm working on that.

>
> The library's stance on thread safety needs to be clearly defined. Currently, `defaultLogger` is process-wide, which can only mean logger instances must be thread-safe. Yet there is no mention in the documentation that loggers must be thread-safe, and indeed I think most of the default-provided loggers are written with no concern for thread safety.
>
> I suggest one of two approaches: 1) make `defaultLogger` TLS and rework the documentation so it's clear that each thread must manage their own logger, or 2) make it clear that `defaultLogger` must be thread-safe, and take extreme care in the default-provided loggers that they are indeed thread-safe. Maybe a templated base logger class `LockingLogger` or something could help here.

yeah, apart from StdIOLogger everything is thread unsafe. I like the template base class LockingLogger idea. I will see what I can do.

>
> The documentation needs a lot of work, but I think anyone can help with that. I intend to file a pull request to Robert's fork with fixes I could spot; it seems more efficient for both of us than posting an endless stream of line comments.
+1
July 24, 2014
On Thursday, 24 July 2014 at 23:01:56 UTC, Robert burner Schadek wrote:
> I do this lazily in a function, because having it global froze std.concurrency and std.process unittest. I couldn't figure out why.

It could still be initialized lazily, using `emplace`, ala

---
private static __gshared Logger _defaultLogger;

Logger defaultLogger() @safe @nogc
{
    static __gshared ubyte[__traits(classInstanceSize, StdoutLogger)] buffer;

    if(!_defaultLogger) // TODO: thread safety
        _defaultLogger = () @trusted { return emplace!StdoutLogger(buffer); }();

    return _defaultLogger;
}

void defaultLogger(Logger newDefaultLogger) @safe @nogc
{
    _defaultLogger = newDefaultLogger;
}
---

> As said earlier, I think GC and Logger is a none issue. I mean how often has anyone seen a Logger created in a loop over and over again.

Some programs want to forego having a GC-heap entirely. That means any GC allocation is a no-go.

Class instances don't have to be GC-allocated, so it's not an issue to use classes.

> nothrow will be hard as std.logger uses format, same for nogc

How often have you seen a formatted log message logged in a loop? I'd wager that happens quite often. Using `format` is a no-go as it completely thrashes the GC, it needs to use `formattedWrite` to write directly to the underlying buffer (such as a file).

Even using `formattedWrite` though, `nothrow` is still a problem, and since exceptions are still GC-allocated, it doesn't help with @nogc either. The latter is something we can fix in the future though.

> So you're thinking of a stack array?

No, MultiLogger could manage a non-GC yet still heap-allocated array using std.container.array.Array. It uses the C heap internally, i.e. malloc, realloc and free. Sortedness can be used for searching by name in logarithmic time if desired.

> What about the log functions and there implementation as well as the Logger specific LogLevel and name?

The log functions don't need to be virtual, only the `writeLogMsg` function does, so these implementations can either be final member functions of the interface, or UFCS functions as I suggested in the corresponding line comment.

The Logger-specific LogLevel and the name do not have to be implemented by Logger. Leave it to concrete classes to implement those. As an internal aid, an abstract GenericLogger base class that manages these properties as member variables (as Logger currently does) can help.