Merge pull request #94 from Virtual-Finland-Development/feat/error-alerting

lsipii · web-flow · commit 8b24818ea5eb · 2023-10-25T12:07:08.000+03:00
Subscribe errors to the monitoring/alerter
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Activities/User/Operations/GetSearchProfile.cs b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Activities/User/Operations/GetSearchProfile.cs
@@ -51,7 +51,6 @@ public async Task<SearchProfile> Handle(Query request, CancellationToken cancell
 
             if (userSearchProfile is null)
             {
-                _logger.LogInformation("Failed to retrieve search profile: {RequestProfileId}", request.ProfileId);
                 throw new NotFoundException($"Specified search profile not found by ID: {request.ProfileId}");
             }
 
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Helpers/Services/TestbedConsentSecurityService.cs b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Helpers/Services/TestbedConsentSecurityService.cs
@@ -24,7 +24,7 @@ public TestbedConsentSecurityService(ILogger<TestbedConsentSecurityService> logg
 
     public async Task VerifyConsentTokenRequestHeaders(IHeaderDictionary headers, string dataSourceUri)
     {
-        _logger.LogInformation("Verifying consent request");
+        _logger.LogDebug("Verifying consent request");
         var idToken = headers.Authorization.ToString().Replace("Bearer ", string.Empty);
         if (string.IsNullOrEmpty(idToken))
             throw new NotAuthorizedException("Authorization token is missing");
@@ -36,12 +36,12 @@ public async Task VerifyConsentTokenRequestHeaders(IHeaderDictionary headers, st
         VerifyConsentToken(consentToken, idToken, dataSourceUri);
         await VerifyConsentTokenWithService(consentToken, idToken, dataSourceUri); // Checks for token revokation
 
-        _logger.LogInformation("Consent request verified");
+        _logger.LogDebug("Consent request verified");
     }
 
     public void VerifyConsentToken(string consentTokenRaw, string idTokenRaw, string dataSourceUri)
     {
-        _logger.LogInformation("Verifying consent token");
+        _logger.LogDebug("Verifying consent token");
 
         var idToken = ParseJwtToken(idTokenRaw);
         if (idToken == null)
@@ -96,13 +96,13 @@ public void VerifyConsentToken(string consentTokenRaw, string idTokenRaw, string
         if (consentToken.Payload["dsi"] as string != dataSourceUri)
             throw new NotAuthorizedException("Token mismatch: dsi");
 
-        _logger.LogInformation("Consent token verified");
+        _logger.LogDebug("Consent token verified");
     }
 
 
     public async Task VerifyConsentTokenWithService(string consentToken, string idToken, string dataSourceUri)
     {
-        _logger.LogInformation("Verifying consent with Testbed Consent API");
+        _logger.LogDebug("Verifying consent with Testbed Consent API");
         try
         {
             var httpClient = _httpClientFactory.CreateClient();
@@ -130,7 +130,7 @@ public async Task VerifyConsentTokenWithService(string consentToken, string idTo
             throw new NotAuthorizedException(e.Message);
         }
 
-        _logger.LogInformation("Consent verified by Testbed Consent API");
+        _logger.LogDebug("Consent verified by Testbed Consent API");
     }
 
 
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Middleware/ErrorHandlerMiddleware.cs b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Middleware/ErrorHandlerMiddleware.cs
@@ -23,6 +23,13 @@ public async Task Invoke(HttpContext context)
         }
         catch (Exception error)
         {
+            // Debug mode logging
+            _logger.LogDebug(error, "Debug");
+
+            // Attach exception to the request context for request logger middleware
+            context.Items.Add("Exception", error);
+
+            // Write the error response
             switch (error)
             {
                 case NotAuthorizedException:
@@ -40,7 +47,6 @@ public async Task Invoke(HttpContext context)
                     }, HttpStatusCode.NotFound);
                     break;
                 case BadRequestException:
-                    _logger.LogError(error, "Request processing failure!");
                     await WriteErrorResponse(context, new ErrorResponse()
                     {
                         Type = "BadRequest",
@@ -113,7 +119,6 @@ public async Task Invoke(HttpContext context)
                     }, HttpStatusCode.RequestTimeout);
                     break;
                 default:
-                    _logger.LogError(error, "Request processing failure!");
                     await WriteErrorResponse(context, new ErrorResponse()
                     {
                         Type = "InternalServerError",
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Program.cs b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/Program.cs
@@ -170,7 +170,17 @@
 }
 
 
-app.UseSerilogRequestLogging();
+app.UseSerilogRequestLogging(options =>
+{
+    options.EnrichDiagnosticContext = (diagnosticContext, httpContext) =>
+    {
+        if (httpContext.Items["Exception"] is Exception exception)
+        {
+            // Add the exception to the log context, omit the stack trace
+            diagnosticContext.Set("@x", $"{exception.GetType().Name}: {exception.Message}");
+        }
+    };
+});
 app.UseMiddleware<RequestTracingMiddleware>();
 app.UseMiddleware<ErrorHandlerMiddleware>();
 app.UseHttpsRedirection();
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.dev.json b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.dev.json
@@ -1,26 +1,4 @@
 {
-  "Serilog": {
-    "Using": [
-      "Serilog.Sinks.Console"
-    ],
-    "MinimumLevel": {
-      "Default": "Information",
-      "Override": {
-        "Microsoft": "Warning",
-        "Microsoft.Hosting.Lifetime": "Warning",
-        "Microsoft.AspNetCore": "Warning",
-        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
-      }
-    },
-    "WriteTo": [
-      {
-        "Name": "Console",
-        "Args": {
-          "formatter": "Serilog.Formatting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact"
-        }
-      }
-    ]
-  },
   "Security": {
     "Authorization": {
       "SuomiFi": {
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.json b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.json
@@ -5,6 +5,28 @@
       "Microsoft.AspNetCore": "Warning"
     }
   },
+  "Serilog": {
+    "Using": [
+      "Serilog.Sinks.Console"
+    ],
+    "MinimumLevel": {
+      "Default": "Information",
+      "Override": {
+        "Microsoft": "Warning",
+        "Microsoft.Hosting.Lifetime": "Warning",
+        "Microsoft.AspNetCore": "Warning",
+        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
+      }
+    },
+    "WriteTo": [
+      {
+        "Name": "Console",
+        "Args": {
+          "formatter": "Serilog.Formatting.Compact.RenderedCompactJsonFormatter, Serilog.Formatting.Compact"
+        }
+      }
+    ]
+  },
   "AllowedHosts": "*",
   "Security": {
     "Access": {
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.local.json b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.local.json
@@ -1,20 +1,18 @@
 {
   "Serilog": {
-    "Using": [
-      "Serilog.Sinks.Console"
-    ],
     "MinimumLevel": {
-      "Default": "Information",
+      "Default": "Debug",
       "Override": {
-        "Microsoft": "Warning",
-        "Microsoft.Hosting.Lifetime": "Warning",
-        "Microsoft.AspNetCore": "Warning",
-        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
+        "Microsoft.EntityFrameworkCore.Database.Command": "Information"
       }
     },
     "WriteTo": [
       {
-        "Name": "Console"
+        "Name": "Console",
+        "Args": {
+          "theme": "Serilog.Sinks.SystemConsole.Themes.AnsiConsoleTheme::Code, Serilog.Sinks.Console",
+          "outputTemplate": "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"
+        }
       }
     ]
   },
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.mvp-staging.json b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.mvp-staging.json
@@ -1,26 +1,4 @@
 {
-  "Serilog": {
-    "Using": [
-      "Serilog.Sinks.Console"
-    ],
-    "MinimumLevel": {
-      "Default": "Information",
-      "Override": {
-        "Microsoft": "Warning",
-        "Microsoft.Hosting.Lifetime": "Warning",
-        "Microsoft.AspNetCore": "Warning",
-        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
-      }
-    },
-    "WriteTo": [
-      {
-        "Name": "Console",
-        "Args": {
-          "formatter": "Serilog.Formatting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact"
-        }
-      }
-    ]
-  },
   "Security": {
     "Authorization": {
       "Sinuna": {
diff --git a/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.staging.json b/VirtualFinland.UserAPI/src/VirtualFinland.UsersAPI/appsettings.staging.json
@@ -1,26 +1,4 @@
 {
-  "Serilog": {
-    "Using": [
-      "Serilog.Sinks.Console"
-    ],
-    "MinimumLevel": {
-      "Default": "Information",
-      "Override": {
-        "Microsoft": "Warning",
-        "Microsoft.Hosting.Lifetime": "Warning",
-        "Microsoft.AspNetCore": "Warning",
-        "Microsoft.EntityFrameworkCore.Database.Command": "Warning"
-      }
-    },
-    "WriteTo": [
-      {
-        "Name": "Console",
-        "Args": {
-          "formatter": "Serilog.Formatting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact"
-        }
-      }
-    ]
-  },
   "Security": {
     "Authorization": {
       "SuomiFi": {
diff --git a/VirtualFinland.UsersAPI.Deployment/Common/Models/StackSetup.cs b/VirtualFinland.UsersAPI.Deployment/Common/Models/StackSetup.cs
@@ -12,4 +12,5 @@ public class StackSetup
     public string Region = default!;
     public string CreateResourceName(string name) => $"{ProjectName}-{name}-{Environment}".ToLower();
     public string GetInfrastructureStackName() => $"{Organization}/infrastructure/{Environment}";
+    public string GetAlertingStackName() => $"{Organization}/cloudwatch-logs-alerts/{Environment}";
 }
diff --git a/VirtualFinland.UsersAPI.Deployment/Features/UsersApiLambdaFunction.cs b/VirtualFinland.UsersAPI.Deployment/Features/UsersApiLambdaFunction.cs
@@ -116,7 +116,7 @@ public UsersApiLambdaFunction(Config config, StackSetup stackSetup, VpcSetup vpc
             Role = execRole.Arn,
             Runtime = "dotnet6",
             Handler = "VirtualFinland.UsersAPI",
-            Timeout = 30,
+            Timeout = 15,
             MemorySize = 2048,
             Environment = new FunctionEnvironmentArgs
             {
@@ -171,10 +171,44 @@ public UsersApiLambdaFunction(Config config, StackSetup stackSetup, VpcSetup vpc
         // Configure log group with retention of 180 days
         LogGroup = cloudwatch.CreateLambdaFunctionLogGroup(stackSetup, "apiFunction", LambdaFunctionResource, 180);
 
+        // Setup error alerting
+        SetupErrorAlerting(stackSetup);
+
         LambdaFunctionArn = LambdaFunctionResource.Arn;
         LambdaFunctionId = LambdaFunctionResource.Id;
     }
 
+    private void SetupErrorAlerting(StackSetup stackSetup)
+    {
+        var stackReference = new StackReference(stackSetup.GetAlertingStackName());
+        var errorLambdaFunctionArnRef = stackReference.RequireOutput("errorSubLambdaFunctionArn");
+        var errorLambdaFunctionArn = Output.Format($"{errorLambdaFunctionArnRef}");
+
+        // Permissions for the log group subscription to invoke the error alerting lambda function of monitoring stack
+        var logGroupInvokePermission = new Permission(stackSetup.CreateResourceName("ErrorAlerter"), new PermissionArgs
+        {
+            Action = "lambda:InvokeFunction",
+            Function = errorLambdaFunctionArn,
+            Principal = "logs.amazonaws.com",
+            SourceArn = Output.Format($"{LogGroup.Arn}:*"),
+        }, new() { DependsOn = { LogGroup } });
+
+        // Subscribe to the log groups
+        _ = new LogSubscriptionFilter(stackSetup.CreateResourceName("StatusCodeAlert"), new LogSubscriptionFilterArgs
+        {
+            LogGroup = LogGroup.Name,
+            FilterPattern = "{ $.StatusCode > 404 }", // Users API should not encounter errors with status code > 404, for example validation errors not expected
+            DestinationArn = errorLambdaFunctionArn,
+        }, new() { DependsOn = { logGroupInvokePermission } });
+
+        _ = new LogSubscriptionFilter(stackSetup.CreateResourceName("TaskTimedOutAlert"), new LogSubscriptionFilterArgs
+        {
+            LogGroup = LogGroup.Name,
+            FilterPattern = "%Task timed out%", // Users API should not encounter timeouts
+            DestinationArn = errorLambdaFunctionArn,
+        }, new() { DependsOn = { logGroupInvokePermission } });
+    }
+
     public Function LambdaFunctionResource = default!;
     public Output<string> LambdaFunctionArn = default!;
     public Output<string> LambdaFunctionId = default!;

Original file line number	Diff line number	Diff line change
`@@ -51,7 +51,6 @@ public async Task<SearchProfile> Handle(Query request, CancellationToken cancell`
`51`	`51`
`52`	`52`	`if (userSearchProfile is null)`
`53`	`53`	`{`
`54`		`- _logger.LogInformation("Failed to retrieve search profile: {RequestProfileId}", request.ProfileId);`
`55`	`54`	`throw new NotFoundException($"Specified search profile not found by ID: {request.ProfileId}");`
`56`	`55`	`}`
`57`	`56`
Original file line number	Diff line number	Diff line change
`@@ -24,7 +24,7 @@ public TestbedConsentSecurityService(ILogger<TestbedConsentSecurityService> logg`
`24`	`24`
`25`	`25`	`public async Task VerifyConsentTokenRequestHeaders(IHeaderDictionary headers, string dataSourceUri)`
`26`	`26`	`{`
`27`		`- _logger.LogInformation("Verifying consent request");`
	`27`	`+ _logger.LogDebug("Verifying consent request");`
`28`	`28`	`var idToken = headers.Authorization.ToString().Replace("Bearer ", string.Empty);`
`29`	`29`	`if (string.IsNullOrEmpty(idToken))`
`30`	`30`	`throw new NotAuthorizedException("Authorization token is missing");`
`@@ -36,12 +36,12 @@ public async Task VerifyConsentTokenRequestHeaders(IHeaderDictionary headers, st`
`36`	`36`	`VerifyConsentToken(consentToken, idToken, dataSourceUri);`
`37`	`37`	`await VerifyConsentTokenWithService(consentToken, idToken, dataSourceUri); // Checks for token revokation`
`38`	`38`
`39`		`- _logger.LogInformation("Consent request verified");`
	`39`	`+ _logger.LogDebug("Consent request verified");`
`40`	`40`	`}`
`41`	`41`
`42`	`42`	`public void VerifyConsentToken(string consentTokenRaw, string idTokenRaw, string dataSourceUri)`
`43`	`43`	`{`
`44`		`- _logger.LogInformation("Verifying consent token");`
	`44`	`+ _logger.LogDebug("Verifying consent token");`
`45`	`45`
`46`	`46`	`var idToken = ParseJwtToken(idTokenRaw);`
`47`	`47`	`if (idToken == null)`
`@@ -96,13 +96,13 @@ public void VerifyConsentToken(string consentTokenRaw, string idTokenRaw, string`
`96`	`96`	`if (consentToken.Payload["dsi"] as string != dataSourceUri)`
`97`	`97`	`throw new NotAuthorizedException("Token mismatch: dsi");`
`98`	`98`
`99`		`- _logger.LogInformation("Consent token verified");`
	`99`	`+ _logger.LogDebug("Consent token verified");`
`100`	`100`	`}`
`101`	`101`
`102`	`102`
`103`	`103`	`public async Task VerifyConsentTokenWithService(string consentToken, string idToken, string dataSourceUri)`
`104`	`104`	`{`
`105`		`- _logger.LogInformation("Verifying consent with Testbed Consent API");`
	`105`	`+ _logger.LogDebug("Verifying consent with Testbed Consent API");`
`106`	`106`	`try`
`107`	`107`	`{`
`108`	`108`	`var httpClient = _httpClientFactory.CreateClient();`
`@@ -130,7 +130,7 @@ public async Task VerifyConsentTokenWithService(string consentToken, string idTo`
`130`	`130`	`throw new NotAuthorizedException(e.Message);`
`131`	`131`	`}`
`132`	`132`
`133`		`- _logger.LogInformation("Consent verified by Testbed Consent API");`
	`133`	`+ _logger.LogDebug("Consent verified by Testbed Consent API");`
`134`	`134`	`}`
`135`	`135`
`136`	`136`
Original file line number	Diff line number	Diff line change
`@@ -23,6 +23,13 @@ public async Task Invoke(HttpContext context)`
`23`	`23`	`}`
`24`	`24`	`catch (Exception error)`
`25`	`25`	`{`
	`26`	`+ // Debug mode logging`
	`27`	`+ _logger.LogDebug(error, "Debug");`
	`28`	`+`
	`29`	`+ // Attach exception to the request context for request logger middleware`
	`30`	`+ context.Items.Add("Exception", error);`
	`31`	`+`
	`32`	`+ // Write the error response`
`26`	`33`	`switch (error)`
`27`	`34`	`{`
`28`	`35`	`case NotAuthorizedException:`
`@@ -40,7 +47,6 @@ public async Task Invoke(HttpContext context)`
`40`	`47`	`}, HttpStatusCode.NotFound);`
`41`	`48`	`break;`
`42`	`49`	`case BadRequestException:`
`43`		`- _logger.LogError(error, "Request processing failure!");`
`44`	`50`	`await WriteErrorResponse(context, new ErrorResponse()`
`45`	`51`	`{`
`46`	`52`	`Type = "BadRequest",`
`@@ -113,7 +119,6 @@ public async Task Invoke(HttpContext context)`
`113`	`119`	`}, HttpStatusCode.RequestTimeout);`
`114`	`120`	`break;`
`115`	`121`	`default:`
`116`		`- _logger.LogError(error, "Request processing failure!");`
`117`	`122`	`await WriteErrorResponse(context, new ErrorResponse()`
`118`	`123`	`{`
`119`	`124`	`Type = "InternalServerError",`
Original file line number	Diff line number	Diff line change
`@@ -1,20 +1,18 @@`
`1`	`1`	`{`
`2`	`2`	`"Serilog": {`
`3`		`- "Using": [`
`4`		`- "Serilog.Sinks.Console"`
`5`		`- ],`
`6`	`3`	`"MinimumLevel": {`
`7`		`- "Default": "Information",`
	`4`	`+ "Default": "Debug",`
`8`	`5`	`"Override": {`
`9`		`- "Microsoft": "Warning",`
`10`		`- "Microsoft.Hosting.Lifetime": "Warning",`
`11`		`- "Microsoft.AspNetCore": "Warning",`
`12`		`- "Microsoft.EntityFrameworkCore.Database.Command": "Warning"`
	`6`	`+ "Microsoft.EntityFrameworkCore.Database.Command": "Information"`
`13`	`7`	`}`
`14`	`8`	`},`
`15`	`9`	`"WriteTo": [`
`16`	`10`	`{`
`17`		`- "Name": "Console"`
	`11`	`+ "Name": "Console",`
	`12`	`+ "Args": {`
	`13`	`+ "theme": "Serilog.Sinks.SystemConsole.Themes.AnsiConsoleTheme::Code, Serilog.Sinks.Console",`
	`14`	`+ "outputTemplate": "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"`
	`15`	`+ }`
`18`	`16`	`}`
`19`	`17`	`]`
`20`	`18`	`},`
Original file line number	Diff line number	Diff line change
`@@ -12,4 +12,5 @@ public class StackSetup`
`12`	`12`	`public string Region = default!;`
`13`	`13`	`public string CreateResourceName(string name) => $"{ProjectName}-{name}-{Environment}".ToLower();`
`14`	`14`	`public string GetInfrastructureStackName() => $"{Organization}/infrastructure/{Environment}";`
	`15`	`+ public string GetAlertingStackName() => $"{Organization}/cloudwatch-logs-alerts/{Environment}";`
`15`	`16`	`}`