fix: Better processing for HTTP 500 service responses

Fixes #206.

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

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;

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<IReadOnlyCollection<string>> GetValidationErrorsAsync(FlurlHttpException e)
-    {
-        var response = await e.GetResponseJsonAsync<List<dynamic>>();
-        if (response is null)
-        {
-            return Array.Empty<string>();
-        }
-
-        return response
-            .Select(x => (string) x.errorMessage)
-            .NotNull(x => !string.IsNullOrEmpty(x))
-            .ToList();
-    }
 }

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<JsonTextReader> _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<dynamic>, IEnumerable<object>> expr)
+    {
+        try
+        {
+            using var stream = _streamFactory();
+            var value = _serializer.Deserialize<List<dynamic>>(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<dynamic, object> expr)
+    {
+        try
+        {
+            using var stream = _streamFactory();
+            var value = _serializer.Deserialize<dynamic>(stream);
+            if (value is null)
+            {
+                return false;
+            }
+
+            _log.Error("Reason: {Message:l}", (string) expr(value));
+            return true;
+        }
+        catch
+        {
+            return false;
+        }
+    }
+}

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.");
+    }
+}

src/Recyclarr.Cli/Processors/ErrorHandling/IFlurlHttpExceptionHandler.cs

@@ -0,0 +1,6 @@
+namespace Recyclarr.Cli.Processors.ErrorHandling;
+
+public interface IFlurlHttpExceptionHandler
+{
+    Task ProcessServiceErrorMessages(IServiceErrorMessageExtractor extractor);
+}

src/Recyclarr.Cli/Processors/ErrorHandling/IServiceErrorMessageExtractor.cs

@@ -0,0 +1,6 @@
+namespace Recyclarr.Cli.Processors.ErrorHandling;
+
+public interface IServiceErrorMessageExtractor
+{
+    Task<string> GetErrorMessage();
+}

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<string> GetErrorMessage()
+    {
+        return await _e.GetResponseStringAsync();
+    }
+}

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<ConsoleExceptionHandler>();
+        builder.RegisterType<FlurlHttpExceptionHandler>().As<IFlurlHttpExceptionHandler>();
 
         // Sync
         builder.RegisterType<SyncProcessor>().As<ISyncProcessor>();

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;

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.<Create>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.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)\n   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)\n   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)\n   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>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.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)"
+}

src/tests/Recyclarr.Cli.Tests/Processors/ErrorHandling/Data/validation_error.json

@@ -0,0 +1,8 @@
+[
+  {
+    "errorMessage": "error one"
+  },
+  {
+    "errorMessage": "error two"
+  }
+]

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()
+        );
+    }
+}