www.digitalmars.com         C & C++   DMDScript  

digitalmars.D - LogLevel [was std.experimental.logger formal review round 3]

reply Martin Nowak <code+news.digitalmars dawg.eu> writes:
I just found a very compelling alternative solution to the LogLevel 
disabling problem. This was one of the reasons for the delay of std.log 
and the current solution still isn't great [1].

This idea here achieves
- fine grained control over log levels (per module/package)
- zero overhead for statically disabled log levels
- zero (almost) boilerplate (works even with the global stdlog)
- and it establishes a nice convention to enable logging for a library
   `pkg.logLevel = LogLevel.info;`

Basically it works by declaring a logLevel in a module or package.
Then the std.logger module does a reverse lookup of that declaration.

```d
module mymod;

import std.logger;

// can be anything that converts to a LogLevel
// calls with lower log level can be optimized away if this is a compile 
time constant
// runtime values also work nicely but incur a small overhead
// if this declaration is not present, logLevel from the package is used 
or the default LogLevel.

enum logLevel = LogLevel.critical;

void foo()
{
     info("information from foo"); // optimized out
     fatal("error");               // logs
}
```

https://gist.github.com/MartinNowak/443f11aa017d14007c35

There is a tiny gotcha, this works because the logger module imports the 
calling module. So we'd need to avoid module constructors in the logger 
module or use a workaround [2].

Also it can lead to additional imports when the whole package is 
imported to resolve logLevel.  This can be avoided though by declaring 
logLevel in a separate module and making it available in every module of 
a package.

```d
module mypkg.loglevel;

LogLevel logLevel;
```
```d
module mypkg.foo.bar;

public import mypkg.logLevel;

void baz(T)(T t)
{
     info("baz");
}
```

[1]: http://forum.dlang.org/post/m2p3r6$148j$1 digitalmars.com
[2]: 
https://github.com/D-Programming-Language/phobos/blob/9a46840c2b36beb6711244ec4340c117fc91a0f1/std/stdiobase.d
Dec 03 2014
next sibling parent reply Rikki Cattermole <alphaglosined gmail.com> writes:
On 4/12/2014 2:10 p.m., Martin Nowak wrote:
 I just found a very compelling alternative solution to the LogLevel
 disabling problem. This was one of the reasons for the delay of std.log
 and the current solution still isn't great [1].

 This idea here achieves
 - fine grained control over log levels (per module/package)
 - zero overhead for statically disabled log levels
 - zero (almost) boilerplate (works even with the global stdlog)
 - and it establishes a nice convention to enable logging for a library
    `pkg.logLevel = LogLevel.info;`

 Basically it works by declaring a logLevel in a module or package.
 Then the std.logger module does a reverse lookup of that declaration.

 ```d
 module mymod;

 import std.logger;

 // can be anything that converts to a LogLevel
 // calls with lower log level can be optimized away if this is a compile
 time constant
 // runtime values also work nicely but incur a small overhead
 // if this declaration is not present, logLevel from the package is used
 or the default LogLevel.

 enum logLevel = LogLevel.critical;

 void foo()
 {
      info("information from foo"); // optimized out
      fatal("error");               // logs
 }
 ```

 https://gist.github.com/MartinNowak/443f11aa017d14007c35

 There is a tiny gotcha, this works because the logger module imports the
 calling module. So we'd need to avoid module constructors in the logger
 module or use a workaround [2].

 Also it can lead to additional imports when the whole package is
 imported to resolve logLevel.  This can be avoided though by declaring
 logLevel in a separate module and making it available in every module of
 a package.

 ```d
 module mypkg.loglevel;

 LogLevel logLevel;
 ```
 ```d
 module mypkg.foo.bar;

 public import mypkg.logLevel;

 void baz(T)(T t)
 {
      info("baz");
 }
 ```

 [1]: http://forum.dlang.org/post/m2p3r6$148j$1 digitalmars.com
 [2]:
 https://github.com/D-Programming-Language/phobos/blob/9a46840c2b36beb6711244ec4340c117fc91a0f1/std/stdiobase.d
I also just wrote some test code based upon this idea. $ cat a.d module a; enum level = "test"; void main() { test("hi"); } void test(T, string module_ = __MODULE__)(T t) { import std.stdio; mixin("static import mod = " ~ module_ ~ ";"); writeln(mod.level, ": ", t); } $ cat b.d module b; import a; enum level = "BModule"; void afunc() { test("something"); } static this() { import std.stdio; writeln("static this on b"); } shared static this() { import std.stdio; writeln("shared static this on b"); } $ rdmd b.d shared static this on b static this on b test: hi Okay its a lot simpler and far less context specific. One thing I think should be addressed is at runtime, to override these defaults. At both function/method level and at module level. I'm not sure much can be done about module constructors, but static imports would probably be the best place to begin. Now theoretically it should also be a good place to look at using UDAS to override per function/method. Same goes for with statements for runtime changes. But in any case this is suddenly going into terms of frameworks not just logging libraries and making me go *shudder* not for phobos.
Dec 03 2014
parent Martin Nowak <code+news.digitalmars dawg.eu> writes:
On 12/04/2014 03:41 AM, Rikki Cattermole wrote:
 Okay its a lot simpler and far less context specific.
 One thing I think should be addressed is at runtime, to override these
 defaults.
Just use a value instead of an enum, and you can configure the log level at runtime. https://gist.github.com/MartinNowak/443f11aa017d14007c35#file-main-d
Dec 03 2014
prev sibling next sibling parent "Vic" <vic.cvc gmx.com> writes:
(I don't want to hijack the thread, and I'm so happy for donated 
hours. If I my just touch on that JRE size maintenance team did 
not add logging till 1.4
http://www.onjava.com/pub/a/onjava/2002/03/06/topten.html
- instead people used downstream. Pardon me)
Dec 03 2014
prev sibling next sibling parent reply Jacob Carlborg <doob me.com> writes:
On 2014-12-04 02:10, Martin Nowak wrote:
 I just found a very compelling alternative solution to the LogLevel
 disabling problem. This was one of the reasons for the delay of std.log
 and the current solution still isn't great [1].

 This idea here achieves
 - fine grained control over log levels (per module/package)
 - zero overhead for statically disabled log levels
 - zero (almost) boilerplate (works even with the global stdlog)
 - and it establishes a nice convention to enable logging for a library
    `pkg.logLevel = LogLevel.info;`

 Basically it works by declaring a logLevel in a module or package.
 Then the std.logger module does a reverse lookup of that declaration.
This is kind of cool that you can do in D, but it feels like a hack. I have stopped following the std.log thread, could you summarize what issues you're having and trying to solve and why not a more obvious solution doesn't work? -- /Jacob Carlborg
Dec 04 2014
parent reply "Martin Nowak" <code dawg.eu> writes:
On Thursday, 4 December 2014 at 08:14:56 UTC, Jacob Carlborg 
wrote:
 On 2014-12-04 02:10, Martin Nowak wrote:
 I just found a very compelling alternative solution to the 
 LogLevel
 disabling problem. This was one of the reasons for the delay 
 of std.log
 and the current solution still isn't great [1].

 This idea here achieves
 - fine grained control over log levels (per module/package)
 - zero overhead for statically disabled log levels
 - zero (almost) boilerplate (works even with the global stdlog)
 - and it establishes a nice convention to enable logging for a 
 library
   `pkg.logLevel = LogLevel.info;`
This is kind of cool that you can do in D, but it feels like a hack. I have stopped following the std.log thread, could you summarize what issues you're having and trying to solve and why not a more obvious solution doesn't work?
Zero overhead for statically disabled log levels. The current proposal uses global version identifiers to alter the behavior of std.logger. Fine grained (at least per library) control over log levels. The current proposal required to use different logger wrappers in each library and scoped global version identifiers, see [1] in the OP.
Dec 04 2014
next sibling parent reply "Ola Fosheim =?UTF-8?B?R3LDuHN0YWQi?= writes:
On Thursday, 4 December 2014 at 10:16:52 UTC, Martin Nowak wrote:
 On Thursday, 4 December 2014 at 08:14:56 UTC, Jacob Carlborg
 hack. I have stopped following the std.log thread, could you 
 summarize what issues you're having and trying to solve and 
 why not a more obvious solution doesn't work?
Zero overhead for statically disabled log levels. The current proposal uses global version identifiers to alter the behavior of std.logger. Fine grained (at least per library) control over log levels. The current proposal required to use different logger wrappers in each library and scoped global version identifiers, see [1] in the OP.
I like the direction you are taking, but I think the better solution is to have: 1. A manifest/config file where you configure these and other settings in a uniform manner. 2. Provide support for configurations and switching between configurations at realtime. 3. Compiler support for the manifest file that allows library code to query it at compile time as well as generating bitfields for real time switching between configurations. (Just memcpy to change configuration) 4. Have logInfo(…) etc as always inlined stubs. 5. Have one bit per log level (32 should be sufficient), rather than a number. 6. Allow for compiler profiling so that bits in the configuration that are accessed together become co-located on the same word/64 bytes cacheline. Something like this: <configuration name="normal"> <module match="*"> <logging type="info" status="off"/> <logging type="error" status="on" logger="file" href="file://var/myfile.txt"/> </module> <module match="http"> <logging type="info" status="on" logger="remote"/> </module> </configuration> <configuration name="debug" inherit="normal"> <module match="mylib.*[has_symbol('DEBUG')]"> <logging type="debug" status="on" /> </module> </configuration>
Dec 04 2014
next sibling parent reply "Robert burner Schadek" <rburners gmail.com> writes:
As I have explained countless times, the configuration in source 
and through inheritance will always be more powerful and flexible 
than a config file. I'm not gone create any config file support, 
as there will be always one feature missing and there is just no 
way to anticipate all possible configuration requirements. So one 
shouldn't even try.
Dec 04 2014
parent reply "Ola Fosheim =?UTF-8?B?R3LDuHN0YWQi?= writes:
On Thursday, 4 December 2014 at 10:56:29 UTC, Robert burner 
Schadek wrote:
 As I have explained countless times, the configuration in 
 source and through inheritance will always be more powerful and
There is no contradiction. Configuration is level 1, implementation is level 2.
Dec 04 2014
parent "Robert burner Schadek" <rburners gmail.com> writes:
On Thursday, 4 December 2014 at 11:02:23 UTC, Ola Fosheim Grøstad 
wrote:
 On Thursday, 4 December 2014 at 10:56:29 UTC, Robert burner 
 Schadek wrote:
 As I have explained countless times, the configuration in 
 source and through inheritance will always be more powerful and
There is no contradiction. Configuration is level 1, implementation is level 2.
Either I don't see your point or you didn't see mine.
Dec 04 2014
prev sibling parent reply "Martin Nowak" <code dawg.eu> writes:
On Thursday, 4 December 2014 at 10:44:22 UTC, Ola Fosheim Grøstad 
wrote:
 I like the direction you are taking, but I think the better 
 solution is to have:
It's a nice idea for generic feature testing flags, but it's a lot of implementation work in the compiler. And it seems odd to implement a big part of a library in the compiler.
Dec 04 2014
parent reply "Ola Fosheim =?UTF-8?B?R3LDuHN0YWQi?= writes:
On Thursday, 4 December 2014 at 11:02:39 UTC, Martin Nowak wrote:
 It's a nice idea for generic feature testing flags, but it's a 
 lot of implementation work in the compiler. And it seems odd to 
 implement a big part of a library in the compiler.
I think D lacks a generic project configuration mechanism. I generally want configurations to be located in one or at least a few files that are easy to modify and which can have tools written for them. So yes, this should not be written for logger alone. I don't know how much work it is for the compiler, but I suspect a lot of it could be written as a compiler extension in D that communicates with the C++ compiler core. It would be very useful for server programmers to be able to swap configuration for the whole program on a live server when you detect a problem. Third parties could create a GUI tool for managing configuration settings with automatic transfer of new bitpatterns over tcp/udp, or even automatic rebuilds.
Dec 04 2014
parent reply "Robert burner Schadek" <rburners gmail.com> writes:
On Thursday, 4 December 2014 at 11:49:53 UTC, Ola Fosheim Grøstad 
wrote:
 I think D lacks a generic project configuration mechanism. I 
 generally want configurations to be located in one or at least 
 a few files that are easy to modify and which can have tools 
 written for them. So yes, this should not be written for logger 
 alone.
I think D lacks a good std.serialization module
Dec 04 2014
parent "Ola Fosheim =?UTF-8?B?R3LDuHN0YWQi?= writes:
On Thursday, 4 December 2014 at 12:16:54 UTC, Robert burner 
Schadek wrote:
 I think D lacks a good std.serialization module
That would be a good point if you did binary logging…
Dec 04 2014
prev sibling parent Andrei Alexandrescu <SeeWebsiteForEmail erdani.org> writes:
On 12/4/14 8:16 PM, Martin Nowak wrote:
 On Thursday, 4 December 2014 at 08:14:56 UTC, Jacob Carlborg wrote:
 On 2014-12-04 02:10, Martin Nowak wrote:
 I just found a very compelling alternative solution to the LogLevel
 disabling problem. This was one of the reasons for the delay of std.log
 and the current solution still isn't great [1].

 This idea here achieves
 - fine grained control over log levels (per module/package)
 - zero overhead for statically disabled log levels
 - zero (almost) boilerplate (works even with the global stdlog)
 - and it establishes a nice convention to enable logging for a library
   `pkg.logLevel = LogLevel.info;`
This is kind of cool that you can do in D, but it feels like a hack. I have stopped following the std.log thread, could you summarize what issues you're having and trying to solve and why not a more obvious solution doesn't work?
Zero overhead for statically disabled log levels. The current proposal uses global version identifiers to alter the behavior of std.logger. Fine grained (at least per library) control over log levels. The current proposal required to use different logger wrappers in each library and scoped global version identifiers, see [1] in the OP.
We should scrutinize and streamline this idiom properly. It's very powerful and after enshrined in Phobos it will serve everyone as a precedent to follow. Thanks, Martin! -- Andrei
Dec 08 2014
prev sibling next sibling parent reply "Kagamin" <spam here.lot> writes:
On Thursday, 4 December 2014 at 01:10:43 UTC, Martin Nowak wrote:
 ```d
 module mypkg.foo.bar;

 public import mypkg.logLevel;

 void baz(T)(T t)
 {
     info("baz");
 }
 ```
Not bad. Does info="baz" compile?
Dec 04 2014
parent "Martin Nowak" <code dawg.eu> writes:
On Thursday, 4 December 2014 at 08:42:36 UTC, Kagamin wrote:
 Not bad. Does info="baz" compile?
That's not my business, if it's callable with a single argument, it would work, but it's not property.
Dec 04 2014
prev sibling next sibling parent reply "Robert burner Schadek" <rburners gmail.com> writes:
That is much nicer, thank you for taking the time.

Couldn't way just say that we don't import __MODULE__ but rather 
__MODULE__ ~ "_loggerinfo.d" and then describe the import 
constraint in the documentation.
Dec 04 2014
next sibling parent "Martin Nowak" <code dawg.eu> writes:
On Thursday, 4 December 2014 at 10:37:12 UTC, Robert burner 
Schadek wrote:
 That is much nicer, thank you for taking the time.

 Couldn't way just say that we don't import __MODULE__ but 
 rather __MODULE__ ~ "_loggerinfo.d" and then describe the 
 import constraint in the documentation.
Good idea, that would work for libraries (dub packages) where adding a single module is cheap. It's a bit annoying for script like D usage so I'd only do this optionally. But then the compiler would hit the hard disk every time you call log, trying to find that non-present module, so maybe it's simpler and more transparent to always only look in the calling context.
Dec 04 2014
prev sibling next sibling parent reply "Martin Nowak" <code dawg.eu> writes:
On Thursday, 4 December 2014 at 10:37:12 UTC, Robert burner 
Schadek wrote:
 That is much nicer, thank you for taking the time.

 Couldn't way just say that we don't import __MODULE__ but 
 rather __MODULE__ ~ "_loggerinfo.d" and then describe the 
 import constraint in the documentation.
Importing a different module wouldn't reliably work, when file paths differ from module paths. The nice thing about importing __MODULE__ is that the compiler already knows it, because it's the caller. Also importing a different file by name feels a bit too much like magic ruby bindings.
Dec 04 2014
parent "Robert burner Schadek" <rburners gmail.com> writes:
On Thursday, 4 December 2014 at 11:12:02 UTC, Martin Nowak wrote:
 On Thursday, 4 December 2014 at 10:37:12 UTC, Robert burner 
 Schadek wrote:
 That is much nicer, thank you for taking the time.

 Couldn't way just say that we don't import __MODULE__ but 
 rather __MODULE__ ~ "_loggerinfo.d" and then describe the 
 import constraint in the documentation.
Importing a different module wouldn't reliably work, when file paths differ from module paths. The nice thing about importing __MODULE__ is that the compiler already knows it, because it's the caller. Also importing a different file by name feels a bit too much like magic ruby bindings.
Well, the static if mixin stuff also a bit like magic. How do you suggest do we solve the dependency cycle? Anyway, the code you showed needs a default case where there is no LogLevel defined and no parent is left.
Dec 04 2014
prev sibling parent reply Andrei Alexandrescu <SeeWebsiteForEmail erdani.org> writes:
On 12/4/14 8:37 PM, Robert burner Schadek wrote:
 That is much nicer, thank you for taking the time.

 Couldn't way just say that we don't import __MODULE__ but rather
 __MODULE__ ~ "_loggerinfo.d" and then describe the import constraint in
 the documentation.
Perhaps that might improve error messages. I fear of things that could happen if a circular import via mixin fails. Andrei
Dec 08 2014
parent "Robert burner Schadek" <rburners gmail.com> writes:
On Monday, 8 December 2014 at 21:20:20 UTC, Andrei Alexandrescu 
wrote:
 On 12/4/14 8:37 PM, Robert burner Schadek wrote:
 That is much nicer, thank you for taking the time.

 Couldn't way just say that we don't import __MODULE__ but 
 rather
 __MODULE__ ~ "_loggerinfo.d" and then describe the import 
 constraint in
 the documentation.
Perhaps that might improve error messages. I fear of things that could happen if a circular import via mixin fails. Andrei
How long is a line of your terminal? On a more serious note: I proposed "_loggerinfo.d" to counteract that and this file could be the place to store all logger configuration anybody invents. This way we would have a canonical place for all configuration concerning the logger.
Dec 09 2014
prev sibling parent reply "Daniel Murphy" <yebbliesnospam gmail.com> writes:
"Martin Nowak"  wrote in message news:m5ocaj$2i8t$1 digitalmars.com...

 I just found a very compelling alternative solution to the LogLevel 
 disabling problem. This was one of the reasons for the delay of std.log 
 and the current solution still isn't great [1].

 This idea here achieves
 - fine grained control over log levels (per module/package)
 - zero overhead for statically disabled log levels
 - zero (almost) boilerplate (works even with the global stdlog)
 - and it establishes a nice convention to enable logging for a library
    `pkg.logLevel = LogLevel.info;`

 Basically it works by declaring a logLevel in a module or package.
 Then the std.logger module does a reverse lookup of that declaration.
FWIW I don't really like this - it feels like a hack. I'd rather just declare a private logger alias (or something like that) and use that in the library. Decision can be made at compile time, doesn't require reverse module imports, doesn't depend on global versions. eg alias libraryLogger = std.logger.FilteredLogger!(LogLevel.info);
Dec 04 2014
next sibling parent Martin Nowak <code+news.digitalmars dawg.eu> writes:
On 12/04/2014 03:32 PM, Daniel Murphy wrote:
 FWIW I don't really like this - it feels like a hack.  I'd rather just
 declare a private logger alias (or something like that) and use that in
 the library.  Decision can be made at compile time, doesn't require
 reverse module imports, doesn't depend on global versions.

 eg

 alias libraryLogger = std.logger.FilteredLogger!(LogLevel.info);
That's a bit shorter but similar to what I already proposed here http://forum.dlang.org/post/m2k13k$12vf$1 digitalmars.com. Something along this line would still be a good solution IMO.
Dec 04 2014
prev sibling parent reply "Dicebot" <public dicebot.lv> writes:
On Thursday, 4 December 2014 at 14:32:27 UTC, Daniel Murphy wrote:
 FWIW I don't really like this - it feels like a hack.  I'd 
 rather just declare a private logger alias (or something like 
 that) and use that in the library.  Decision can be made at 
 compile time, doesn't require reverse module imports, doesn't 
 depend on global versions.

 eg

 alias libraryLogger = std.logger.FilteredLogger!(LogLevel.info);
I agree with Daniel here. It feels like seeking for too much magic just because it is cool - while more simple and straightforward approach can do the job as well.
Dec 05 2014
parent "Robert burner Schadek" <rburners gmail.com> writes:
On Friday, 5 December 2014 at 10:30:08 UTC, Dicebot wrote:
 On Thursday, 4 December 2014 at 14:32:27 UTC, Daniel Murphy 
 wrote:
 FWIW I don't really like this - it feels like a hack.  I'd 
 rather just declare a private logger alias (or something like 
 that) and use that in the library.  Decision can be made at 
 compile time, doesn't require reverse module imports, doesn't 
 depend on global versions.

 eg

 alias libraryLogger = 
 std.logger.FilteredLogger!(LogLevel.info);
I agree with Daniel here. It feels like seeking for too much magic just because it is cool - while more simple and straightforward approach can do the job as well.
Yes simpler is better, if it works. As discussed twice already, an approach like: alias libraryLogger = std.logger.FilteredLogger!(LogLevel.info); will not work. Currently I think the best solution is Martin's idea with my mod. The complexity of the task to accomplish does not simple go away. Unless you cut features which we can't do to keep the generality of the library. And that is the main goal after all.
Dec 05 2014