From 0b82c3bea3e2228ac1bc0068edd0d86a6a989d34 Mon Sep 17 00:00:00 2001 From: Robert Dailey Date: Fri, 25 Aug 2023 10:39:28 -0500 Subject: [PATCH] fix: Better processing for HTTP 500 service responses Fixes #206. --- CHANGELOG.md | 4 ++ .../Commands/DeleteCustomFormatsCommand.cs | 1 + .../ConsoleExceptionHandler.cs | 27 ++------ .../ErrorHandling/ErrorResponseParser.cs | 66 +++++++++++++++++++ .../FlurlHttpExceptionHandler.cs | 36 ++++++++++ .../IFlurlHttpExceptionHandler.cs | 6 ++ .../IServiceErrorMessageExtractor.cs | 6 ++ .../ServiceErrorMessageExtractor.cs | 18 +++++ .../ServiceProcessorsAutofacModule.cs | 2 + .../Processors/Sync/SyncProcessor.cs | 1 + .../Data/database_locked_error.json | 4 ++ .../ErrorHandling/Data/validation_error.json | 8 +++ .../FlurlHttpExceptionHandlerTest.cs | 57 ++++++++++++++++ 13 files changed, 214 insertions(+), 22 deletions(-) rename src/Recyclarr.Cli/Processors/{ => ErrorHandling}/ConsoleExceptionHandler.cs (72%) create mode 100644 src/Recyclarr.Cli/Processors/ErrorHandling/ErrorResponseParser.cs create mode 100644 src/Recyclarr.Cli/Processors/ErrorHandling/FlurlHttpExceptionHandler.cs create mode 100644 src/Recyclarr.Cli/Processors/ErrorHandling/IFlurlHttpExceptionHandler.cs create mode 100644 src/Recyclarr.Cli/Processors/ErrorHandling/IServiceErrorMessageExtractor.cs create mode 100644 src/Recyclarr.Cli/Processors/ErrorHandling/ServiceErrorMessageExtractor.cs create mode 100644 src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/database_locked_error.json create mode 100644 src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/validation_error.json create mode 100644 src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/FlurlHttpExceptionHandlerTest.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index 2835eba7..f0e50333 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Print date & time log at the end of each completed instance sync (#165). +### Fixed + +- Service failures (e.g. HTTP 500) no longer cause exceptions (#206). + ## [5.3.1] - 2023-08-21 ### Fixed diff --git a/src/Recyclarr.Cli/Console/Commands/DeleteCustomFormatsCommand.cs b/src/Recyclarr.Cli/Console/Commands/DeleteCustomFormatsCommand.cs index 6f2a5628..13b81479 100644 --- a/src/Recyclarr.Cli/Console/Commands/DeleteCustomFormatsCommand.cs +++ b/src/Recyclarr.Cli/Console/Commands/DeleteCustomFormatsCommand.cs @@ -4,6 +4,7 @@ using JetBrains.Annotations; using Recyclarr.Cli.Console.Settings; using Recyclarr.Cli.Processors; using Recyclarr.Cli.Processors.Delete; +using Recyclarr.Cli.Processors.ErrorHandling; using Spectre.Console.Cli; namespace Recyclarr.Cli.Console.Commands; diff --git a/src/Recyclarr.Cli/Processors/ConsoleExceptionHandler.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/ConsoleExceptionHandler.cs similarity index 72% rename from src/Recyclarr.Cli/Processors/ConsoleExceptionHandler.cs rename to src/Recyclarr.Cli/Processors/ErrorHandling/ConsoleExceptionHandler.cs index 39451eba..815c6017 100644 --- a/src/Recyclarr.Cli/Processors/ConsoleExceptionHandler.cs +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/ConsoleExceptionHandler.cs @@ -1,19 +1,20 @@ using Flurl.Http; -using Recyclarr.Common.Extensions; using Recyclarr.TrashLib.Config.Parsing.ErrorHandling; using Recyclarr.TrashLib.ExceptionTypes; using Recyclarr.TrashLib.Http; using Recyclarr.TrashLib.Repo.VersionControl; -namespace Recyclarr.Cli.Processors; +namespace Recyclarr.Cli.Processors.ErrorHandling; public class ConsoleExceptionHandler { private readonly ILogger _log; + private readonly IFlurlHttpExceptionHandler _httpExceptionHandler; - public ConsoleExceptionHandler(ILogger log) + public ConsoleExceptionHandler(ILogger log, IFlurlHttpExceptionHandler httpExceptionHandler) { _log = log; + _httpExceptionHandler = httpExceptionHandler; } public async Task HandleException(Exception sourceException) @@ -27,11 +28,7 @@ public class ConsoleExceptionHandler case FlurlHttpException e: _log.Error("HTTP error: {Message}", e.SanitizedExceptionMessage()); - foreach (var error in await GetValidationErrorsAsync(e)) - { - _log.Error("Reason: {Error}", error); - } - + await _httpExceptionHandler.ProcessServiceErrorMessages(new ServiceErrorMessageExtractor(e)); break; case NoConfigurationFilesException: @@ -63,18 +60,4 @@ public class ConsoleExceptionHandler throw sourceException; } } - - private static async Task> GetValidationErrorsAsync(FlurlHttpException e) - { - var response = await e.GetResponseJsonAsync>(); - if (response is null) - { - return Array.Empty(); - } - - return response - .Select(x => (string) x.errorMessage) - .NotNull(x => !string.IsNullOrEmpty(x)) - .ToList(); - } } diff --git a/src/Recyclarr.Cli/Processors/ErrorHandling/ErrorResponseParser.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/ErrorResponseParser.cs new file mode 100644 index 00000000..ec1a88a6 --- /dev/null +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/ErrorResponseParser.cs @@ -0,0 +1,66 @@ +using System.Diagnostics.CodeAnalysis; +using Newtonsoft.Json; +using Recyclarr.TrashLib.Json; + +namespace Recyclarr.Cli.Processors.ErrorHandling; + +public sealed class ErrorResponseParser +{ + private readonly ILogger _log; + private readonly Func _streamFactory; + private readonly JsonSerializer _serializer; + + public ErrorResponseParser(ILogger log, string responseBody) + { + _log = log; + _streamFactory = () => new JsonTextReader(new StringReader(responseBody)); + _serializer = ServiceJsonSerializerFactory.Create(); + } + + [SuppressMessage("Design", "CA1031:Do not catch general exception types")] + public bool DeserializeList(Func, IEnumerable> expr) + { + try + { + using var stream = _streamFactory(); + var value = _serializer.Deserialize>(stream); + if (value is null) + { + return false; + } + + var parsed = expr(value); + foreach (var s in parsed) + { + _log.Error("Reason: {Message:l}", (string) s); + } + + return true; + } + catch + { + return false; + } + } + + [SuppressMessage("Design", "CA1031:Do not catch general exception types")] + public bool Deserialize(Func expr) + { + try + { + using var stream = _streamFactory(); + var value = _serializer.Deserialize(stream); + if (value is null) + { + return false; + } + + _log.Error("Reason: {Message:l}", (string) expr(value)); + return true; + } + catch + { + return false; + } + } +} diff --git a/src/Recyclarr.Cli/Processors/ErrorHandling/FlurlHttpExceptionHandler.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/FlurlHttpExceptionHandler.cs new file mode 100644 index 00000000..32dc16ab --- /dev/null +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/FlurlHttpExceptionHandler.cs @@ -0,0 +1,36 @@ +using System.Diagnostics.CodeAnalysis; +using Recyclarr.Common.Extensions; + +namespace Recyclarr.Cli.Processors.ErrorHandling; + +public class FlurlHttpExceptionHandler : IFlurlHttpExceptionHandler +{ + private readonly ILogger _log; + + public FlurlHttpExceptionHandler(ILogger log) + { + _log = log; + } + + [SuppressMessage("Design", "CA1031:Do not catch general exception types")] + public async Task ProcessServiceErrorMessages(IServiceErrorMessageExtractor extractor) + { + var responseBody = await extractor.GetErrorMessage(); + var parser = new ErrorResponseParser(_log, responseBody); + + if (parser.DeserializeList(s => s + .Select(x => (string) x.errorMessage) + .NotNull(x => !string.IsNullOrEmpty(x)))) + { + return; + } + + if (parser.Deserialize(s => s.message)) + { + return; + } + + // Last resort + _log.Error("Reason: Unable to determine. Please report this as a bug and attach your `verbose.log` file."); + } +} diff --git a/src/Recyclarr.Cli/Processors/ErrorHandling/IFlurlHttpExceptionHandler.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/IFlurlHttpExceptionHandler.cs new file mode 100644 index 00000000..99e355d2 --- /dev/null +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/IFlurlHttpExceptionHandler.cs @@ -0,0 +1,6 @@ +namespace Recyclarr.Cli.Processors.ErrorHandling; + +public interface IFlurlHttpExceptionHandler +{ + Task ProcessServiceErrorMessages(IServiceErrorMessageExtractor extractor); +} diff --git a/src/Recyclarr.Cli/Processors/ErrorHandling/IServiceErrorMessageExtractor.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/IServiceErrorMessageExtractor.cs new file mode 100644 index 00000000..bd8ca351 --- /dev/null +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/IServiceErrorMessageExtractor.cs @@ -0,0 +1,6 @@ +namespace Recyclarr.Cli.Processors.ErrorHandling; + +public interface IServiceErrorMessageExtractor +{ + Task GetErrorMessage(); +} diff --git a/src/Recyclarr.Cli/Processors/ErrorHandling/ServiceErrorMessageExtractor.cs b/src/Recyclarr.Cli/Processors/ErrorHandling/ServiceErrorMessageExtractor.cs new file mode 100644 index 00000000..df8fdc8d --- /dev/null +++ b/src/Recyclarr.Cli/Processors/ErrorHandling/ServiceErrorMessageExtractor.cs @@ -0,0 +1,18 @@ +using Flurl.Http; + +namespace Recyclarr.Cli.Processors.ErrorHandling; + +public class ServiceErrorMessageExtractor : IServiceErrorMessageExtractor +{ + private readonly FlurlHttpException _e; + + public ServiceErrorMessageExtractor(FlurlHttpException e) + { + _e = e; + } + + public async Task GetErrorMessage() + { + return await _e.GetResponseStringAsync(); + } +} diff --git a/src/Recyclarr.Cli/Processors/ServiceProcessorsAutofacModule.cs b/src/Recyclarr.Cli/Processors/ServiceProcessorsAutofacModule.cs index 19b210c8..aecc98c8 100644 --- a/src/Recyclarr.Cli/Processors/ServiceProcessorsAutofacModule.cs +++ b/src/Recyclarr.Cli/Processors/ServiceProcessorsAutofacModule.cs @@ -2,6 +2,7 @@ using Autofac; using Autofac.Extras.Ordering; using Recyclarr.Cli.Processors.Config; using Recyclarr.Cli.Processors.Delete; +using Recyclarr.Cli.Processors.ErrorHandling; using Recyclarr.Cli.Processors.Sync; namespace Recyclarr.Cli.Processors; @@ -13,6 +14,7 @@ public class ServiceProcessorsAutofacModule : Module base.Load(builder); builder.RegisterType(); + builder.RegisterType().As(); // Sync builder.RegisterType().As(); diff --git a/src/Recyclarr.Cli/Processors/Sync/SyncProcessor.cs b/src/Recyclarr.Cli/Processors/Sync/SyncProcessor.cs index 2316786a..680666e5 100644 --- a/src/Recyclarr.Cli/Processors/Sync/SyncProcessor.cs +++ b/src/Recyclarr.Cli/Processors/Sync/SyncProcessor.cs @@ -1,5 +1,6 @@ using System.Diagnostics.CodeAnalysis; using Recyclarr.Cli.Console.Settings; +using Recyclarr.Cli.Processors.ErrorHandling; using Recyclarr.TrashLib.Compatibility; using Recyclarr.TrashLib.Config; using Recyclarr.TrashLib.Config.Services; diff --git a/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/database_locked_error.json b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/database_locked_error.json new file mode 100644 index 00000000..54883ffd --- /dev/null +++ b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/database_locked_error.json @@ -0,0 +1,4 @@ +{ + "message": "database is locked\ndatabase is locked", + "description": "code = Busy (5), message = System.Data.SQLite.SQLiteException (0x87AF00AA): database is locked\ndatabase is locked\n at System.Data.SQLite.SQLite3.Prepare(SQLiteConnection cnn, SQLiteCommand command, String strSql, SQLiteStatement previous, UInt32 timeoutMS, String& strRemain)\n at System.Data.SQLite.SQLiteCommand.BuildNextCommand()\n at System.Data.SQLite.SQLiteDataReader.NextResult()\n at System.Data.SQLite.SQLiteDataReader..ctor(SQLiteCommand cmd, CommandBehavior behave)\n at System.Data.SQLite.SQLiteCommand.ExecuteReader(CommandBehavior behavior)\n at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery(CommandBehavior behavior)\n at System.Data.SQLite.SQLiteConnection.Open()\n at NzbDrone.Core.Datastore.DbFactory.<>c__DisplayClass9_0.b__0() in ./Radarr.Core/Datastore/DbFactory.cs:line 104\n at NzbDrone.Core.Datastore.BasicRepository`1.UpdateMany(IList`1 models) in ./Radarr.Core/Datastore/BasicRepository.cs:line 246\n at NzbDrone.Core.Qualities.QualityDefinitionService.UpdateMany(List`1 qualityDefinitions) in ./Radarr.Core/Qualities/QualityDefinitionService.cs:line 49\n at Radarr.Api.V3.Qualities.QualityDefinitionController.UpdateMany(List`1 resource) in ./Radarr.Api.V3/Qualities/QualityDefinitionController.cs:line 52\n at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncObjectResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()\n--- End of stack trace from previous location ---\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()\n--- End of stack trace from previous location ---\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)\n at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)\n at Microsoft.AspNetCore.Routing.EndpointMiddleware.g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)\n at Radarr.Http.Middleware.BufferingMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/BufferingMiddleware.cs:line 28\n at Radarr.Http.Middleware.IfModifiedMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/IfModifiedMiddleware.cs:line 41\n at Radarr.Http.Middleware.CacheHeaderMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/CacheHeaderMiddleware.cs:line 33\n at Radarr.Http.Middleware.StartingUpMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/StartingUpMiddleware.cs:line 38\n at Radarr.Http.Middleware.UrlBaseMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/UrlBaseMiddleware.cs:line 27\n at Radarr.Http.Middleware.VersionMiddleware.InvokeAsync(HttpContext context) in ./Radarr.Http/Middleware/VersionMiddleware.cs:line 29\n at Microsoft.AspNetCore.ResponseCompression.ResponseCompressionMiddleware.InvokeCore(HttpContext context)\n at Microsoft.AspNetCore.Authorization.Policy.AuthorizationMiddlewareResultHandler.HandleAsync(RequestDelegate next, HttpContext context, AuthorizationPolicy policy, PolicyAuthorizationResult authorizeResult)\n at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)\n at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)\n at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)" +} diff --git a/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/validation_error.json b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/validation_error.json new file mode 100644 index 00000000..8ceac225 --- /dev/null +++ b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/validation_error.json @@ -0,0 +1,8 @@ +[ + { + "errorMessage": "error one" + }, + { + "errorMessage": "error two" + } +] diff --git a/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/FlurlHttpExceptionHandlerTest.cs b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/FlurlHttpExceptionHandlerTest.cs new file mode 100644 index 00000000..e40a10c9 --- /dev/null +++ b/src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/FlurlHttpExceptionHandlerTest.cs @@ -0,0 +1,57 @@ +using System.Diagnostics.CodeAnalysis; +using Recyclarr.Cli.Processors.ErrorHandling; +using Recyclarr.Common; +using Recyclarr.TestLibrary; + +namespace Recyclarr.Cli.Tests.Processors.ErrorHandling; + +[TestFixture] +[Parallelizable(ParallelScope.All)] +[SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope")] +public class FlurlHttpExceptionHandlerTest +{ + [Test, AutoMockData] + public async Task Http_exception_print_validation_errors( + [Frozen(Matching.ImplementedInterfaces)] TestableLogger log, + IServiceErrorMessageExtractor extractor, + FlurlHttpExceptionHandler sut) + { + var resourceReader = new ResourceDataReader(typeof(FlurlHttpExceptionHandlerTest), "Data"); + var responseContent = resourceReader.ReadData("validation_error.json"); + + extractor.GetErrorMessage().Returns(responseContent); + await sut.ProcessServiceErrorMessages(extractor); + + var logs = log.Messages; + + logs.Should().BeEquivalentTo(new[] + { + "Reason: error one", + "Reason: error two" + }, + o => o.WithStrictOrdering() + ); + } + + [Test, AutoMockData] + public async Task Http_exception_print_plain_message( + [Frozen(Matching.ImplementedInterfaces)] TestableLogger log, + IServiceErrorMessageExtractor extractor, + FlurlHttpExceptionHandler sut) + { + var resourceReader = new ResourceDataReader(typeof(FlurlHttpExceptionHandlerTest), "Data"); + var responseContent = resourceReader.ReadData("database_locked_error.json"); + + extractor.GetErrorMessage().Returns(responseContent); + await sut.ProcessServiceErrorMessages(extractor); + + var logs = log.Messages; + + logs.Should().BeEquivalentTo(new[] + { + "Reason: database is locked\ndatabase is locked" + }, + o => o.WithStrictOrdering() + ); + } +}