[log] static log util

[Alice52]

app settings config root level

"Logging": {
    "ApplicationInsights": {
      "LogLevel": {
        "Default": "Information",
        "System": "Information",
        "Microsoft": "Information",
        "Microsoft.EntityFrameworkCore": "Warning"
      }
    },
    "LogLevel": {
      "Default": "Information",
      "System": "Information",
      "Microsoft": "Information",
      "Microsoft.EntityFrameworkCore": "Warning"
    }
  }

nlog config

elements: use the following elements to customize the log config for scenarios.

1. targets – defines log targets/outputs
2. rules – defines log routing rules
3. extensions – loads NLog extensions from the *.dll file
4. include– includes an external configuration file
5. variable – sets the value of a configuration variable

Rules

1. name – logger name filter - may include wildcard characters *, ?
2. minlevel – minimal level to log
3. maxlevel – maximum level to log
4. level, levels
5. writeTo – targets to write to
6. final – no rules are processed after a final rule matches
7. enabled - set to false to disable the rule without deleting it

Customize Rules with Wildcard *, ?

1. disable LINQ in log

 <!-- rules to map from logger name to target -->
<rules>
    <logger name="*" minlevel="Trace" writeTo="allfile"/>

    <logger name="Microsoft.EntityFrameworkCore.Model.Validation" minlevel="Warn" final="true"/>
    <logger name="Microsoft.EntityFrameworkCore.Database.Command" minlevel="Info" final="true"/>
    <logger name="*" minlevel="Info" writeTo="infofile"/>
</rules>

Target

1. name - name of the target
2. layout - text to be rendered
3. encoding
4. archiveAboveSize - size in bytes, and above it, log files will be automatically archived.
5. maxArchiveFiles - max number of archive files, and above it, log files will be automatically rolled.
6. archiveFileName - name of archive file
7. archiveNumbering - way file archives are numbered, recommend use Rolling, which is numbering
8. archiveOldFileOnStartup - auto-archive old log file on startup
9. fileName - named file to write to
10. createDirs
11. concurrentWrites - concurrent writes to same log file and default true
12. keepFileOpen - keep log file open instead of opening and closing it on each logging event and default: false
13. enableArchiveFileCompression - compress the archive files into the zip files, and default false

Customize Roll

1. daily roll:

   • fileName: can use the parameter to daily roll

   fileName="${logDirectory}/${serviceName}-${shortdate}-all.log"

2. size roll:

   • archiveAboveSize: Size in bytes

     archiveAboveSize="20000000"

   • maxArchiveFiles: max file number for each fileName

     maxArchiveFiles="50"

     according by combination of fileName, such as xxx-2019-12-27-info.log if this log size more than 20M, it will be backed and renamed with xxx-2019-12-27-infoINTEGER.log

Level:

1. Trace
2. Debug
3. Info
4. Warn
5. Error
6. Fatal
7. Off

Sample

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true" internalLogLevel="info" internalLogFile="Log\internal-nlog.log">

    <!-- log file directory -->
    <variable name="logDirectory" value="Log"/>

    <!-- log file name prefix -->
    <variable name="serviceName" value="xxxx"/>

    <!-- enable asp.net core layout renderers -->
    <extensions>
        <add assembly="NLog.Web.AspNetCore"/>
    </extensions>

    <!-- the targets to write to -->
    <targets async="true">
        <!-- write logs to file  -->
        <target xsi:type="File" name="tracefile" fileName="${logDirectory}/${serviceName}-${shortdate}-trace.log" archiveAboveSize="20000000" archiveNumbering="Rolling" maxArchiveFiles="50" concurrentWrites="false" keepFileOpen="false" encoding="utf-8" createDirs="true" layout="${longdate}|${pad:padding=-5:inner=${level:uppercase=true}}|thread-${threadid}|${logger}|${message} ${exception:format=tostring}" />
        <target xsi:type="File" name="infofile" fileName="${logDirectory}/${serviceName}-${shortdate}-info.log" archiveAboveSize="20000000" archiveNumbering="Rolling" maxArchiveFiles="50" concurrentWrites="false" keepFileOpen="false" encoding="utf-8" createDirs="true" layout="${longdate}|${pad:padding=-5:inner=${level:uppercase=true}}|thread-${threadid}|${logger}|${message} ${exception:format=tostring}" />
        <target xsi:type="File" name="errorfile" fileName="${logDirectory}/${serviceName}-${shortdate}-error.log" archiveAboveSize="20000000" archiveNumbering="Rolling" maxArchiveFiles="50" concurrentWrites="false" keepFileOpen="false" encoding="utf-8" createDirs="true" layout="${longdate}|${pad:padding=-5:inner=${level:uppercase=true}}|thread-${threadid}|${logger}|${message} ${exception:format=tostring}" />
        <target xsi:type="File" name="accessfile" fileName="${logDirectory}/${serviceName}-${shortdate}-access.log" archiveAboveSize="20000000" archiveNumbering="Rolling" maxArchiveFiles="50" concurrentWrites="false" keepFileOpen="false" encoding="utf-8" createDirs="true" layout="${longdate}|${pad:padding=-5:inner=${level:uppercase=true}}|thread-${threadid}|${message}"/>
    </targets>

    <!-- rules to map from logger name to target -->
    <rules>
        <!--All logs, including from Microsoft-->
        <logger name="*" minlevel="Trace" writeTo="tracefile" />
        <logger name="*" minlevel="Error" writeTo="errorfile" />
        <logger name="Microsoft.AspNetCore.Hosting.Internal.WebHost" minlevel="Trace" writeTo="accessfile" />

        <!-- this is also can be disbled in app settings by change root level of efcore class -->
        <logger name="Microsoft.EntityFrameworkCore.Model.Validation" minlevel="Warn" final="true" />
        <logger name="Microsoft.EntityFrameworkCore.Database.Command" minlevel="Info" final="true"/>
        <logger name="*" minlevel="Info" writeTo="infofile" />
    </rules>
</nlog>

---

log utils code, which is controlled in nlog

1. get log object from IOC container

logger = LogManager.GetLogger(loggerName);

2. custom static class sample

using System.Text;
using System;
using System.Collections.Generic;
using System.Diagnostics;
using NLog;
using RestSharp;
using System.Text.RegularExpressions;
using System.Linq;
using Newtonsoft.Json;

namespace Augmentum.Foundation.Core.Utils
{
    public class LogUtil
    {
        protected const string TRACE_LEVEL = "TRACE";
        protected const string DEBUG_LEVEL = "DEBUG";
        protected const string INFO_LEVEL = "INFO";
        protected const string WARN_LEVEL = "WARN";
        protected const string ERROR_LEVEL = "ERROR";
        protected const string FATAL_LEVEL = "FATAL";

        private static IDictionary<string, Logger> Loggers = new Dictionary<string, Logger>();

        #region common log
        public static void Trace<T>(T value)
        {
            WriteLog(value, TRACE_LEVEL);
        }
        public static void Debug<T>(T value)
        {
            WriteLog(value, DEBUG_LEVEL);
        }
        public static void Info<T>(T value)
        {
            WriteLog(value, INFO_LEVEL);
        }
        public static void Warn<T>(T value)
        {
            WriteLog(value, WARN_LEVEL);
        }
        public static void Error<T>(T value)
        {
            WriteLog(value, ERROR_LEVEL);
        }
        public static void Fatal<T>(T value)
        {
            WriteLog(value, FATAL_LEVEL);
        }
        #endregion

        #region log rest request and response
        public static void LogRestRequest(string requestUrl, IRestRequest request, object requestData)
        {
            // Masks the PIN.
            var maskedServiceUrl = Regex.Replace(requestUrl, "(authentication/.+?/).+?$", "$1****");

            var sb = new StringBuilder();

            sb.AppendLine(String.Format(@"{0} {1} HTTP/1.1", request.Method, maskedServiceUrl));

            foreach (var parameter in request.Parameters.Where(x => x.Type == ParameterType.HttpHeader))
            {
                sb.AppendFormat("{0}: {1}\r\n", parameter.Name, parameter.Value);
            }

            var data = JsonConvert.SerializeObject(requestData, Formatting.Indented);

            sb.AppendLine(data);

            Debug(sb.ToString());

        }

        public static void LogRestResponse(string requestUrl, IRestResponse response)
        {
            // Masks the PIN.
            var maskedServiceUrl = Regex.Replace(requestUrl, "(authentication/.+?/).+?$", "$1****");

            var sb = new StringBuilder();

            sb.AppendLine(maskedServiceUrl);
            sb.AppendFormat("HTTP/1.1 {0} {1}\r\n", (int)response.StatusCode, response.StatusDescription);

            foreach (var parameter in response.Headers)
            {
                sb.AppendFormat("{0}: {1}\r\n", parameter.Name, parameter.Value);
            }

            sb.AppendLine(response.Content);

            Debug(sb.ToString());
        }
        #endregion

        #region private method
        private static void WriteLog<T>(T value, string level)
        {
            Logger logger = GetLogger();
            if (logger == null)
            {
                throw new Exception("Error occurred during initialize logger");
            }
            switch (level)
            {
                case TRACE_LEVEL:
                    logger.Trace(value);
                    break;
                case DEBUG_LEVEL:
                    logger.Debug(value);
                    break;
                case INFO_LEVEL:
                    logger.Info(value);
                    break;
                case WARN_LEVEL:
                    logger.Warn(value);
                    break;
                case ERROR_LEVEL:
                    logger.Error(value);
                    break;
                case FATAL_LEVEL:
                    logger.Fatal(value);
                    break;
                default:
                    logger.Info(value);
                    break;
            }
        }
        private static string GetLoggerName()
        {
            StackTrace stackTrace = new StackTrace(4, true);
            StackFrame stackFrame = stackTrace.GetFrame(0);
            var method = stackFrame.GetMethod();
            StringBuilder stringBuilder = new StringBuilder();
            stringBuilder.Append(stackFrame.GetMethod().DeclaringType.FullName)
                .Append("-")
                .Append(stackFrame.GetMethod().Name)
                .AppendFormat("[{0}]", stackFrame.GetFileLineNumber());
            return stringBuilder.ToString();
        }

        private static Logger GetLogger()
        {
            Logger logger = null;
            string loggerName = GetLoggerName();
            Loggers.TryGetValue(loggerName, out logger);
            if (logger == null)
            {
                logger = LogManager.GetLogger(loggerName);
                Loggers.Add(loggerName, logger);
            }
            return logger;
        }
        #endregion
    }
}

3. use Middleware to log, and should inspect in startup as singleton

• startup register and inject to IOC container

app.UseMiddleware<LoggingMiddleWare>();

services.AddSingleton<LoggingMiddleWare>();

• Middleware implement

public class LoggingMiddleWare : IMiddleware
{
    private static string[] ignoreHeader = {
        "Sec-Fetch-Dest",
        "Sec-Fetch-Site",
        "Sec-Fetch-Mode",
        "Sec-Fetch-Dest",
        "Cookie",
        "Connection"
    };
    public async Task InvokeAsync(HttpContext context, RequestDelegate next)
    {
        try
        {
            var request = context.Request;
            string serviceUrl = GetRequestUrl(request);
            LogRequest(serviceUrl, request);
            var requestStartTime = DateTime.Now;
            var originalResponseBodyStream = context.Response.Body;
            using(var responseBody = new MemoryStream())
            {
                var response = context.Response;
                response.Body = responseBody;
                await next(context);
                var requestEndTime = DateTime.Now;
                TimeSpan timeSpan = requestEndTime - requestStartTime;
                response.Body.Seek(0, SeekOrigin.Begin);
                LogResponse(serviceUrl, response, timeSpan);
                await responseBody.CopyToAsync(originalResponseBodyStream);
            }
        }
        catch
        {
            await next(context);
        }

    }

    private string GetRequestUrl(HttpRequest request)
    {
        StringBuilder content = new StringBuilder();
        content.Append(request.Method + " ")
                .Append(request.Scheme + "://")
                .Append(request.Host)
                .Append(request.Path + " ")
                .Append(request.Protocol);
        return content.ToString();
    }
    private async void LogResponse(string serviceUrl, HttpResponse response, TimeSpan timeSpan)
    {
        StringBuilder content = new StringBuilder();
        content.AppendLine(serviceUrl)
                .AppendFormat("StatusCode: " + response.StatusCode)
                .AppendLine();
        var responseHeader = response.Headers;
        var headerIterator = responseHeader.GetEnumerator();
        while(headerIterator.MoveNext())
        {
            var currentItem = headerIterator.Current;
            if(Array.IndexOf(ignoreHeader, currentItem.Key) != -1) continue;
            content.Append(currentItem.Key + ": ")
                    .AppendLine(currentItem.Value.ToString());
        }
        var responseBody = await new StreamReader(response.Body).ReadToEndAsync();
        var responseBodyFormatSettings = new JsonSerializerSettings{ Formatting = Formatting.Indented };
        string formatresponseBody = JsonUtil.FormatJsonString(responseBody, responseBodyFormatSettings);
        content.AppendFormat("ResponseBody: {0}", formatresponseBody)
                .AppendLine()
                .AppendFormat("Requested Take: {0}ms", timeSpan.TotalMilliseconds)
                .AppendLine();
        response.Body.Seek(0, SeekOrigin.Begin);
        LogUtil.Info(content.ToString());
    }

    private async void LogRequest(string serviceUrl, HttpRequest request)
    {
        StringBuilder content = new StringBuilder();
        content.AppendLine(serviceUrl);

        var requestHeader = request.Headers;
        var headerIterator = requestHeader.GetEnumerator();
        while(headerIterator.MoveNext())
        {
            var currentItem = headerIterator.Current;
            if(Array.IndexOf(ignoreHeader, currentItem.Key) != -1) continue;
            content.Append(currentItem.Key + ": ")
                    .AppendLine(currentItem.Value.ToString());
        }

        request.EnableRewind();
        var requestBodyBuffer = new byte[Convert.ToInt32(request.ContentLength)];
        await request.Body.ReadAsync(requestBodyBuffer, 0, requestBodyBuffer.Length);
        var requestBody = Encoding.UTF8.GetString(requestBodyBuffer);
        request.Body.Seek(0, SeekOrigin.Begin);

        var requestBodyFormatSettings = new JsonSerializerSettings{ Formatting = Formatting.Indented };
        string formatRequestBody = JsonUtil.FormatJsonString(requestBody, requestBodyFormatSettings);
        content.AppendFormat("RequestBody: {0}", formatRequestBody);
        LogUtil.Info(content.ToString());
    }
}

reference

1. https://nlog-project.org/config/
2. https://github.com/nlog/NLog/wiki/Configuration-file
3. https://github.com/NLog/NLog/wiki/File-target