log4net.tools 1.4.0

The ForwardingAppenderAsync wrapps any log4net appender putting the async buffer in front. The independent background worker is responsible for dequeuing of items from the buffer without blocking a client app.

Thus waiting needing before for example to write a log in a database is delegated now and the only place where the client app is blocking is the stage of the in-memory enqueuing.

The 'Dequeue' graph reflects the latency in microseconds of the RollingFileAppender (taken just as example) which works under the hood as the attached synchronous appender. A consumer is blocked only during the 'Enqueue' microseconds.

The approach allows:

• to get the minimal blocking of the client app;
• to turn any 'old' synchronous appender into the 'async' version easily without additional coding or recompile;
• to eliminate concurrent waits on the internal lock section as the background worker is singlethreaded if no pooling is used;
• to build aggregations over the buffer. For example, to drop log duplicates or generate stats on the fly.

Configurable logic:

• handling the buffer overflow situation
• closing behavior

XML Configuration

The example of the minimal configuration:

<appender name="ForwardingAppenderAsync" type="log4net.tools.ForwardingAppenderAsync">
    <appender-ref ref="RollingFileAppender" />
</appender>

The example of the advanced configuration:

<appender name="ForwardingAppenderAsync" type="log4net.tools.ForwardingAppenderAsync">
    <BufferSize value="1000"/>
    <Fix value="260"/>
    <BufferOverflowBehaviour value="RejectNew"/>
    <BufferClosingType value="DumpToLog"/>
    <WorkerPoolSize value="5"/>

    <appender-ref ref="DebugAppender" />
    <appender-ref ref="RollingFileAppender" />
    <appender-ref ref="AdoNetAppender" />
</appender>

More examples of the xml configuration are available here.

RollingFileAppender Benchmark

10K of sequential info-logs:

10K of "parallel" (Parallel.For) info-logs:

AdoNetAppender Benchmark

10K of sequential info-logs:

10K of "parallel" (Parallel.For) info-logs:

Worker Pool

The worker pool allows to improve throughput between the buffer and the attached appenders as it allows to dequeue the cached logs in parallel.

For example, the test with the RollingFileAppender shows the difference in intencity of 'dequeue' events:

The latency is on the same level. We observe that more workers generate the denser 'Dequeue' graph.

The buffer size grows not as steep as with the single threaded configuration as several workers together are more productive in processing of the benchmark stress load.

The 'WorkerPoolSize' configuration property defines the level of parallelism. The default value is '1' which corresponds to the 'single worker' scenario.

ForwardingAppenderAsyncWithMetrics

The appender grabs the metrics: LatencyUs, BufferSize, AllocatedBytes in addition to the ForwardingAppenderAsync functionality. The default output is Trace Info. Metrics bring some additional load so it is recommended to use the ForwardingAppenderAsync in scenarios where the minimum latency is required.

The example of the minimal xml configuration:

<appender name="Forwarding2RollingFileAppenderWithMetrics" type="log4net.tools.ForwardingAppenderAsyncWithMetrics, log4net.tools">
    <appender-ref ref="RollingFileAppender" />
</appender>

The example above uses "Trace" channel to output the metrics.

The example of the advanced xml configuration:

<appender name="Forwarding2RollingFileAppenderWithMetrics" type="log4net.tools.ForwardingAppenderAsyncWithMetrics, log4net.tools">
    <MetricsWriter type="log4net.tools.integration.MetricsCsvWriter, log4net.tools.integration">
        <CsvFilePath value="data.csv"/>
        <MaxRowCount value="100000"/>
    </MetricsWriter> 

    <BufferSize value="1000"/>
    <Fix value="260"/>
    <BufferOverflowBehaviour value="RejectNew"/>
    <BufferClosingType value="DumpToLog"/>
    <WorkerPoolSize value="5"/>

    <appender-ref ref="DebugAppender" />
    <appender-ref ref="RollingFileAppender" />
    <appender-ref ref="AdoNetAppender" />
</appender>

MetricsCsvWriter is available in the log4net.tools.integration package.

The example of the output:

DateTime            ,LatencyUs ,BufferSize ,CallerName ,AllocatedBytes
2021-05-04T11:49:22 ,2.00      ,76         ,DoAppend   ,5491168
2021-05-04T11:49:22 ,2.80      ,77         ,DoAppend   ,5587296
2021-05-04T11:49:22 ,318.80    ,77         ,Dequeue    ,5684840
2021-05-04T11:49:22 ,2.40      ,77         ,DoAppend   ,1269424
2021-05-04T11:49:22 ,2.50      ,78         ,DoAppend   ,1367776
2021-05-04T11:49:22 ,2.00      ,79         ,DoAppend   ,1466128
2021-05-04T11:49:22 ,2.30      ,80         ,DoAppend   ,1564480
2021-05-04T11:49:22 ,1.50      ,81         ,DoAppend   ,1662832
2021-05-04T11:49:22 ,273.80    ,81         ,Dequeue    ,1752992

The python notebook to analyze the metrics.