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.

Reply via email to