Merge pull request #69 from ucdavis/swe/ElasticLogging

Add elastic logging

src/AD419/AD419.csproj

@@ -14,6 +14,14 @@
     <PackageReference Include="Microsoft.AspNetCore.Authentication.OpenIdConnect" Version="6.0.3" />
     <PackageReference Include="Microsoft.AspNetCore.SpaServices.Extensions" Version="6.0.3" />
     <PackageReference Include="Microsoft.Data.SqlClient" Version="4.1.0" />
+		<PackageReference Include="Serilog" Version="2.10.0"/>
+		<PackageReference Include="Serilog.AspNetCore" Version="4.1.0"/>
+		<PackageReference Include="Serilog.Enrichers.ClientInfo" Version="1.1.4"/>
+		<PackageReference Include="Serilog.Exceptions" Version="8.0.0"/>
+		<PackageReference Include="Serilog.Extensions.Logging" Version="3.1.0"/>
+		<PackageReference Include="Serilog.Sinks.Console" Version="4.0.1"/>
+		<PackageReference Include="serilog.sinks.elasticsearch" Version="8.4.1"/>
+    <PackageReference Include="Serilog.ThrowContext" Version="0.1.2" />
   </ItemGroup>
   <ItemGroup>
     <!-- Don't publish the SPA source files, but do show them in the project files list -->

src/AD419/Logging/CorrelationIdMiddleware.cs

@@ -0,0 +1,37 @@
+using System;
+using System.Collections.Generic;
+using System.Threading.Tasks;
+using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
+
+namespace AD419.Logging
+{
+    public class CorrelationIdMiddleware
+    {
+        public const string HeaderKey = "X-Correlation-Id";
+
+        private readonly RequestDelegate _next;
+        private readonly ILogger _logger;
+
+        public CorrelationIdMiddleware(RequestDelegate next, ILoggerFactory loggerFactory)
+        {
+            _next = next;
+            _logger = loggerFactory.CreateLogger<CorrelationIdMiddleware>();
+        }
+
+        public async Task Invoke(HttpContext context)
+        {
+            // generate new id
+            var id = Guid.NewGuid().ToString();
+
+            // append to response header
+            context.Response.OnStarting(() =>
+            {
+                context.Response.Headers.Add(HeaderKey, id);
+                return Task.CompletedTask;
+            });
+
+            await _next(context);
+        }
+    }
+}

src/AD419/Logging/SerilogHttpContextEnricher.cs

@@ -0,0 +1,75 @@
+using System;
+using System.Collections.Concurrent;
+using Microsoft.AspNetCore.Http;
+using Microsoft.AspNetCore.Mvc.Controllers;
+using Microsoft.AspNetCore.Mvc.ModelBinding;
+using Serilog.Core;
+using Serilog.Events;
+
+namespace AD419.Logging
+{
+    public class SerilogHttpContextEnricher : ILogEventEnricher
+    {
+        private readonly IHttpContextAccessor _contextAccessor;
+        private bool _enriching = false;
+
+        public SerilogHttpContextEnricher(IHttpContextAccessor contextAccessor)
+        {
+            _contextAccessor = contextAccessor;
+        }
+
+        public SerilogHttpContextEnricher()
+        {
+            _contextAccessor = new HttpContextAccessor();
+        }
+
+        public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
+        {
+            if (_enriching)
+            {
+                // Prevent infinite recursion that can happen when accessing certain properties, like ISession.Id
+                return;
+            }
+            try
+            {
+                _enriching = true;
+                var httpContext = _contextAccessor.HttpContext;
+                if (httpContext == null)
+                    return;
+
+                // Set HttpContext properties
+                AddOrUpdateProperty(httpContext, logEvent, propertyFactory, "User", () => httpContext.User?.Identity?.Name);
+                AddOrUpdateProperty(httpContext, logEvent, propertyFactory, "TraceId", () => httpContext.TraceIdentifier);
+                AddOrUpdateProperty(httpContext, logEvent, propertyFactory, "EndpointName", () => httpContext.GetEndpoint()?.DisplayName);
+                AddOrUpdateProperty(httpContext, logEvent, propertyFactory, "ResponseContentType", () => httpContext.Response?.ContentType?.ToString());
+                AddOrUpdateProperty(httpContext, logEvent, propertyFactory, "CorrelationId", () => httpContext.Response?.Headers?[CorrelationIdMiddleware.HeaderKey]);
+            }
+            finally
+            {
+                _enriching = false;
+            }
+        }
+
+        private static void AddOrUpdateProperty(HttpContext httpContext, LogEvent logEvent, ILogEventPropertyFactory factory,
+            string propertyName, Func<object> getValue, string defaultValue = "unknown", bool destructure = true)
+        {
+            // Values retrieved from httpContext can go into and out of scope depending on where in the execution
+            // pipeline logging occurs. We want to hold onto the most up-to-date value that is not defaultValue.
+            var itemKey = $"SERILOG_CUSTOM_{propertyName}";
+            var value = getValue();
+            if (httpContext.Items[itemKey] is ValueTuple<object, LogEventProperty> item)
+            {
+                if (value == null || item.Item1 == value)
+                {
+                    logEvent.AddOrUpdateProperty(item.Item2);
+                    return;
+                }
+            }
+
+            var newValue = value ?? defaultValue;
+            var newProperty = factory.CreateProperty(propertyName, newValue, destructure);
+            httpContext.Items[itemKey] = (newValue, newProperty);
+            logEvent.AddOrUpdateProperty(newProperty);
+        }
+    }
+}

src/AD419/Program.cs

@@ -1,23 +1,89 @@
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.Linq;
 using System.Threading.Tasks;
+using AD419.Logging;
 using Microsoft.AspNetCore.Hosting;
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.Hosting;
 using Microsoft.Extensions.Logging;
+using Serilog;
+using Serilog.Events;
+using Serilog.Exceptions;
+using Serilog.Sinks.Elasticsearch;
+using Serilog.ThrowContext;
 
 namespace AD419
 {
     public class Program
     {
-        public static void Main(string[] args)
+        public static int Main(string[] args)
         {
-            CreateHostBuilder(args).Build().Run();
+#if DEBUG
+            Serilog.Debugging.SelfLog.Enable(msg => Debug.WriteLine(msg));
+#endif
+            var isDevelopment = string.Equals(Environment.GetEnvironmentVariable("ASPNETCORE_ENVIRONMENT"), "development", StringComparison.OrdinalIgnoreCase);
+            var builder = new ConfigurationBuilder()
+                .SetBasePath(System.IO.Directory.GetCurrentDirectory())
+                .AddJsonFile("appsettings.json")
+                .AddEnvironmentVariables();
+
+            //only add secrets in development
+            if (isDevelopment)
+            {
+                builder.AddUserSecrets<Program>();
+            }
+            var configuration = builder.Build();
+            var loggingSection = configuration.GetSection("Serilog");
+
+            var loggerConfig = new LoggerConfiguration()
+                .MinimumLevel.Debug()
+                .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
+                // .MinimumLevel.Override("Microsoft.EntityFrameworkCore", LogEventLevel.Warning) // uncomment this to hide EF core general info logs
+                .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
+                .MinimumLevel.Override("System", LogEventLevel.Warning)
+                .Enrich.With<ThrowContextEnricher>()
+                .Enrich.FromLogContext()
+                .Enrich.WithClientIp()
+                .Enrich.WithClientAgent()
+                .Enrich.WithExceptionDetails()
+                .Enrich.WithProperty("Application", loggingSection.GetValue<string>("AppName"))
+                .Enrich.WithProperty("AppEnvironment", loggingSection.GetValue<string>("Environment"))
+                .Enrich.With<SerilogHttpContextEnricher>()
+                .WriteTo.Console();
+
+            // add in elastic search sink if the uri is valid
+            if (Uri.TryCreate(loggingSection.GetValue<string>("ElasticUrl"), UriKind.Absolute, out var elasticUri))
+            {
+                loggerConfig.WriteTo.Elasticsearch(new ElasticsearchSinkOptions(elasticUri)
+                {
+                    IndexFormat = "aspnet-ad419-ea-{0:yyyy.MM}"
+                });
+            }
+
+            Log.Logger = loggerConfig.CreateLogger();
+
+            try
+            {
+                Log.Information("Starting up");
+                CreateHostBuilder(args).Build().Run();
+                return 0;
+            }
+            catch (Exception ex)
+            {
+                Log.Fatal(ex, "Application start-up failed");
+                return 1; // indicate abnormal termination
+            }
+            finally
+            {
+                Log.CloseAndFlush();
+            }
         }
 
         public static IHostBuilder CreateHostBuilder(string[] args) =>
             Host.CreateDefaultBuilder(args)
+                .UseSerilog()
                 .ConfigureWebHostDefaults(webBuilder =>
                 {
                     webBuilder.UseStartup<Startup>();

src/AD419/Startup.cs

@@ -1,3 +1,4 @@
+using AD419.Logging;
 using AD419.Services;
 using Microsoft.AspNetCore.Authentication;
 using Microsoft.AspNetCore.Authentication.Cookies;
@@ -11,6 +12,7 @@
 using Microsoft.Extensions.Hosting;
 using Microsoft.IdentityModel.Protocols.OpenIdConnect;
 using Microsoft.IdentityModel.Tokens;
+using Serilog;
 
 namespace AD419
 {
@@ -48,6 +50,7 @@ public void ConfigureServices(IServiceCollection services)
 
 
             services.AddControllersWithViews();
+            services.AddHttpContextAccessor();
 
             // In production, the React files will be served from this directory
             services.AddSpaStaticFiles(configuration =>
@@ -62,6 +65,9 @@ public void ConfigureServices(IServiceCollection services)
         // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
         public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
         {
+            app.UseSerilogRequestLogging();
+            app.UseMiddleware<CorrelationIdMiddleware>();
+
             if (env.IsDevelopment())
             {
                 app.UseDeveloperExceptionPage();

src/AD419/appsettings.json

@@ -12,5 +12,10 @@
     "ClientId": "[external]",
     "ClientSecret": "[external]",
     "Authority": "https://ssodev.ucdavis.edu/cas/oidc"
+  },
+  "Serilog": {
+    "AppName": "AD419ExpenseAssociation",
+    "Environment": "[External]",
+    "ElasticUrl": "[External]"
   }
 }