LoggingMiddleware.cs

using Coscine.ApiCommons.Utils;
using Coscine.Configuration;
using Coscine.Logging;
using Microsoft.AspNetCore.Diagnostics;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Http.Internal;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Primitives;
using System;
using System.IO;
using System.Linq;
using System.Text;
using System.Threading.Tasks;

namespace Coscine.ApiCommons.Middleware
{
    public class LoggingMiddleware
    {
        private readonly RequestDelegate _next;
        private readonly CoscineLogger _coscineLogger;

        public LoggingMiddleware(ILogger<LoggingMiddleware> logger, RequestDelegate next)
        {
            _next = next;
            _coscineLogger = new CoscineLogger(logger);
        }

        public async Task Invoke(HttpContext context)
        {
            string _uri = "";
            string _request = "";
            string _requestBody = "";
            string _responseBody = "";
            string _statusCode = "";

            using (MemoryStream requestBodyStream = new MemoryStream())
            {
                using (MemoryStream responseBodyStream = new MemoryStream())
                {
                    Stream originalRequestBody = context.Request.Body;
                    Stream originalResponseBody = context.Response.Body;

                    var debugLevelIsActive = CoscineLoggerConfiguration.IsLogLevelActivated(LogType.Debug);

                    if (debugLevelIsActive)
                    {
                        context.Request.EnableRewind();
                    }
                    try
                    {
                        /*******************************************
                         * logging process
                         ******************************************/

                        // reading of the request header
                        _uri = $"{context.Request.Scheme}://{context.Request.Host}{context.Request.Path}{context.Request.QueryString}";
                        _request = $"Uri: {_uri} Method: {context.Request.Method}";

                        CoscineLoggerMetadata.SetUri(_uri);

                        // Get the User Id
                        var authorization = context.Request.Headers["Authorization"].ToArray();
                        string bearer = null;
                        foreach (var line in authorization)
                        {
                            if (line.Contains("Bearer"))
                            {
                                bearer = line;
                            }
                        }
                        if (!string.IsNullOrWhiteSpace(bearer))
                        {
                            bearer = bearer.Replace("Bearer", "").Trim();
                            JWTHandler jwtHandler = new JWTHandler(new ConsulConfiguration());
                            var claims = jwtHandler.GetContents(bearer);
                            var userClaim = (from claimObj in claims
                                             where claimObj.Type == "UserId"
                                             select claimObj).First();
                            CoscineLoggerMetadata.SetUserId(userClaim.Value);
                        }

                        // Get the corrolation Id
                        context.Request.Headers.TryGetValue("X-Coscine-Logging-CorrelationId", out StringValues clientCorrolationId);
                        if (clientCorrolationId.Count == 1)
                        {
                            CoscineLoggerMetadata.SetClientCorrolationId(clientCorrolationId.ToString());
                        }
                        CoscineLoggerMetadata.SetCorrolationId();                        

                        /*******************************************
                         * preparation of the logging process
                         ******************************************/
                        if (debugLevelIsActive)
                        {
                            // write a log entry if fields are missing
                            if (!(context.Request.Method.Equals("GET") || context.Request.Method.Equals("DELETE")) && (context.Request.ContentType == null || context.Request.ContentType == ""))
                            {
                                _coscineLogger.Log(LogType.Debug, $"{_request} No MimeType specified for Request.");
                            }
                            // only log short requests or request that contain json
                            if (context.Request.ContentLength < 500000 || (context.Request.ContentType != null && context.Request.ContentType.Contains("json")))
                            {
                                context.Request.Body.CopyTo(requestBodyStream);
                                requestBodyStream.Seek(0, SeekOrigin.Begin);

                                _requestBody = new StreamReader(requestBodyStream).ReadToEnd();

                                requestBodyStream.Seek(0, SeekOrigin.Begin);
                                context.Request.Body = requestBodyStream;
                            }
                            else
                            {
                                _requestBody = "No Request Body or Request Body to long.";
                            }

                            _coscineLogger.Log(LogType.Debug, $"{_request} RequestBody: {_requestBody}");
                            _responseBody = "Default Response Body";
                            context.Response.Body = responseBodyStream;
                        }

                        /*******************************************
                         * processing of the request
                         ******************************************/

                        await _next(context);

                        /*******************************************
                         * processing of the response
                         ******************************************/

                        _statusCode = $"{context.Response.StatusCode}";
                        CoscineLoggerMetadata.SetStatus(_statusCode);

                        // log every message on high that has a non 200-399 StatusCode
                        if (context.Response.StatusCode < StatusCodes.Status200OK || context.Response.StatusCode >= StatusCodes.Status400BadRequest)
                        {
                            _coscineLogger.Log(LogType.High, $"{_request} StatusCode: {_statusCode}");
                        }

                        if (debugLevelIsActive && context.Response.StatusCode != StatusCodes.Status204NoContent)
                        {
                            // Write a log entry if fields are missing
                            if (context.Response.ContentType == null || context.Response.ContentType == "")
                            {
                                _coscineLogger.Log(LogType.Debug, $"{_request} No MimeType specified for Response.");
                            }

                            // only log short responses or responses that return json
                            if (context.Response.ContentLength < 500000 || (context.Response.ContentType != null && context.Response.ContentType.Contains("json")))
                            {
                                responseBodyStream.Seek(0, SeekOrigin.Begin);
                                _responseBody = new StreamReader(responseBodyStream).ReadToEnd();
                            }
                            else
                            {
                                _responseBody = "No Response Body or Response Body to long.";
                            }
                            
                            responseBodyStream.Seek(0, SeekOrigin.Begin);
                            await responseBodyStream.CopyToAsync(originalResponseBody);
                        }
                        _coscineLogger.Log(LogType.Debug, $"{_request} RequestBody: {_requestBody} StatusCode: {_statusCode} ResponseBody: {_responseBody}");

                    }
                    catch (Exception ex)
                    {
                        _coscineLogger.Log(LogType.Critical, $"An uncaught Exception occured while processing the request: {_request}", ex);
                        if (!context.Response.HasStarted)
                        {
                            context.Response.StatusCode = StatusCodes.Status500InternalServerError;
                            byte[] data = System.Text.Encoding.UTF8.GetBytes("Unhandled Error occured. Please, try again in a while.");
                            context.Response.ContentLength = data.Length;
                            originalResponseBody.Write(data, 0, data.Length);
                        }
                    }
                    finally
                    {
                        context.Request.Body = originalRequestBody;
                        if (context.Response.StatusCode != StatusCodes.Status204NoContent)
                        {
                            context.Response.Body = originalResponseBody;
                        }
                    }
                }
            }
        }
    }
}