Review: std.logger

[Jakob Ovrum via Digitalmars-d]

On Thursday, 24 July 2014 at 23:40:56 UTC, Jakob Ovrum wrote:
> 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).

To eloborate on this: using `format` like std.logger currently 
does, for short-lived strings that are consumed and discared 
almost immediately in a higher stack frame, is extremely 
inefficient as every string needs at least one heap memory 
allocation (though `format` can easily do *multiple* in one 
call). It's a good way to quickly thrash and fragment the GC 
heap, putting an extreme amount of stress on the collector.

Even C has fprintf. If we don't provide efficient formatted 
writing, people will not use our abstractions.

The solution is to use `formattedWrite` for custom allocation 
behaviour. When I've used `formattedWrite` for this kind of 
problem before, it has generally come down to the following 
patterns; let's assume the underlying sink is a file:

  * One solution is to use `formattedWrite` to write to the file 
directly. Of course, Logger doesn't provide an interface for 
writing partial log messages, or writing log messages in chunks, 
so this would require modifying the basic API. Also, 
`formattedWrite` doesn't guarantee any minimum chunk size, so in 
the worst case, it might result in one write operation per 
character, which is very inefficient.

* Another solution is to use `formattedWrite` to write to a 
stack-allocated character buffer, then subsequently pass it to 
`writeLogMsg`. This is a leaky abstraction because it puts an 
arbitrary upper limit on how long log entries can be. A practical 
compromise is to revert to a heap allocation for entries that 
don't fit in the stack buffer, but we can do better;

* The best solution is a hybrid one. Use `formattedWrite` to 
write to a stack-allocated buffer, then whenever it's full, write 
the contents of the buffer to the underlying sink (this is easily 
doable by passing a delegate to `formattedWrite` that sees the 
stack buffer as an upvalue). Yes, this does require modifying the 
basic logger API to support partial writes, but it gives us 
optimal performance.

The last solution gives us no dynamic memory allocations unless 
an exception is thrown, while still minimizing the number of 
writes to the underlying sink, which is important when writes can 
be expensive, such as writes to a file or a socket.