diff --git a/SW.Bitween.Web/BitweenLogging.cs b/SW.Bitween.Web/BitweenLogging.cs new file mode 100644 index 00000000..28d8911d --- /dev/null +++ b/SW.Bitween.Web/BitweenLogging.cs @@ -0,0 +1,277 @@ +using System; +using System.Diagnostics; +using System.Linq; +using System.Text.RegularExpressions; +using System.Text.Json.Nodes; +using System.Text.Json; +using System.Collections.Generic; +using System.Reflection; +using Elastic.Ingest.Elasticsearch; +using Elastic.Ingest.Elasticsearch.DataStreams; +using Elastic.Serilog.Sinks; +using Elastic.Transport; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Nest; +using Serilog; +using Serilog.Events; +using Serilog.Formatting.Compact; + +namespace SW.Bitween.Web +{ + /// + /// Options for , bound from the "SwLogger" + /// configuration section so the names match what the Helm chart already sets + /// (SwLogger__ElasticsearchUrl and friends). + /// + public class BitweenLoggerOptions + { + public const string ConfigurationSection = "SwLogger"; + + /// Serilog's LogEventLevel: 0 Verbose, 1 Debug, 2 Information, 3 Warning. + public int LoggingLevel { get; set; } = 2; + + public string ApplicationName { get; set; } = "unknownapp"; + public string ApplicationVersion { get; set; } + + /// Unset disables the Elasticsearch sink entirely; stdout is unaffected. + public string ElasticsearchUrl { get; set; } + + public string ElasticsearchUser { get; set; } + public string ElasticsearchPassword { get; set; } + + /// + /// Comma-separated environment names that ship to Elasticsearch. An environment absent + /// from this list logs to stdout only, which is how a given deployment opts out. + /// + public string ElasticsearchEnvironments { get; set; } = "Development,Staging,Production"; + + public string ElasticsearchCertificatePath { get; set; } + public int ElasticsearchDeleteIndexAfterDays { get; set; } = 90; + + public bool ShipsToElasticsearch(string environmentName) => + !string.IsNullOrWhiteSpace(ElasticsearchUrl) + && !string.IsNullOrWhiteSpace(ElasticsearchEnvironments) + && ElasticsearchEnvironments + .Split(',') + .Select(e => e.Trim()) + .Contains(environmentName, StringComparer.OrdinalIgnoreCase); + + public string PolicyName => $"{ApplicationName.ToLower()}-policy"; + + /// The data stream the sink writes to; its backing indices are ".ds-{this}-*". + public string DataStreamName(string environmentName) => + $"logs-{ApplicationName.ToLower()}-{environmentName.ToLower()}"; + } + + /// + /// Builds the one Serilog pipeline this service logs through, writing to stdout always and to + /// Elasticsearch where configured. + /// + /// This replaces AddSWConsoleLogger/UseSwElasticSearchLogger rather than calling either. + /// Both of those build a pipeline of their own and only one can win: the Elasticsearch package + /// calls UseSerilog with writeToProviders:false, which silently discards the console package's + /// provider, and its own console sink is hardcoded to plain text. Running both therefore + /// produced no JSON on stdout at all, so the log collector had nothing structured to index. + /// One pipeline with two sinks is what actually lets both destinations work at once. + /// + /// + public static class BitweenLogging + { + public static IServiceCollection AddBitweenLogging( + this IServiceCollection services, + IConfiguration configuration, + IHostEnvironment environment, + Action configure = null) + { + var options = new BitweenLoggerOptions + { + ApplicationVersion = Assembly.GetCallingAssembly().GetName().Version?.ToString() + }; + configure?.Invoke(options); + // Configuration last, so a deployment's environment variables win over code defaults. + configuration.GetSection(BitweenLoggerOptions.ConfigurationSection).Bind(options); + + var logger = new LoggerConfiguration() + .MinimumLevel.Is((LogEventLevel)options.LoggingLevel) + .Enrich.FromLogContext() + .Enrich.WithProperty("Environment", environment.EnvironmentName) + .Enrich.WithProperty("ApplicationVersion", options.ApplicationVersion) + .Enrich.WithProperty("Application", options.ApplicationName); + + // CLEF (compact JSON) is what makes every property queryable once collected. Under a + // debugger nobody is collecting anything, so prefer the line a human can read. + logger = Debugger.IsAttached + ? logger.WriteTo.Console( + outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}") + : logger.WriteTo.Console(new CompactJsonFormatter()); + + if (options.ShipsToElasticsearch(environment.EnvironmentName)) + { + logger = logger.WriteTo.Elasticsearch( + new[] { new Uri(options.ElasticsearchUrl) }, + opts => + { + opts.DataStream = new DataStreamName( + "logs", options.ApplicationName.ToLower(), environment.EnvironmentName); + opts.BootstrapMethod = BootstrapMethod.Failure; + }, + transport => + { + transport.Authentication( + new BasicAuthentication(options.ElasticsearchUser, options.ElasticsearchPassword)); + // Only override validation when a custom authority is supplied. Trusting + // every certificate would expose these credentials and the log stream to + // anyone able to impersonate the Elasticsearch host. + if (!string.IsNullOrWhiteSpace(options.ElasticsearchCertificatePath)) + { + transport.ServerCertificateValidationCallback( + CertificateValidations.AuthorityIsRoot( + new System.Security.Cryptography.X509Certificates.X509Certificate( + options.ElasticsearchCertificatePath))); + } + }); + } + + var serilogLogger = logger.CreateLogger(); + + // After CreateLogger, because the sink writes its index template while bootstrapping + // and the retention setting has to end up on that template. + if (options.ShipsToElasticsearch(environment.EnvironmentName)) + ApplyRetentionPolicy(options, environment.EnvironmentName); + + services.AddSingleton(options); + services.AddSerilog(serilogLogger, dispose: true); + return services; + } + + /// + /// Makes ElasticsearchDeleteIndexAfterDays actually govern how long logs are kept. + /// + /// Elasticsearch never deletes anything on its own. The sink writes to a + /// "logs-{app}-{env}" data stream, and a data stream's backing indices inherit their + /// retention from the composable index template that created them, not from any setting + /// applied to the stream itself. The sink bootstraps that template pointing at + /// Elasticsearch's built-in "logs" policy, which only rolls indices over and has no delete + /// phase, so without this logs accumulate forever. Writing the setting into the template + /// covers every index created from here on; the sweep afterwards covers the ones already + /// on disk, which is what lets an existing deployment adopt a retention policy. + /// + /// + private static void ApplyRetentionPolicy(BitweenLoggerOptions options, string environmentName) + { + var settings = new ConnectionSettings(new Uri(options.ElasticsearchUrl)) + .BasicAuthentication(options.ElasticsearchUser, options.ElasticsearchPassword); + var client = new ElasticClient(settings); + + client.IndexLifecycleManagement.PutLifecycle(options.PolicyName, p => p + .Policy(po => po + .Phases(ph => ph + .Delete(d => d + .MinimumAge($"{options.ElasticsearchDeleteIndexAfterDays}d") + .Actions(a => a.Delete(x => x)))))); + + var stream = options.DataStreamName(environmentName); + var template = FindTemplateFor(client, stream); + if (template != null) PointTemplateAtPolicy(client, template, options.PolicyName); + + // Existing backing indices keep whatever policy they were created with. + Request(client, Elasticsearch.Net.HttpMethod.PUT, $"/.ds-{stream}-*/_settings", + $@"{{""index.lifecycle.name"":""{options.PolicyName}""}}"); + } + + /// Raw Elasticsearch call; returns the body, or null when the call failed. + private static string Request( + IElasticClient client, Elasticsearch.Net.HttpMethod method, string path, string body = null) + { + var response = client.LowLevel.DoRequest( + method, path, Elasticsearch.Net.PostData.String(body ?? string.Empty)); + return response.Success ? response.Body : null; + } + + /// + /// The one index template Elasticsearch would actually apply to the sink's data stream. + /// + /// Several templates can match a name, but only the highest-priority one is used, so that + /// is the only one worth editing. Templates Elasticsearch manages itself are skipped + /// outright: the built-in "logs" template matches "logs-*-*" and therefore covers every + /// service in the cluster, so writing this application's retention into it would quietly + /// take over how everyone else's logs expire. + /// + /// + private static string FindTemplateFor(IElasticClient client, string stream) + { + var response = Request(client, Elasticsearch.Net.HttpMethod.GET, "/_index_template"); + if (response == null) return null; + + using var document = JsonDocument.Parse(response); + if (!document.RootElement.TryGetProperty("index_templates", out var templates)) + return null; + + string winner = null; + var highest = long.MinValue; + + foreach (var entry in templates.EnumerateArray()) + { + var template = entry.GetProperty("index_template"); + + if (template.TryGetProperty("_meta", out var meta) + && meta.TryGetProperty("managed", out var managed) + && managed.ValueKind == JsonValueKind.True) continue; + + var patterns = template.GetProperty("index_patterns").EnumerateArray(); + if (!patterns.Any(pattern => MatchesPattern(pattern.GetString(), stream))) continue; + + var priority = template.TryGetProperty("priority", out var p) ? p.GetInt64() : 0; + if (priority < highest) continue; + + highest = priority; + winner = entry.GetProperty("name").GetString(); + } + + return winner; + } + + private static bool MatchesPattern(string pattern, string value) + { + if (string.IsNullOrEmpty(pattern)) return false; + var regex = "^" + string.Join(".*", pattern.Split('*').Select(Regex.Escape)) + "$"; + return Regex.IsMatch(value, regex, RegexOptions.IgnoreCase); + } + + /// + /// Rewrites one template with the retention setting added, leaving the rest of it — the ECS + /// mappings the sink depends on — exactly as the sink wrote it. + /// + private static void PointTemplateAtPolicy(IElasticClient client, string templateName, string policyName) + { + var current = Request(client, Elasticsearch.Net.HttpMethod.GET, $"/_index_template/{templateName}"); + if (current == null) return; + + var root = JsonNode.Parse(current); + var template = root?["index_templates"]?.AsArray().FirstOrDefault()?["index_template"]; + if (template == null) return; + + var body = template.AsObject(); + var inner = body["template"]?.AsObject(); + if (inner == null) + { + inner = new JsonObject(); + body["template"] = inner; + } + + var indexSettings = inner["settings"]?.AsObject(); + if (indexSettings == null) + { + indexSettings = new JsonObject(); + inner["settings"] = indexSettings; + } + + indexSettings["index.lifecycle.name"] = policyName; + + Request(client, Elasticsearch.Net.HttpMethod.PUT, + $"/_index_template/{templateName}", body.ToJsonString()); + } + } +} diff --git a/SW.Bitween.Web/EdgeRequestIdHttpContextFactory.cs b/SW.Bitween.Web/EdgeRequestIdHttpContextFactory.cs new file mode 100644 index 00000000..d0fd3fbc --- /dev/null +++ b/SW.Bitween.Web/EdgeRequestIdHttpContextFactory.cs @@ -0,0 +1,42 @@ +using System.Linq; +using Microsoft.AspNetCore.Http; +using Microsoft.AspNetCore.Http.Features; + +namespace SW.Bitween.Web +{ + /// + /// Adopts the ingress's X-Request-ID as the request's TraceIdentifier, which is what the + /// logging pipeline reports as RequestId. + /// + /// This has to happen in the context factory rather than in middleware: ASP.NET opens the + /// logging scope that captures RequestId immediately after the context is created and before + /// the middleware pipeline runs, so a middleware assignment lands too late and every log line + /// still carries ASP.NET's own id. That id joins to nothing at the ingress, which is what makes + /// pivoting from a failing HTTP request to this service's logs impossible. + /// + /// + public class EdgeRequestIdHttpContextFactory : IHttpContextFactory + { + private const string EdgeRequestIdHeader = "X-Request-ID"; + + private readonly IHttpContextFactory inner; + + public EdgeRequestIdHttpContextFactory(IHttpContextFactory inner) + { + this.inner = inner; + } + + public HttpContext Create(IFeatureCollection featureCollection) + { + var context = inner.Create(featureCollection); + + var edgeId = context.Request.Headers[EdgeRequestIdHeader] + .FirstOrDefault(value => !string.IsNullOrWhiteSpace(value)); + if (edgeId != null) context.TraceIdentifier = edgeId; + + return context; + } + + public void Dispose(HttpContext httpContext) => inner.Dispose(httpContext); + } +} diff --git a/SW.Bitween.Web/Program.cs b/SW.Bitween.Web/Program.cs index 5d99388a..dd20d090 100644 --- a/SW.Bitween.Web/Program.cs +++ b/SW.Bitween.Web/Program.cs @@ -12,7 +12,6 @@ using SW.Bitween.Services; using SW.EfCoreExtensions; using SW.Logger; -using SW.Logger.ElasticSerach; namespace SW.Bitween.Web { @@ -21,7 +20,7 @@ public class Program public static void Main(string[] args) { //var id = (long)(DateTime.UtcNow.Subtract(new DateTime(2010, 1, 1)).TotalMilliseconds * 1000); - var host = CreateHostBuilder(args).UseSwElasticSearchLogger().Build(); + var host = CreateHostBuilder(args).Build(); // Startup migration failures otherwise surface only as a bare unhandled exception with // no indication of which database was targeted, which makes an environment-specific diff --git a/SW.Bitween.Web/SW.Bitween.Web.csproj b/SW.Bitween.Web/SW.Bitween.Web.csproj index 7b31944d..8980680f 100644 --- a/SW.Bitween.Web/SW.Bitween.Web.csproj +++ b/SW.Bitween.Web/SW.Bitween.Web.csproj @@ -37,8 +37,10 @@ + + @@ -46,7 +48,6 @@ - diff --git a/SW.Bitween.Web/Startup.cs b/SW.Bitween.Web/Startup.cs index b8209361..ded1b37c 100644 --- a/SW.Bitween.Web/Startup.cs +++ b/SW.Bitween.Web/Startup.cs @@ -5,6 +5,7 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Builder; using Microsoft.AspNetCore.Hosting; +using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.ResponseCompression; using Microsoft.EntityFrameworkCore; using Microsoft.Extensions.Configuration; @@ -35,7 +36,6 @@ using SW.Serverless.Resident; using SW.CqApi.AuthOptions; using SW.Logger.Console; -using SW.Logger.ElasticSerach; using Azure.Identity; using Microsoft.Data.SqlClient; using SW.Bitween.NativeAdapters; @@ -94,10 +94,12 @@ public void ConfigureServices(IServiceCollection services) services.AddScoped(); services.AddHostedService(); - services.AddSWConsoleLogger(options => + services.AddBitweenLogging(Configuration, Environment, options => { options.ApplicationName = bitweenOptions.QueuePrefix; }); + services.AddSingleton(sp => + new EdgeRequestIdHttpContextFactory(new DefaultHttpContextFactory(sp))); services.AddBus(config => { @@ -601,7 +603,7 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env) app.UseAuthentication(); app.UseAuthorization(); app.UseHttpAsRequestContext(); - SW.Logger.ElasticSerach.IAppBuilderExtensions.UseRequestContextLogEnricher(app); + SW.Logger.Console.IAppBuilderExtensions.UseRequestContextLogEnricher(app); app.UseSwaggerUI(c => { c.SwaggerEndpoint("/api/swagger.json", "Bitween Api"); });