I am currently implementing a logging module, I want to make logging to stderr/stdout/"any file" possible, also during runtime-shutdown (logging from dtors)

Atm it lookes like this:

----
void log(LogLevel level, Args...)(Args args) {
    string message = format(args);

    ... pass string to writer
}
---

But format allocates! That makes it throw an InvalidMemoryOperationError when calling the logging function from a dtor. So I need a GC-free writer for std.format.formattedWrite, similiar to std.stdio's LockingTextWriter but with a buffer instead of a file (std.array.Appender GC free something like that). I couldn't come up with a working solution, I hope you have ideas.

On Feb 8, 2013, at 7:57 AM, David <d@dav1d.de> wrote:

> I am currently implementing a logging module, I want to make logging to stderr/stdout/"any file" possible, also during runtime-shutdown (logging from dtors)
> 
> Atm it lookes like this:
> 
> ----
> void log(LogLevel level, Args...)(Args args) {
>    string message = format(args);
> 
>    ... pass string to writer
> }
> ---
> 
> But format allocates! That makes it throw an InvalidMemoryOperationError when calling the logging function from a dtor. So I need a GC-free writer for std.format.formattedWrite, similiar to std.stdio's LockingTextWriter but with a buffer instead of a file (std.array.Appender GC free something like that). I couldn't come up with a working solution, I hope you have ideas.

Does your IO layer require one call per log line or can you do multiple writes followed by an "end log line" terminator?  Assuming the former, the most obvious approach would be for the writer to have a static array equal to the max log line size, accumulate until done and then issue one write to the output layer.

On Fri, 08 Feb 2013 16:57:39 +0100, David wrote:
> I am currently implementing a logging module, I want to make logging to stderr/stdout/"any file" possible, also during runtime-shutdown (logging from dtors)
> 
> Atm it lookes like this:
> 
> ----
> void log(LogLevel level, Args...)(Args args) {
>     string message = format(args);
> 
>     ... pass string to writer
> }
> ---

Will this module be published for others to use?  If so, can I suggest a feature?

One thing that's really important with logging, but rarely available, is not levels, but code areas.  I believe python, for example, allows you to name log sections:

    logger("mainsection.subsection.subsubsection1", "message1")
    logger("mainsection.subsection.subsubsection2", "message2")

and then you can enable, say, everything related to "subsection", but then filter out everything in "subsubsection2".

That's really important, when debugging/auditing complex apps, without actually wanting to modify the code just to find out what's going on. Especially since modifying the code can CHANGE what's going on.


-- 
Lee

Am 08.02.2013 22:53, schrieb Lee Braiden:
> On Fri, 08 Feb 2013 16:57:39 +0100, David wrote:
>> I am currently implementing a logging module, I want to make logging to stderr/stdout/"any file" possible, also during runtime-shutdown (logging from dtors)
>>
>> Atm it lookes like this:
>>
>> ----
>> void log(LogLevel level, Args...)(Args args) {
>>     string message = format(args);
>>
>>     ... pass string to writer
>> }
>> ---
> 
> Will this module be published for others to use?  If so, can I suggest a feature?
> 
> One thing that's really important with logging, but rarely available, is not levels, but code areas.  I believe python, for example, allows you to name log sections:
> 
>     logger("mainsection.subsection.subsubsection1", "message1")
>     logger("mainsection.subsection.subsubsection2", "message2")
> 
> and then you can enable, say, everything related to "subsection", but then filter out everything in "subsubsection2".
> 
> That's really important, when debugging/auditing complex apps, without actually wanting to modify the code just to find out what's going on. Especially since modifying the code can CHANGE what's going on.
> 
> 

Well, here it is: https://github.com/Dav1dde/BraLa/blob/master/brala/utils/log.d

You can't name section, but you can create loggers with different names. But this actually a good idea (design is similiar, but less complex and powerful, to logbook http://packages.python.org/Logbook/ )

> Does your IO layer require one call per log line or can you do multiple writes followed by an "end log line" terminator?
> Assuming the former, the most obvious approach would be for the writer to have a static array equal to the max log line size,
> accumulate until done and then issue one write to the output layer.

I don't understand, you mean I should pass `args` directly to the writer? I tried it, ended up with linker errors, since writer is an interface:

----
interface IWriter {
    void log(LogLevel level, string name, const(char)[] message);
    @property bool bubbles();
    @property void bubbles(bool);
}
----

So I have to pass a string around, which isn't a big deal, until the runtime shuts down.


jA_cOp pointed me to std.string.sformat on IRC, I tried it with a stack-allocated buffer, unfortunatly it seems to allocate somewhere:

----
#0  0x00000000015cc4dc in onInvalidMemoryOperationError ()
#1  0x00000000015b53d2 in gc.gcx.GC.mallocNoSync() ()
#2  0x00000000015b534b in gc.gcx.GC.malloc() ()
#3  0x000000000157d569 in gc_malloc ()
#4  0x000000000157fcbb in _d_allocmemory ()
#5  0x00000000008f0f7b in char[] std.string.sformat!(char, void*,
immutable(char)[], uint).sformat(char[], const(char[]), void*,
immutable(char)[], uint)
----

So this is also no solution, since I wasn't able to find the origin of this allocation (it's not because an error is thrown, well very unlikely, formatting with the same arguments at "runtime" works)