Nlog Doesn't Work Correctly In Dotnetty Handler

Question

I wrote a Dotnetty server and used Nlog as the logging framework. Every connection has its own ID and I want to log this ID alongside other data(message, Datetime, etc...) to Sql. As Dotnetty handles multiple connections by single thread, using mdlc/ndlc to log ID caused incorrect data to log (By incorrect I mean one connection ID logged with another connection data). I can use logevent properties but I have to pass the connection ID to each class/method I want to log inside. Any suggestion ?

this is Custom Logger

 public void SetFlowmeterSerial(long? flowmeterSerial)
    {
        MappedDiagnosticsLogicalContext.Set("Serial",flowmeterSerial);
    }

    public long GetSerialNumber()
    {
      return   Convert.ToInt64(MappedDiagnosticsLogicalContext.Get("Serial"));


    }

NLogConfig for database

public static void DataBaseTarget(LogLevel min, LogLevel max, LoggingConfiguration config, string 
name,string connectionString,string databaseName)
    {
        var greDateTime = TimeCodec.Trim(DateTime.Now,TimeSpan.TicksPerSecond);
        var persianDateTime = TimeCodec.GreToPersianDateTime(greDateTime);
        var sqlFormattedDateTime = greDateTime.ToString("yyyy-MM-dd HH:mm:ss.fff");
        var databaseTarget = new DatabaseTarget
        {
            ConnectionString = connectionString,//"server=.;database=FlowMeterSimulatorLOG;integrated security=sspi",
            DBProvider = "System.Data.SqlClient",
            DBDatabase = databaseName,//"FlowMeterSimulatorLOG",
            DBHost = ".",
            CommandText =
                $"insert into SystemLog (FlowMeterSerial,GreDateTime,PersianDateTime,Level,CallSite,Message,ExceptionType,ExceptionMessage,StackTrace)values(@FlowMeterSerial,'{sqlFormattedDateTime}','{persianDateTime}',@Level,@CallSite,@Message,@ExceptionType,@ExceptionMessage,@StackTrace);",
        };
        var param = new DatabaseParameterInfo { Name = "@Level", Layout = "${level}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@CallSite", Layout = "${callsite}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@Message", Layout = "${message}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@ExceptionType", Layout = "${exception:format=type}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@ExceptionMessage", Layout = "${exception:format=message}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@StackTrace", Layout = "${exception:format=stackTrace}" };
        databaseTarget.Parameters.Add(param);
        param = new DatabaseParameterInfo { Name = "@FlowMeterSerial", Layout = "${mdlc:item=Serial}" };
        databaseTarget.Parameters.Add(param);

        config.AddRule(min, max, databaseTarget);
        LogManager.Configuration = config;
    }

Dotnetty Handler

    public class LogHandler : ChannelHandlerAdapter
{
    private readonly CustomLogger _logger = (CustomLogger) LogManager.GetCurrentClassLogger(typeof(CustomLogger));

    //private static readonly ILogger _logger = LogManager.GetCurrentClassLogger();
    private long _serialNumber;

    public override void ChannelRead(IChannelHandlerContext context, object message)
    {
        if (!(message is IByteBuffer buffer))
            throw new ArgumentException();
        var deviceInfo = context.Channel.GetAttribute(ProcessHandler.DeviceInfo).Get();
        if (deviceInfo != null)
            _serialNumber = deviceInfo.Serial;
        _logger.SetFlowmeterSerial(_serialNumber);
        _logger?.Debug(
            $"Received: {ByteBufferUtil.HexDump(buffer)}");
        base.ChannelRead(context, message);
    }

    public override async Task WriteAsync(IChannelHandlerContext context, object message)
    {
        try
        {
            if (!(message is IByteBuffer buffer)) throw new ArgumentException();
            try
            {
                //_logger.SetFlowmeterSerial(_serialNumber);
                _logger?.Debug(
                    $"Sent: {ByteBufferUtil.HexDump(buffer)}");
                await base.WriteAsync(context, message).ConfigureAwait(false);
            }
            catch
            {
                if (buffer.ReferenceCount != 0) buffer.Release();
                throw;
            }
        }
        catch (Exception e)
        {
            context.FireExceptionCaught(e);
            //await Task.FromException(e);
        }
    }

}

I have Other Handlers Like This For Processing Data and Log them.

score 0 · Answer 1 · answered Jan 04 '20 at 12:25

I have never used Netty, so just trying to read the documentation:

https://netty.io/5.0/api/io/netty/channel/ChannelHandlerContext.html

Then you should use the IChannelHandlerContext for handling context information (Like CorrelationId, RequestId, etc.).

Constantly trying to keep the NLog MDLC in sync with the active netty-context will probably be fragile. Maybe just implement helper logger-methods that gets netty-context as input? Ex.:

public override void ChannelRead(IChannelHandlerContext context, object message)
{
    LogDebug(context, "Read");
    base.ChannelRead(context, message);
}

public override async Task WriteAsync(IChannelHandlerContext context, object message)
{
    LogDebug(context, "Write");
    await base.WriteAsync(context, message).ConfigureAwait(false);
}

private void LogDebug(IChannelHandlerContext context, string mesage)
{
    var deviceInfo = context.Channel.GetAttribute(ProcessHandler.DeviceInfo).Get();
    if (deviceInfo != null)
       _logger.WithProperty("FlowMeterSerial", deviceInfo.Serial).Debug(message);
    else
       _logger.Debug(mesage);
}

Anyway just a random suggestion. Know nothing about Java-Netty or Dot-Netty.

Nlog Doesn't Work Correctly In Dotnetty Handler

1 Answers1