Changed logging into structured format

SS14.Labeller/GitHubApi/GitHubApiClient.cs

@@ -6,7 +6,7 @@
 
 namespace SS14.Labeller.GitHubApi;
 
-public class GitHubApiClient(HttpClient httpClient) : IGitHubApiClient
+public class GitHubApiClient(HttpClient httpClient, ILogger<GitHubApiClient> logger) : IGitHubApiClient
 {
     private const string BaseUrl = "https://api.github.com";
 
@@ -17,7 +17,10 @@ public async Task AddLabel(string owner, string repoName, int number, LabelBase
         var json = JsonSerializer.Serialize(request, SourceGenerationContext.Default.AddLabelRequest);
         var content = new StringContent(json, Encoding.UTF8, "application/json");
 
-        await httpClient.PostAsync($"{BaseUrl}/repos/{owner}/{repoName}/issues/{number}/labels", content, ct);
+        await SendAndLogErrorsAsync(
+            () => httpClient.PostAsync(IssueUrl(owner, repoName, number, "labels"), content, ct),
+            "add label",
+            ct);
     }
 
     public Task AddLabel(GithubRepo repo, int number, LabelBase label, CancellationToken ct)
@@ -28,7 +31,10 @@ public Task AddLabel(GithubRepo repo, int number, LabelBase label, CancellationT
     /// <inheritdoc />
     public async Task RemoveLabel(string owner, string repoName, int number, LabelBase label, CancellationToken ct)
     {
-        await httpClient.DeleteAsync($"{BaseUrl}/repos/{owner}/{repoName}/issues/{number}/labels/{Uri.EscapeDataString(label)}", ct);
+        await SendAndLogErrorsAsync(
+            () => httpClient.DeleteAsync(IssueUrl(owner, repoName, number, $"labels/{Uri.EscapeDataString(label)}"), ct),
+            "remove label",
+            ct);
     }
 
     public Task RemoveLabel(GithubRepo repo, int number, LabelBase label, CancellationToken ct)
@@ -45,11 +51,12 @@ public async Task<List<string>> GetChangedFiles(GithubRepo repo, int prNumber, C
         var page = 1;
         while (true)
         {
-            var res = await httpClient.GetAsync($"{BaseUrl}/repos/{repo.Owner.Login}/{repo.Name}/pulls/{prNumber}/files?per_page=100&page={page}", ct);
-            if (!res.IsSuccessStatusCode)
-                break; // TODO: Logging?
+            var url = RepoUrl(repo.Owner.Login, repo.Name, $"pulls/{prNumber}/files?per_page=100&page={page}");
+            var response = await SendAndLogErrorsAsync(() => httpClient.GetAsync(url, ct), "get changed files", ct);
+            if (!response.IsSuccessStatusCode)
+                break;
 
-            var content = await res.Content.ReadAsStringAsync(ct);
+            var content = await response.Content.ReadAsStringAsync(ct);
             var json = JsonDocument.Parse(content);
             var batch = json.RootElement.EnumerateArray().Select(f => f.GetProperty("filename").GetString()!).ToList();
             if (batch.Count == 0) break;
@@ -66,13 +73,14 @@ public async Task<List<string>> GetChangedFiles(GithubRepo repo, int prNumber, C
     /// <inheritdoc />
     public async Task<bool> IsMaintainer(string? user, GithubRepo repo, CancellationToken ct)
     {
-        var permRes = await httpClient.GetAsync($"{BaseUrl}/repos/{repo.Owner.Login}/{repo.Name}/collaborators/{user}/permission", ct);
-        if (!permRes.IsSuccessStatusCode)
+        var url = RepoUrl(repo.Owner.Login, repo.Name, $"collaborators/{user}/permission");
+        var response = await SendAndLogErrorsAsync(() => httpClient.GetAsync(url, ct), "IsMaintainer check", ct);
+        if (!response.IsSuccessStatusCode)
         {
-            throw new Exception("Failed to get permissions! Does the github token have enough access?");
+            throw new HttpRequestException("Failed to get permissions! Does the github token have enough access?");
         }
 
-        var permJson = JsonDocument.Parse(await permRes.Content.ReadAsStringAsync(ct));
+        var permJson = JsonDocument.Parse(await response.Content.ReadAsStringAsync(ct));
         var requestedPermission = permJson.RootElement.GetProperty("permission").GetString();
         return requestedPermission is "write" or "admin";
     }
@@ -83,7 +91,10 @@ public async Task AddComment(GithubRepo repo, int number, string comment, Cancel
         var json = JsonSerializer.Serialize(request, SourceGenerationContext.Default.AddCommentRequest);
         var content = new StringContent(json, Encoding.UTF8, "application/json");
 
-        await httpClient.PostAsync($"{BaseUrl}/repos/{repo.Owner.Login}/{repo.Name}/issues/{number}/comments", content, ct);
+        await SendAndLogErrorsAsync(
+            () => httpClient.PostAsync(IssueUrl(repo.Owner.Login, repo.Name, number, "update comments"), content, ct),
+            "AddComment",
+            ct);
     }
 
     public async Task<List<IssueComment>> GetComments(GithubRepo repo, int prNumber, CancellationToken ct)
@@ -93,15 +104,15 @@ public async Task<List<IssueComment>> GetComments(GithubRepo repo, int prNumber,
 
         while (true)
         {
-            var res = await httpClient.GetAsync(url, ct);
-            if (!res.IsSuccessStatusCode)
-                break; // TODO: Logging?
+            var response = await SendAndLogErrorsAsync(() => httpClient.GetAsync(url, ct), "get comments", ct);
+            if (!response.IsSuccessStatusCode)
+                break;
 
-            var json = await res.Content.ReadAsStringAsync(ct);
+            var json = await response.Content.ReadAsStringAsync(ct);
             var comments = (IssueComment[])JsonSerializer.Deserialize(json, typeof(IssueComment[]), SourceGenerationContext.DeserializationContext)!;
             allComments.AddRange(comments);
 
-            if (res.Headers.TryGetValues("Link", out var linkHeaders))
+            if (response.Headers.TryGetValues("Link", out var linkHeaders))
             {
                 var links = linkHeaders.FirstOrDefault();
                 url = ParseNextPageUrl(links);
@@ -114,6 +125,36 @@ public async Task<List<IssueComment>> GetComments(GithubRepo repo, int prNumber,
         return allComments;
     }
 
+    private async Task<HttpResponseMessage> SendAndLogErrorsAsync(
+        Func<Task<HttpResponseMessage>> send,
+        string operation,
+        CancellationToken ct)
+    {
+        var response = await send();
+
+        if (response.IsSuccessStatusCode)
+            return response;
+
+        var body = await response.Content.ReadAsStringAsync(ct);
+        logger.LogError(
+            "GitHub API request '{Operation}' failed with status {StatusCode}: {Body}",
+            operation,
+            (int)response.StatusCode,
+            body);
+
+        return response;
+    }
+
+    private static string RepoUrl(string owner, string repoName, string path)
+    {
+        return $"{BaseUrl}/repos/{owner}/{repoName}/{path}";
+    }
+
+    private static string IssueUrl(string owner, string repoName, int number, string subPath)
+    {
+        return RepoUrl(owner, repoName, $"issues/{number}/{subPath}");
+    }
+
     private static string? ParseNextPageUrl(string? linkHeader)
     {
         if (string.IsNullOrEmpty(linkHeader))

SS14.Labeller/Program.cs

@@ -1,11 +1,6 @@
 using Dapper;
-using Microsoft.AspNetCore.Mvc;
-using Microsoft.Extensions.Options;
-using SS14.Labeller.Configuration;
+using Serilog;
 using SS14.Labeller.Endpoints;
-using SS14.Labeller.Handlers;
-using SS14.Labeller.Middlewares;
-using SS14.Labeller.Models;
 
 [module:DapperAot]
 
@@ -21,9 +16,6 @@ public static void Main(string[] args)
         builder.Configuration.AddJsonFile("appsettings.Secret.json", true, true);
         builder.Configuration.AddJsonFile($"appsettings.{builder.Environment.EnvironmentName}.json", true, true);
 
-        builder.Logging.ClearProviders();
-        builder.Logging.AddConsole();
-
         builder.Services.RegisterDependencies(builder.Configuration);
 
         var app = builder.Build();
@@ -34,5 +26,7 @@ public static void Main(string[] args)
         app.MapGithubWebhook();
 
         app.Run();
+
+        Log.CloseAndFlush();
     }
 }

SS14.Labeller/Registry.cs

@@ -9,13 +9,20 @@
 using System.Net.Http.Headers;
 using Polly;
 using Polly.Extensions.Http;
+using Serilog;
 
 namespace SS14.Labeller;
 
 public static class Registry
 {
     public static void RegisterDependencies(this IServiceCollection service, IConfiguration configuration)
     {
+        Log.Logger = new LoggerConfiguration().ReadFrom.Configuration(configuration)
+                                              .Enrich.WithProperty("ApplicationName", "SS14.Labeller") // TODO: move to AppSettings.json when NAOT will be removed
+                                              .CreateLogger();
+
+        service.AddSerilog();
+
 #pragma warning disable IL2026
         service.AddOptions<DiscourseConfig>()
                .Bind(configuration.GetSection(DiscourseConfig.Name))

SS14.Labeller/SS14.Labeller.csproj

@@ -21,5 +21,17 @@
       <PackageReference Include="Dapper.AOT" Version="1.0.48" />
       <PackageReference Include="Microsoft.Data.Sqlite" Version="9.0.8" />
       <PackageReference Include="Microsoft.Extensions.Http.Polly" Version="9.0.8" />
+      <PackageReference Include="Serilog" Version="4.4.0" />
+      <PackageReference Include="Serilog.Extensions.Hosting" Version="9.0.0" />
+      <PackageReference Include="Serilog.Sinks.Console" Version="6.1.1" />
+      <PackageReference Include="Serilog.Settings.Configuration" Version="9.0.0" />
     </ItemGroup>
+
+    <!-- Serilog's config-driven logging (ReadFrom.Configuration) instantiates sinks and formatters from
+         strings in appsettings.json via reflection; root those assemblies so trimming/AOT keeps them. -->
+    <ItemGroup>
+      <TrimmerRootAssembly Include="Serilog.Sinks.Console" />
+      <TrimmerRootAssembly Include="SS14.Labeller" />
+    </ItemGroup>
+
 </Project>

SS14.Labeller/SerilogNAOTSafeJsonConsoleFormatter.cs

@@ -0,0 +1,165 @@
+using System.Buffers;
+using System.Globalization;
+using System.Text;
+using System.Text.Json;
+using Serilog.Events;
+using Serilog.Formatting;
+
+namespace SS14.Labeller;
+
+/// <summary>
+/// Writes Serilog events as newline-delimited compact JSON,
+/// using the Serilog compact schema (@t, @m, @l, @x, @tr, @sp and the event's own properties).
+/// Built only on <see cref="System.Text.Json"/>, so it stays compatible with Native AOT publishing.
+/// REPLACE IT with default one when NAOT will be removed.
+/// </summary>
+public sealed class SerilogNAOTSafeJsonConsoleFormatter : ITextFormatter
+{
+    public void Format(LogEvent logEvent, TextWriter output)
+    {
+        var buffer = new ArrayBufferWriter<byte>();
+
+        using (var writer = new Utf8JsonWriter(buffer))
+        {
+            writer.WriteStartObject();
+
+            writer.WriteString("Timestamp", logEvent.Timestamp.UtcDateTime.ToString("O", CultureInfo.InvariantCulture));
+            writer.WriteString("MessageTemplate", logEvent.MessageTemplate.Render(logEvent.Properties, CultureInfo.InvariantCulture));
+            writer.WriteString("Message", logEvent.RenderMessage());
+
+            if (logEvent.Level != LogEventLevel.Information)
+                writer.WriteString("Level", logEvent.Level.ToString());
+
+            if (logEvent.Exception is { } exception)
+                writer.WriteString("Exception", exception.ToString());
+
+            if (logEvent.TraceId is { } traceId)
+                writer.WriteString("TraceId", traceId.ToHexString());
+
+            if (logEvent.SpanId is { } spanId)
+                writer.WriteString("SpanId", spanId.ToHexString());
+
+            foreach (var property in logEvent.Properties)
+            {
+                var name = property.Key;
+                if (name.Length > 0 && name[0] == '@')
+                    name = '@' + name; // Escape a leading '@' by doubling it, as in Serilog.Formatting.Compact.
+
+                writer.WritePropertyName(name);
+                WriteValue(writer, property.Value);
+            }
+
+            writer.WriteEndObject();
+        }
+
+        output.Write(Encoding.UTF8.GetString(buffer.WrittenSpan));
+        output.WriteLine();
+    }
+
+    private static void WriteValue(Utf8JsonWriter writer, LogEventPropertyValue value)
+    {
+        switch (value)
+        {
+            case ScalarValue scalarValue:
+                WriteScalar(writer, scalarValue.Value);
+                break;
+
+            case SequenceValue sequenceValue:
+                writer.WriteStartArray();
+                foreach (var element in sequenceValue.Elements)
+                    WriteValue(writer, element);
+                writer.WriteEndArray();
+                break;
+
+            case StructureValue structureValue:
+                writer.WriteStartObject();
+                if (structureValue.TypeTag is { Length: > 0 } typeTag)
+                    writer.WriteString("$type", typeTag);
+                foreach (var property in structureValue.Properties)
+                {
+                    writer.WritePropertyName(property.Name);
+                    WriteValue(writer, property.Value);
+                }
+                writer.WriteEndObject();
+                break;
+
+            case DictionaryValue dictionaryValue:
+                writer.WriteStartObject();
+                foreach (var element in dictionaryValue.Elements)
+                {
+                    writer.WritePropertyName((element.Key as ScalarValue)?.Value?.ToString() ?? element.Key.ToString());
+                    WriteValue(writer, element.Value);
+                }
+                writer.WriteEndObject();
+                break;
+
+            default:
+                writer.WriteNullValue();
+                break;
+        }
+    }
+
+    private static void WriteScalar(Utf8JsonWriter writer, object? value)
+    {
+        switch (value)
+        {
+            case null:
+                writer.WriteNullValue();
+                break;
+            case string text:
+                writer.WriteStringValue(text);
+                break;
+            case bool flag:
+                writer.WriteBooleanValue(flag);
+                break;
+            case byte n:
+                writer.WriteNumberValue(n);
+                break;
+            case sbyte n:
+                writer.WriteNumberValue(n);
+                break;
+            case short n:
+                writer.WriteNumberValue(n);
+                break;
+            case ushort n:
+                writer.WriteNumberValue(n);
+                break;
+            case int n:
+                writer.WriteNumberValue(n);
+                break;
+            case uint n:
+                writer.WriteNumberValue(n);
+                break;
+            case long n:
+                writer.WriteNumberValue(n);
+                break;
+            case ulong n:
+                writer.WriteNumberValue(n);
+                break;
+            case float n:
+                writer.WriteNumberValue(n);
+                break;
+            case double n:
+                writer.WriteNumberValue(n);
+                break;
+            case decimal n:
+                writer.WriteNumberValue(n);
+                break;
+            case DateTime dateTime:
+                writer.WriteStringValue(dateTime);
+                break;
+            case DateTimeOffset dateTimeOffset:
+                writer.WriteStringValue(dateTimeOffset);
+                break;
+            case Guid guid:
+                writer.WriteStringValue(guid);
+                break;
+            case char ch:
+                writer.WriteStringValue(ch.ToString());
+                break;
+            default:
+                writer.WriteStringValue(value.ToString());
+                break;
+        }
+    }
+}

SS14.Labeller/appsettings.Development.json

@@ -0,0 +1,12 @@
+{
+  "Serilog": {
+    "Using": [
+      "Serilog.Sinks.Console"
+    ],
+    "WriteTo": [
+      {
+        "Name": "Console"
+      }
+    ]
+  }
+}