std.experimental.logger formal review round 3

[Dicebot via Digitalmars-d]

Previous review thread :
http://forum.dlang.org/post/zhvmkbahrqtgkptdlcvh at forum.dlang.org

Previous voting thread (also contains discussion in the end) :
http://forum.dlang.org/post/vbotavcclttrgvzcjjia at forum.dlang.org

Code : https://github.com/D-Programming-Language/phobos/pull/1500

Important changes since last review:
- new approach for compile-time log level filtering
- thread-safe API (by Marco Leise, commits 3b32618..e71f317)
- documentation enhancements all over the place
- more @nogc annotations
- "raw" log overload that expects pre-formatted message and all
metadata (file/line/function) as run-time function arguments

(anything I have missed Robert?)

Usual process : 2 weeks for checking out if there are any
critical issues that are likely to prevent successful voting,
write a comment if you need more time for review, focus on API
issues.

[Robert burner Schadek via Digitalmars-d]

Post by Dicebot via Digitalmars-d
http://forum.dlang.org/post/zhvmkbahrqtgkptdlcvh at forum.dlang.org
http://forum.dlang.org/post/vbotavcclttrgvzcjjia at forum.dlang.org
https://github.com/D-Programming-Language/phobos/pull/1500
- new approach for compile-time log level filtering
- thread-safe API (by Marco Leise, commits 3b32618..e71f317)
- documentation enhancements all over the place
- "raw" log overload that expects pre-formatted message and all
metadata (file/line/function) as run-time function arguments
(anything I have missed Robert?)

I added more unittests, but unfortunately didn't find any bugs.
The "raw" log overload is actually a template function that has
one template parameter, the value you want to log.

That's all, I think

[Marco Leise via Digitalmars-d]

This module is going to be the go-to logging in D.
Every other D logging library will extend on it, and libraries
will pass their messages through std.logger's `stdlog`.

It is very important that all of you who plan on using logging
in D or know about specific logger implementations take their
time and see if what they have in mind can be implemented on
the API foundations that std.logger provides. Our community
lacks a real logging guru and needs the collective experience.

If you don't have time to experiment, but believe that some
use case must be covered just describe it in a few words.
(Especially effects on API design, performance or threading.)

[Vladimir Panteleev via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
If you don't have time to experiment, but believe that some
use case must be covered just describe it in a few words.

Two things:

1. Timestamps with millisecond precision or better?

2. Creating one log file per day? I.e. built-in logrotate. If
it's not built-in, would it be difficult to add on top?

[Robert burner Schadek via Digitalmars-d]

On Monday, 29 September 2014 at 10:41:06 UTC, Vladimir Panteleev

Post by Vladimir Panteleev via Digitalmars-d

Post by Marco Leise via Digitalmars-d
If you don't have time to experiment, but believe that some
use case must be covered just describe it in a few words.

1. Timestamps with millisecond precision or better?

You have all that is in Datetime.

Post by Vladimir Panteleev via Digitalmars-d
2. Creating one log file per day? I.e. built-in logrotate. If
it's not built-in, would it be difficult to add on top?

No, as said in the last review thread there are to many solution
on different platforms. But you can build the one you need easily.

[Marco Leise via Digitalmars-d]

Am Mon, 29 Sep 2014 10:41:05 +0000

Post by Vladimir Panteleev via Digitalmars-d
1. Timestamps with millisecond precision or better?
2. Creating one log file per day? I.e. built-in logrotate. If
it's not built-in, would it be difficult to add on top?

Basically your logger gets passed all the basic information
(file, line, function, module, log level, Tid, timestamp as
`SysTime` (up to hnsecs precision), message and the original
logger). You decide how to handle it, whether you pass it on
to another logger, open a file or keep it in memory.

[Dicebot via Digitalmars-d]

On Monday, 29 September 2014 at 10:41:06 UTC, Vladimir Panteleev

Post by Vladimir Panteleev via Digitalmars-d
2. Creating one log file per day? I.e. built-in logrotate. If
it's not built-in, would it be difficult to add on top?

I see logger customization explained in top-level docs of
https://github.com/burner/phobos/blob/logger/std/experimental/logger/core.d
Do you feel something needs to be added there?

[Marco Leise via Digitalmars-d]

The thread-safety changes in short: Every Logger is now taking
a lock when a public method is invoked and then calls the user
overridable methods with the lock taken.

* When you implement a new logger, thread-safety is already
taken care of.
* Taking a lock in a single-threaded context is practically
free compared to the actual logging. (So don't worry.)
* It is not possible to enter a Logger with multiple threads
and provide more fine-grained thread synchronization. In
particular only one thread at a time can call a global log
function like `debug(...)` or `error(...)`.

Note: This is different from the original intention to have
Loggers implement thread safety if they need it and a stopgap
measure looking for use cases that need modifications.

--
Marco

[Kevin Lamonte via Digitalmars-d]

I haven't tested it yet, but have two questions anyway:

1. I did not see any reference to the use of Clock.currTime(),
which on the last round accounted for about 90% of the total time
spent in a log call. Reference:
https://issues.dlang.org/show_bug.cgi?id=13433 . (This is the
difference between logging-and-filtering ~100k logs/sec and ~1M
logs/sec for loggers that use criteria other than logLevel for
filtering messages.) Same question for this cycle: Does
std.logger API need a method for clients or subclasses to
change/defer/omit the call to Clock.currTime? Or defer for a
change in std.datetime?

2. We have Tid in the API. What about Fiber and Thread? If we
can only pick one, I would vote for Thread rather than Tid, as
Tid's currently have no way to be uniquely identified in a
logging message. Reference:
https://issues.dlang.org/show_bug.cgi?id=6989

General comment: very nice to see continued progress!

[Robert burner Schadek via Digitalmars-d]

Post by Kevin Lamonte via Digitalmars-d
1. I did not see any reference to the use of Clock.currTime(),
which on the last round accounted for about 90% of the total
https://issues.dlang.org/show_bug.cgi?id=13433 . (This is the
difference between logging-and-filtering ~100k logs/sec and ~1M
logs/sec for loggers that use criteria other than logLevel for
filtering messages.) Same question for this cycle: Does
std.logger API need a method for clients or subclasses to
change/defer/omit the call to Clock.currTime? Or defer for a
change in std.datetime?

maybe I should add a disableGetSysTime switch

Post by Kevin Lamonte via Digitalmars-d
2. We have Tid in the API. What about Fiber and Thread? If we
can only pick one, I would vote for Thread rather than Tid, as
Tid's currently have no way to be uniquely identified in a
https://issues.dlang.org/show_bug.cgi?id=6989
General comment: very nice to see continued progress!

I'm gone take a closer look

[Marco Leise via Digitalmars-d]

Am Wed, 01 Oct 2014 12:49:29 +0000

Post by Robert burner Schadek via Digitalmars-d
maybe I should add a disableGetSysTime switch

CLOCK_REALTIME_COARSE / CLOCK_REALTIME_FAST should be explored.
On Linux you can't expect finer resolution than the kernel Hz,
for FreeBSD I only found mention of 10ms resolution.
If you format log messages with 2 digits time precision
anyway, you don't need the precise version.

If you disable time completely, what would the LogEntry
contain as the time stamp? SysTime.init?

[Robert burner Schadek via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
Am Wed, 01 Oct 2014 12:49:29 +0000

Post by Robert burner Schadek via Digitalmars-d
maybe I should add a disableGetSysTime switch

CLOCK_REALTIME_COARSE / CLOCK_REALTIME_FAST should be explored.

good pointer, but what about Win and Mac

Post by Marco Leise via Digitalmars-d
If you disable time completely, what would the LogEntry
contain as the time stamp? SysTime.init?

That was my first idea.

[Marco Leise via Digitalmars-d]

Am Wed, 01 Oct 2014 15:05:53 +0000

Post by Robert burner Schadek via Digitalmars-d

Post by Marco Leise via Digitalmars-d
Am Wed, 01 Oct 2014 12:49:29 +0000

Post by Robert burner Schadek via Digitalmars-d
maybe I should add a disableGetSysTime switch

CLOCK_REALTIME_COARSE / CLOCK_REALTIME_FAST should be explored.

good pointer, but what about Win and Mac

Windows 2000 had some function that returns 4ms accurate time,
I hope it is implemented like CLOCK_REALTIME_COARSE.
OS X ... oh well. Don't know. Just declare the "fast timer" a
hint, I guess. Like when you ask for anti-aliasing in OpenGL
and the implementation is free to decide if it can or want's
to deliver. So it turns into: "I need a sub-second
timestamp, but make it as fast as possible on the target OS".
Maybe some day Apple will copy CLOCK_REALTIME_FAST from
FreeBSD.

Post by Robert burner Schadek via Digitalmars-d

Post by Marco Leise via Digitalmars-d
If you disable time completely, what would the LogEntry
contain as the time stamp? SysTime.init?

That was my first idea.

[Steven Schveighoffer via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
Am Wed, 01 Oct 2014 15:05:53 +0000

Post by Robert burner Schadek via Digitalmars-d

Post by Marco Leise via Digitalmars-d
Am Wed, 01 Oct 2014 12:49:29 +0000

Post by Robert burner Schadek via Digitalmars-d
maybe I should add a disableGetSysTime switch

CLOCK_REALTIME_COARSE / CLOCK_REALTIME_FAST should be explored.

good pointer, but what about Win and Mac

Windows 2000 had some function that returns 4ms accurate time,
I hope it is implemented like CLOCK_REALTIME_COARSE.

I think it wouldn't be prudent to explore Windows options until we prove
the windows currTime is slow like the Linux version.

On Mac, gettimeofday is used. I don't know that it's necessarily slow,
but I don't know of a better way to get the wall clock time.

-Steve

[via Digitalmars-d]

On Wednesday, 1 October 2014 at 16:10:41 UTC, Steven

Post by Steven Schveighoffer via Digitalmars-d
I think it wouldn't be prudent to explore Windows options until
we prove the windows currTime is slow like the Linux version.
On Mac, gettimeofday is used. I don't know that it's
necessarily slow, but I don't know of a better way to get the
wall clock time.

x86 has a builtin time stamp counter, executes faster than the
fastest system call.

http://en.wikipedia.org/wiki/Time_Stamp_Counter

http://en.wikipedia.org/wiki/High_Precision_Event_Timer

[Sönke Ludwig via Digitalmars-d]

Post by Robert burner Schadek via Digitalmars-d

Post by Marco Leise via Digitalmars-d
Am Wed, 01 Oct 2014 12:49:29 +0000
If you disable time completely, what would the LogEntry
contain as the time stamp? SysTime.init?

That was my first idea.

It should be noted that SysTime.init.toString() currently crashes (at
least some other methods, too).

[Sönke Ludwig via Digitalmars-d]

Post by Robert burner Schadek via Digitalmars-d

1. I did not see any reference to the use of Clock.currTime(), which
on the last round accounted for about 90% of the total time spent in a
log call. Reference: https://issues.dlang.org/show_bug.cgi?id=13433
. (This is the difference between logging-and-filtering ~100k
logs/sec and ~1M logs/sec for loggers that use criteria other than
logLevel for filtering messages.) Same question for this cycle: Does
std.logger API need a method for clients or subclasses to
change/defer/omit the call to Clock.currTime? Or defer for a change
in std.datetime?

maybe I should add a disableGetSysTime switch

Don't know if this is still the case, but calling Clock.currTime() used
to allocate on each call, whereas Clock.currTime(UTC()) didn't and thus
was orders of magnitudes faster.

[Dicebot via Digitalmars-d]

Post by Kevin Lamonte via Digitalmars-d
2. We have Tid in the API. What about Fiber and Thread? If we
can only pick one, I would vote for Thread rather than Tid, as
Tid's currently have no way to be uniquely identified in a
https://issues.dlang.org/show_bug.cgi?id=6989

In my opinion only solution that scales is to provide same ID as
one used by std.concurrency - it can be thread, fiber, process or
pretty much anything. There are many possible threading
abstractions and all can't be easily supported, makes sense to
stick to one considered standard.

[Kevin Lamonte via Digitalmars-d]

On Wednesday, 1 October 2014 at 10:50:54 UTC, Kevin Lamonte

Post by Kevin Lamonte via Digitalmars-d
2. We have Tid in the API. What about Fiber and Thread? If
we can only pick one, I would vote for Thread rather than Tid,
as Tid's currently have no way to be uniquely identified in a
https://issues.dlang.org/show_bug.cgi?id=6989

In my opinion only solution that scales is to provide same ID
as one used by std.concurrency - it can be thread, fiber,
process or pretty much anything. There are many possible
threading abstractions and all can't be easily supported, makes
sense to stick to one considered standard.

Long-term this sounds very reasonable. But the problem at the
moment is that std.concurrency provides nothing that can be used
to distinguish threads in a log file. Tid cannot be converted to
a unique string or vice versa, nor can one Tid.join() to ensure
that a child Thread has completed before closing the log file(s)
and exiting main(). For boring end-user applications Threads are
today's most common denominator.

Would PR
https://github.com/D-Programming-Language/phobos/pull/1910
provide a way given a Tid to determine: a) What underlying
concurrency model it is using (Thread, Fiber, process, future)?
b) Uniquely identify that structure (Thread ID string, Fiber
address string, process ID, something else)? c) Be capable of
using that identifying immutable (because it needs to be
send()able to another Tid writing to network/file/etc)
string-representable thing to find the original Tid again? A+B
is necessary for using std.logger to debug concurrent
applications, C is a very nice-to-have that comes up periodically.

[Sean Kelly via Digitalmars-d]

Post by Kevin Lamonte via Digitalmars-d
Would PR
https://github.com/D-Programming-Language/phobos/pull/1910
provide a way given a Tid to determine: a) What underlying
concurrency model it is using (Thread, Fiber, process, future)?
b) Uniquely identify that structure (Thread ID string, Fiber
address string, process ID, something else)? c) Be capable of
using that identifying immutable (because it needs to be
send()able to another Tid writing to network/file/etc)
string-representable thing to find the original Tid again? A+B
is necessary for using std.logger to debug concurrent
applications, C is a very nice-to-have that comes up
periodically.

register() is meant to provide a means of referring to a thread.
But the relevant thing there is finding a thread by role, not by
instance. So if a thread doing a known job terminates, a new one
can spawn and register under the same name so proper operation
can continue. Having an identifier for logging is a bit
different. Would using the MessageBox address be sufficient?
I'd be happy to add a Tid.id property that returns a value like
this. I'd rather not try to generate a globally unique
identifier though (that would probably mean a UUID, which is long
and expensive to generate).

[Kevin Lamonte via Digitalmars-d]

Having an identifier for logging is a bit different. Would
using the MessageBox address be sufficient? I'd be happy to
add a Tid.id property that returns a value like this. I'd
rather not try to generate a globally unique identifier though
(that would probably mean a UUID, which is long and expensive
to generate).

I think Tid.id returning the MessageBox address would be fine for
logging purposes. The main value is being able to distinguish
messages coming in at the same time from multiple threads. Even
if a MessageBox address was re-used by a new receive()er after a
previous one exited I doubt it would confuse users very much. I
thing that a doc on Tid.id like "this value will not be the same
as any other Tid currently existing, but might be the same as a
Tid that has exited previously" would be sufficient.

[via Digitalmars-d]

Post by Kevin Lamonte via Digitalmars-d

Having an identifier for logging is a bit different. Would
using the MessageBox address be sufficient? I'd be happy to
add a Tid.id property that returns a value like this. I'd
rather not try to generate a globally unique identifier though
(that would probably mean a UUID, which is long and expensive
to generate).

I think Tid.id returning the MessageBox address would be fine
for logging purposes. The main value is being able to
distinguish messages coming in at the same time from multiple
threads. Even if a MessageBox address was re-used by a new
receive()er after a previous one exited I doubt it would
confuse users very much. I thing that a doc on Tid.id like
"this value will not be the same as any other Tid currently
existing, but might be the same as a Tid that has exited
previously" would be sufficient.

A moving GC can affect the address, too, but for your purpose it
would still be fine, you just mustn't put too much significance
into the actual value.

[deadalnix via Digitalmars-d]

Post by Dicebot via Digitalmars-d
http://forum.dlang.org/post/zhvmkbahrqtgkptdlcvh at forum.dlang.org
http://forum.dlang.org/post/vbotavcclttrgvzcjjia at forum.dlang.org
https://github.com/D-Programming-Language/phobos/pull/1500
- new approach for compile-time log level filtering
- thread-safe API (by Marco Leise, commits 3b32618..e71f317)
- documentation enhancements all over the place
- "raw" log overload that expects pre-formatted message and all
metadata (file/line/function) as run-time function arguments
(anything I have missed Robert?)
Usual process : 2 weeks for checking out if there are any
critical issues that are likely to prevent successful voting,
write a comment if you need more time for review, focus on API
issues.

It has been mentioned in the comment already, but log4j like
approach seems better. Also, it is sad that output range are not
leveraged to format/sample/filter/select output of the logger.

[Robert burner Schadek via Digitalmars-d]

Post by deadalnix via Digitalmars-d
It has been mentioned in the comment already, but log4j like
approach seems better. Also, it is sad that output range are not
leveraged to format/sample/filter/select output of the logger.

yeah log4j is totally awesome and shows IMO how pretty something
can be build on top of std.logger. Even though it uses the
non-range LogEntry from std.logger.

[ponce via Digitalmars-d]

Post by Dicebot via Digitalmars-d
http://forum.dlang.org/post/zhvmkbahrqtgkptdlcvh at forum.dlang.org
http://forum.dlang.org/post/vbotavcclttrgvzcjjia at forum.dlang.org
https://github.com/D-Programming-Language/phobos/pull/1500
- new approach for compile-time log level filtering
- thread-safe API (by Marco Leise, commits 3b32618..e71f317)
- documentation enhancements all over the place
- "raw" log overload that expects pre-formatted message and all
metadata (file/line/function) as run-time function arguments
(anything I have missed Robert?)
Usual process : 2 weeks for checking out if there are any
critical issues that are likely to prevent successful voting,
write a comment if you need more time for review, focus on API
issues.

Upgraded my logger to 0.3.0. I like that I don't have to make
them thread-safe myself.
I vote 'yes' again.

[Marco Leise via Digitalmars-d]

How would I typically log an exception?
I thought of one line per exception in the chain plus a full
trace for the last exception in the chain.

So the messages would be like:
Initialization failed.
Could not load configuration.
File "~/.config/app/settings.ini" no found.
Stack trace (outer to inner):
_Dmain_yadda_yadda+120
Config.__ctor(
)+312


File.__ctor(
)+12

So far so good, but I'm stuck at this line of code (where `e`
is a Throwable):

error(e.msg, e.line, e.file, funcName, prettyFuncName, moduleName);

I don't know how to get at the function and module name where
the exception was thrown. I know this stuff is part of the
symbolic debug information, but I would think it is a common
use case of a logger to log exceptions.

Is it? And if so, what do we want to do about it?

[Kevin Lamonte via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
How would I typically log an exception?

We could add a Throwable reference in LogEntry and some
overrides. But how exception stack traces appear in the output
(multiple lines, all-on-one line, e.msg only, following the
chain, etc.) should not be firmly set here: we can provide a
reasonable baseline in FileLogger, but other Logger subclasses
will definitely want to do different things.

Another issue is that in practice one will often want to log at
debug an exception they are about to throw (libraries), but log
at error anything they actually catch (applications). Should we
include those use cases too? This skirts very close to the
"policy, not mechanism" line, but might be worth it.

Proposal:

LogEntry {
...
Throwable throwable; /// Optional Throwable
bool caught; /// If true, then throwable was
logged via caught/caughtf
}

void throwing(Throwable t, string msg) {...}
void throwingf(Throwable t, string formatMsg, A... args) {...}
void caught(Throwable t, string msg) {...}
void caughtf(Throwable t, string formatMsg, A... args) {...}

Thoughts?

[Robert burner Schadek via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
How would I typically log an exception?
I thought of one line per exception in the chain plus a full
trace for the last exception in the chain.
Initialization failed.
Could not load configuration.
File "~/.config/app/settings.ini" no found.
_Dmain_yadda_yadda+120
Config.__ctor(
)+312


File.__ctor(
)+12
So far so good, but I'm stuck at this line of code (where `e`
error(e.msg, e.line, e.file, funcName, prettyFuncName,
moduleName);
I don't know how to get at the function and module name where
the exception was thrown. I know this stuff is part of the
symbolic debug information, but I would think it is a common
use case of a logger to log exceptions.

I guess that should be part of the Exception. I have no idea how
to get __FUCTION__ of and Exception from inside another function.

Post by Marco Leise via Digitalmars-d
Is it? And if so, what do we want to do about it?

[Sönke Ludwig via Digitalmars-d]

I still think that there should be the two predefined log levels "debug"
(for developer related diagnostics) and "diagnostic" (for end user
related diagnostics) between "trace" and "info". This is important for
interoperability of different libraries, so that they have predictable
debug output.

But independent of that, there should really be a function for safely
generating the user defined intermediate log levels, maybe like this:

LogLevel raiseLevel(LogLevel base_level, ubyte increment)
{
assert(base_level is a valid base level);
assert(base_level + increment smaller than the next base level);
return cast(LogLevel)(base_level + increment);
}

// ok
enum notice = raiseLevel(LogLevel.info, 16);

// error, overlaps with the next base level
enum suspicious = raiseLevel(LogLevel.info, 32);

Casting to an enum type is a pretty blunt operation, so it should at
least be made as safe as possible.

[Robert burner Schadek via Digitalmars-d]

Post by Sönke Ludwig via Digitalmars-d
I still think that there should be the two predefined log
levels "debug" (for developer related diagnostics) and
"diagnostic" (for end user related diagnostics) between "trace"
and "info". This is important for interoperability of different
libraries, so that they have predictable debug output.
But independent of that, there should really be a function for
safely generating the user defined intermediate log levels,
LogLevel raiseLevel(LogLevel base_level, ubyte increment)
{
assert(base_level is a valid base level);
assert(base_level + increment smaller than the next
base level);
return cast(LogLevel)(base_level + increment);
}
// ok
enum notice = raiseLevel(LogLevel.info, 16);
// error, overlaps with the next base level
enum suspicious = raiseLevel(LogLevel.info, 32);
Casting to an enum type is a pretty blunt operation, so it
should at least be made as safe as possible.

from log4d
/// Aliases for debugX and fineX functions
alias debug1 = defaultLogFunction!(Log4DLogger.LOG_LEVEL_DEBUG1);
alias debug2 = defaultLogFunction!(Log4DLogger.LOG_LEVEL_DEBUG2);
alias debug3 = defaultLogFunction!(Log4DLogger.LOG_LEVEL_DEBUG3);

but adding a raiseLevel function should be no problem

[Dicebot via Digitalmars-d]

I don't see critical objections so far and this will move to
voting stage this weekend. Please hurry up if you want to say
something bad :)

[Jakob Ovrum via Digitalmars-d]

Post by Dicebot via Digitalmars-d
I don't see critical objections so far and this will move to
voting stage this weekend. Please hurry up if you want to say
something bad :)

Attributes need to be applied thoroughly. Even if most uses will
be through the base class `Logger`, it's still useful to have
stronger guarantees through a derived class reference. This is
particularly important because it's an important design decision
to choose which attributes to apply to `Logger`'s methods.

@trusted is used everywhere instead of properly using @safe and
minimized @trusted. I think this is the third time I point this
out...

The multiloggers are a complete mess. There's both `ArrayLogger`
and `MultiLogger`, and while `ArrayLogger` has simple O(n)
operations, `MultiLogger` is a disaster: insertion iterates all
elements twice and sorts the entire collection on every call, and
removal iterates all elements once, then does binary search
twice. Once using `SortedRange`'s search, and once using its own
binary search algorithm. It also contains debug code that writes
to stdout. Neither type adheres to the Phobos container concept,
instead the underlying array is exposed as a public, undocumented
field. `string` is used instead of `const(char)[]` for search and
removal operations.

The implementation of `Logger` has several performance problems.
`Logger` provides default behaviour that allocates GC memory
multiple times for even the simplest log messages through the
`Appender`. I don't think this behaviour should be encouraged by
putting it in the root logger class, and besides, it can be made
much more intelligent than just using a new appender for each
message.

Another issue is that the way it's written currently,
`writeLogPart` is called a lot more often than necessary, without
any opportunity for optimization within `formattedWrite`, thus
`FileLogger` is doomed to write to the underlying file
character-by-character in easily reproducible circumstances (e.g.
log a range of characters); this issue probably doesn't affect
the API though.

`Logger` has a bunch of public and documented `*Impl` functions...

Some other line comments I posted a while ago have not been
addressed.

[Robert burner Schadek via Digitalmars-d]

Post by Jakob Ovrum via Digitalmars-d

Post by Dicebot via Digitalmars-d
I don't see critical objections so far and this will move to
voting stage this weekend. Please hurry up if you want to say
something bad :)

Attributes need to be applied thoroughly. Even if most uses
will be through the base class `Logger`, it's still useful to
have stronger guarantees through a derived class reference.
This is particularly important because it's an important design
decision to choose which attributes to apply to `Logger`'s
methods.
@trusted is used everywhere instead of properly using @safe and
out...
The multiloggers are a complete mess. There's both
`ArrayLogger` and `MultiLogger`, and while `ArrayLogger` has
simple O(n) operations, `MultiLogger` is a disaster: insertion
iterates all elements twice and sorts the entire collection on
every call, and removal iterates all elements once, then does
binary search twice. Once using `SortedRange`'s search, and
once using its own binary search algorithm. It also contains
debug code that writes to stdout. Neither type adheres to the
Phobos container concept, instead the underlying array is
exposed as a public, undocumented field. `string` is used
instead of `const(char)[]` for search and removal operations.

The latest std.container.Array broke the code anyway, so it is
due for a rewrite anyway.

Post by Jakob Ovrum via Digitalmars-d
The implementation of `Logger` has several performance
problems. `Logger` provides default behaviour that allocates GC
memory multiple times for even the simplest log messages
through the `Appender`. I don't think this behaviour should be
encouraged by putting it in the root logger class, and besides,
it can be made much more intelligent than just using a new
appender for each message.

Well, to have ultra simple thread-safe sub classing (which is an
important part of the design), this was the price. This being
said. Doing it nogc yourself if you know the output is very easy
as shown in FileLogger.

Post by Jakob Ovrum via Digitalmars-d
Another issue is that the way it's written currently,
`writeLogPart` is called a lot more often than necessary,
without any opportunity for optimization within
`formattedWrite`, thus `FileLogger` is doomed to write to the
underlying file character-by-character in easily reproducible
circumstances (e.g. log a range of characters); this issue
probably doesn't affect the API though.

Again, by design. To allow user created structured logging, this
is necessary.

Post by Jakob Ovrum via Digitalmars-d
`Logger` has a bunch of public and documented `*Impl`
functions...

see my other post

Post by Jakob Ovrum via Digitalmars-d
Some other line comments I posted a while ago have not been
addressed.

I will recheck github

[Marco Leise via Digitalmars-d]

Am Sat, 11 Oct 2014 12:23:10 +0000

Post by Robert burner Schadek via Digitalmars-d

Post by Jakob Ovrum via Digitalmars-d
The implementation of `Logger` has several performance
problems. `Logger` provides default behaviour that allocates GC
memory multiple times for even the simplest log messages
through the `Appender`. I don't think this behaviour should be
encouraged by putting it in the root logger class, and besides,
it can be made much more intelligent than just using a new
appender for each message.

Well, to have ultra simple thread-safe sub classing (which is an
important part of the design), this was the price. This being
said. Doing it nogc yourself if you know the output is very easy
as shown in FileLogger.

I had the same feeling as Jakob about an `Appender` already
in the base class and would have expected a bare bones
abstract class + a batteries included version using `Appender`.
(A bit like Java's 
Listener and 
Adapter classes.)
That seems more clean to me in a representational fashion.
Technically we can just ignore the extra field...
It also seems legit to reduce pressure on the GC, by resetting
the `Appender` instead of nulling it.

[Robert burner Schadek via Digitalmars-d]

Post by Marco Leise via Digitalmars-d
I had the same feeling as Jakob about an `Appender` already
in the base class and would have expected a bare bones
abstract class + a batteries included version using `Appender`.
(A bit like Java's 
Listener and 
Adapter classes.)
That seems more clean to me in a representational fashion.
Technically we can just ignore the extra field...
It also seems legit to reduce pressure on the GC, by resetting
the `Appender` instead of nulling it.

What if a Logger down the chain keeps the string around and you
overwrite it?

[Marco Leise via Digitalmars-d]

Am Sun, 12 Oct 2014 12:07:55 +0000

Post by Robert burner Schadek via Digitalmars-d

Post by Marco Leise via Digitalmars-d
I had the same feeling as Jakob about an `Appender` already
in the base class and would have expected a bare bones
abstract class + a batteries included version using `Appender`.
(A bit like Java's 
Listener and 
Adapter classes.)
That seems more clean to me in a representational fashion.
Technically we can just ignore the extra field...
It also seems legit to reduce pressure on the GC, by resetting
the `Appender` instead of nulling it.

What if a Logger down the chain keeps the string around and you
overwrite it?

That would be bad.

[Jacob Carlborg via Digitalmars-d]

I don't see critical objections so far and this will move to voting
stage this weekend. Please hurry up if you want to say something bad :)

I think it's unacceptable that the documentation of "defaultLogFunction"
and "trace", "info" and so on is merged. Same thing with
"memLogFunctions". Do these even need to be exposed?

[Robert burner Schadek via Digitalmars-d]

On Saturday, 11 October 2014 at 10:48:00 UTC, Jacob Carlborg

Post by Jacob Carlborg via Digitalmars-d

Post by Dicebot via Digitalmars-d
I don't see critical objections so far and this will move to
voting
stage this weekend. Please hurry up if you want to say
something bad :)

I think it's unacceptable that the documentation of
"defaultLogFunction" and "trace", "info" and so on is merged.
Same thing with "memLogFunctions". Do these even need to be
exposed?

this has been used make user defined LogLevel log functions, like

trace1(...), trace2(...)

[Jacob Carlborg via Digitalmars-d]

Post by Robert burner Schadek via Digitalmars-d
this has been used make user defined LogLevel log functions, like
trace1(...), trace2(...)

I still don't like the merge of the documentation.

[Robert burner Schadek via Digitalmars-d]

Post by Dicebot via Digitalmars-d
I don't see critical objections so far and this will move to
voting stage this weekend. Please hurry up if you want to say
something bad :)

MultiLogger got a new simpler impl.

[Ola Fosheim Grostad via Digitalmars-d]

Post by Dicebot via Digitalmars-d
I don't see critical objections so far and this will move to
voting stage this weekend. Please hurry up if you want to say
something bad :)

I don't think I will use it for the reasons I stated in the
previous thread, so no point in saying anything bad.

[Dicebot via Digitalmars-d]

As there was quite some last moment feedback I am giving some
more time for me to research issues a bit and Robert to address
them :)

[Jakob Ovrum via Digitalmars-d]

Post by Dicebot via Digitalmars-d
As there was quite some last moment feedback I am giving some
more time for me to research issues a bit and Robert to address
them :)

The Pareto Principle could be worth mentioning here. We were 80%
of the way to a quality interface a long time ago, but the last
20% is taking a disproportionate amount of time to iron out. I
think all this criticism is indicative that we're holding this
module to a high standard rather than the code being bad, which I
think is a very good thing. Thankfully Marco stepped up and
provided a solution to the threading problem, so I don't think
it's that far off.

Apropos threading though, I'm not sure how to consolidate the
fact that we're using shared memory without using `shared`. It
seems like a failure to have such an intricately designed memory
model, then as soon as we do threading in Phobos, we ignore it.

I still intend to go through all the documentation and fix things
I can spot as soon as the interface is finalized.

[Paolo Invernizzi via Digitalmars-d]

Post by Jakob Ovrum via Digitalmars-d
Apropos threading though, I'm not sure how to consolidate the
fact that we're using shared memory without using `shared`. It
seems like a failure to have such an intricately designed
memory model, then as soon as we do threading in Phobos, we
ignore it.

I've written several times that having the TDPL Concurrency
chapter as a free link in the main page it's some sort of
horrible masochism, granted the current state of the
implementation of what it's described there...

But well ;-/
---
/Paolo

[Robert burner Schadek via Digitalmars-d]

Post by Dicebot via Digitalmars-d
As there was quite some last moment feedback I am giving some
more time for me to research issues a bit and Robert to address
them :)

No need, I fixed the MultiLogger last weekend.

[Jakob Ovrum via Digitalmars-d]

On Wednesday, 15 October 2014 at 09:25:07 UTC, Robert burner

Post by Robert burner Schadek via Digitalmars-d

Post by Dicebot via Digitalmars-d
As there was quite some last moment feedback I am giving some
more time for me to research issues a bit and Robert to
address them :)

No need, I fixed the MultiLogger last weekend.

"Fixed" by simply removing the attempt at logarithmic time
operations, and still not conforming to the Phobos container
interface...

[Robert burner Schadek via Digitalmars-d]

Post by Jakob Ovrum via Digitalmars-d
On Wednesday, 15 October 2014 at 09:25:07 UTC, Robert burner

Post by Robert burner Schadek via Digitalmars-d

Post by Dicebot via Digitalmars-d
As there was quite some last moment feedback I am giving some
more time for me to research issues a bit and Robert to
address them :)

No need, I fixed the MultiLogger last weekend.

"Fixed" by simply removing the attempt at logarithmic time
operations, and still not conforming to the Phobos container
interface...

Yes, because other people already complained that nobody will
every need a logarithmic time MulitLogger and I always thought
that MultiLogger was to complex anyway. I could make the Logger[]
array alias this and it would be comforming to Phobos container,
but that doesn't really solve the issue does it.

[Martin Nowak via Digitalmars-d]

Post by Dicebot via Digitalmars-d
- new approach for compile-time log level filtering

What's new here? It still relies on version identifiers to do so.
As I said in some earlier review, I think it's a bad idea for a library
to rely on version identifiers that are defined in client code.
I will only work for templated code and makes it much harder for build
tools. In a way it's the equivalent of
#define LOG_LEVEL 2
#include <logger.h>

I even proposed an alternative that uses type tags instead.
http://dpaste.dzfl.pl/95fb6a4e086d

Post by Dicebot via Digitalmars-d
Usual process : 2 weeks for checking out if there are any critical
issues that are likely to prevent successful voting, write a comment if
you need more time for review, focus on API issues.

- Documentation is out of sync.
- ArrayLogger seems to do about the same as MultiLogger
- Why do loggers have to be classes?
- Define a concept (isLogger template) with the requirements.
- Add a Logger interface and a loggerObject to wrap structures when
polymorphic loggers are needed.

[Robert burner Schadek via Digitalmars-d]

Post by Martin Nowak via Digitalmars-d

Post by Dicebot via Digitalmars-d
- new approach for compile-time log level filtering

What's new here? It still relies on version identifiers to do
so.
As I said in some earlier review, I think it's a bad idea for a
library to rely on version identifiers that are defined in
client code.
I will only work for templated code and makes it much harder
for build tools. In a way it's the equivalent of
#define LOG_LEVEL 2
#include <logger.h>

All that code is contained in 30 line template, That is by far
the best working option anybody could come up with

Post by Martin Nowak via Digitalmars-d
I even proposed an alternative that uses type tags instead.
http://dpaste.dzfl.pl/95fb6a4e086d

And I showed that it did not work.

Post by Martin Nowak via Digitalmars-d
- Documentation is out of sync.

gh-page is yes, give me 15min

Post by Martin Nowak via Digitalmars-d
- ArrayLogger seems to do about the same as MultiLogger

have you read my reply to Jacob

Post by Martin Nowak via Digitalmars-d
- Why do loggers have to be classes?

As answered multiply times before, to build log hierarchies.

[Jacob Carlborg via Digitalmars-d]

Post by Robert burner Schadek via Digitalmars-d

Post by Martin Nowak via Digitalmars-d
- Why do loggers have to be classes?

As answered multiply times before, to build log hierarchies.

What's stopping an interface or class to implement a logging concept?

[Robert burner Schadek via Digitalmars-d]

Post by Jacob Carlborg via Digitalmars-d

Post by Robert burner Schadek via Digitalmars-d

Post by Martin Nowak via Digitalmars-d
- Why do loggers have to be classes?

As answered multiply times before, to build log hierarchies.

What's stopping an interface or class to implement a logging
concept?

Same as last time:
Logger[], Logger without a LogLevel not real useful IMO, (new) no
thread safety by default