Skip to content

Asynchronous Sending for RemoteSyslogAppender #255

@FreeAndNil

Description

@FreeAndNil

Summary

This document proposes an enhancement to the RemoteSyslogAppender in Apache log4net
to resolve severe performance degradation observed under high load conditions due to
synchronous network I/O.

Problem Statement

When using RemoteSyslogAppender in log4net version 3.1.0.0, we observed significant
performance degradation under load, particularly during high throughput API requests in a
production-scale ASP.NET application.
Symptoms:

  • API response time increases drastically with RemoteSyslogAppender enabled.
  • When the appender is disabled, APIs perform consistently faster.
  • The bottleneck was traced to the following line in the Append() method:
    Client.SendAsync(buffer, buffer.Length, RemoteEndPoint).Wait();

Root Cause

  • This line blocks the thread by waiting on an asynchronous UDP send operation.
  • In high-load scenarios, this creates thread contention, as logging becomes I/O-
    bound and synchronous.
  • UDP is inherently unreliable and fast; blocking to wait for its completion defeats
    the purpose and affects overall throughput

Proposed Solution:

Refactor the RemoteSyslogAppender to decouple the UDP send operation from the calling
thread by using a producer-consumer pattern backed by BlockingCollection<byte[]>.

Key Enhancements

  1. Asynchronous Background Worker: A background task consumes queued log
    messages and sends them via UDP.
  2. Non-blocking Logging Path: Append() only queues the message—does not wait for
    UDP transmission.
  3. Graceful Shutdown: Ensures buffered logs are flushed before shutdown.

Code Changes

  private readonly BlockingCollection<byte[]> _sendQueue = new();
  private CancellationTokenSource? _cts;
  private Task? _pumpTask;

  public override void ActivateOptions()
  {
    base.ActivateOptions();
    _cts = new CancellationTokenSource();
    _pumpTask = Task.Run(() => ProcessQueueAsync(_cts.Token), CancellationToken.None);
  }
  
  protected override void OnClose()
  {
    _cts?.Cancel();
    _pumpTask?.Wait(TimeSpan.FromSeconds(5));
    base.OnClose();
  }

  protected override void Append(LoggingEvent loggingEvent)
  {
    var buffer = FormatMessage(loggingEvent); // Assuming your existing logic
    _sendQueue.Add(buffer);
  }

  private async Task ProcessQueueAsync(CancellationToken token)
  {
    // We create our own UdpClient here, so that client lifetime is tied to this task
    using (var udp = new UdpClient())
    {
      udp.Connect(RemoteAddress?.ToString(), RemotePort);

      try
      {
        while (!token.IsCancellationRequested)
        {
          // Take next message or throw when cancelled
          byte[] datagram = _sendQueue.Take(token);
          try
          {
            await udp.SendAsync(datagram, datagram.Length);
          }
          catch (Exception ex) when (!ex.IsFatal())
          {
            ErrorHandler.Error("RemoteSyslogAppender: send failed", ex, ErrorCode.WriteFailure);
          }
        }
      }
      catch (OperationCanceledException)
      {
        // Clean shutdown: drain remaining items if desired
        while (_sendQueue.TryTake(out var leftover))
        {
          try { await udp.SendAsync(leftover, leftover.Length); }
          catch { /* ignore */ }
        }
      }
    }
  }

Technical Justification

  • BlockingCollection with a dedicated task ensures high throughput and thread
    safety.
  • UdpClient.SendAsync() is naturally asynchronous and works well in an async context.
  • This pattern avoids .Wait() and prevents thread pool starvation under high loads.
  • Maintains the contract of RemoteSyslogAppender without changing external
    behavior.

Performance Evidence

Environment:

  • .NET framework 4.7.2 application
  • log4net 3.1.0.0
  • Remote syslog server running on a separate host
  • Load test using Apache JMeter with 200 concurrent users

Test Configuration

  • Tool: Apache JMeter
  • API Endpoint: High-throughput production endpoint
  • Threads: 1000
  • Ramp-Up Period: 100 seconds
  • Request Rate: 10 requests/second

Scenario 1: Default log4net with RemoteSyslogAppender Enabled

(Synchronous.Wait())

Metric Value
Average Response Time 120590
Minimum Response Time 6322
Maximum Response Time 167883
Errors/Failures Some API errors due to timeouts or long waits

Issues Observed

RemoteSyslogAppender causes the API thread to block due to .Wait(),
resulting in slow responses.

Scenario 2: log4net with Asynchronous RemoteSyslogAppender (Proposed Change)

Metric (for major api ConnectDesktop call) Value
Average Response Time 2866
Minimum Response Time 1134
Maximum Response Time 8052
Errors/Failures Some API errors due to long waits

Observation:

Avg, min max time taken is improved and less with With Async Queueing 10req/sec
(thread 1000, ramp up 100sec) as compare to results with the Default log4net (sync
.Wait())

Summary

The proposed update improves the performance and responsiveness of applications using
RemoteSyslogAppender, especially under load. By adopting an asynchronous, queue-based
architecture, we eliminate the unnecessary blocking behavior caused by .Wait(), aligning
better with modern asynchronous .NET patterns.

Next Steps:

We respectfully request the following actions from the log4net maintainers:

  • Review the proposed enhancement for performance improvement in
    RemoteSyslogAppender.
  • Verify compatibility with existing appender behavior.
  • Incorporate the fix in the next official release of log4net.

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions