RadarrMovieNotFound: Movie not found exception when deleting files

[coolius]

Describe the bug When running the command to unmonitor and delete files in Radarr, I receive the following error message once the file deletion process starts. Interestingly, if I rerun the command (after remonitoring the unmonitored files), Excludarr will get one movie further along before throwing the error.

To Reproduce excludarr --debug radarr exclude -a not-monitored -d --progress -y

Expected behavior The matching movies should be marked as unmonitored and their files deleted.

Versions

1. OS Version: Ubuntu 20.04 LTS
2. Excludarr version: 1.06
3. Python version: 2.8

Debug logging

[2022-04-12 00:26:16] - Change monitored to False for movie with Radarr ID: 958
[2022-04-12 00:26:16] - Change monitored to False for movie with Radarr ID: 959
[2022-04-12 00:26:16] - Change monitored to False for movie with Radarr ID: 969
[2022-04-12 00:26:16] - Starting the process of deleting the files
[2022-04-12 00:26:16] - Checking if movie with Radarr ID: 3 has files
[2022-04-12 00:26:16] - Checking if movie with Radarr ID: 6 has files
[2022-04-12 00:26:16] - Checking if movie with Radarr ID: 10 has files
[2022-04-12 00:26:16] - Checking if movie with Radarr ID: 13 has files
[2022-04-12 00:26:16] - Deleting files for movie with Radarr ID: 13
Traceback (most recent call last):
  File "/home/cxp/.local/lib/python3.8/site-packages/requests/models.py", line 910, in json
    return complexjson.loads(self.text, **kwargs)
  File "/usr/lib/python3/dist-packages/simplejson/__init__.py", line 518, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 370, in decode
    obj, end = self.raw_decode(s)
  File "/usr/lib/python3/dist-packages/simplejson/decoder.py", line 400, in raw_decode
    return self.scan_once(s, idx=_w(s, idx).end())
simplejson.errors.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 61, in http_request
    return self._filter_api_error(result)
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 49, in _filter_api_error
    result_json = data.json()
  File "/home/cxp/.local/lib/python3.8/site-packages/requests/models.py", line 917, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
requests.exceptions.JSONDecodeError: [Errno Expecting value] : 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/excludarr", line 8, in <module>
    sys.exit(cli())
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/main.py", line 68, in cli
    app(prog_name="excludarr")
  File "/home/cxp/.local/lib/python3.8/site-packages/typer/main.py", line 214, in __call__
    return get_command(self)(*args, **kwargs)
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 1130, in __call__
    return self.main(*args, **kwargs)
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 1055, in main
    rv = self.invoke(ctx)
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 1657, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/cxp/.local/lib/python3.8/site-packages/click/core.py", line 760, in invoke
    return __callback(*args, **kwargs)
  File "/home/cxp/.local/lib/python3.8/site-packages/typer/main.py", line 500, in wrapper
    return callback(**use_params)  # type: ignore
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/commands/radarr.py", line 134, in exclude
    radarr.delete_files(movies_to_exclude_ids)
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/core/radarr_actions.py", line 252, in delete_files
    self.radarr_client.moviefile.delete_moviefile(moviefile["id"])
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/v3/moviefile.py", line 22, in delete_moviefile
    return self.client.http_delete(self.moviefile_id_path.format(id=id))
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 79, in http_delete
    return self.http_request("delete", path, json=json, params=params)
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 65, in http_request
    self.http_request(method, path, json, params, retries)
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 61, in http_request
    return self._filter_api_error(result)
  File "/home/cxp/.local/lib/python3.8/site-packages/excludarr/modules/pyradarr/__init__.py", line 45, in _filter_api_error
    raise RadarrMovieNotFound("Movie not found")
excludarr.modules.pyradarr.exceptions.RadarrMovieNotFound: Movie not found

Additional context None

[haijeploeg]

Can you post your configuration file (without the api keys) and the full debug logging? Also, which version of Radarr are you using? It seems that your instance cannot find the delete movie endpoint

[coolius]

Thanks for your response.

I am using Radarr version 4.0.5.5981 which I believe is the latest. I do not have the same issues when running Excludarr with Sonarr however.

Here is my configuration

general:
  fast_search: true
  locale: en_GB
  providers:
    - Netflix
    - Amazon Prime Video
    - Disney Plus
    - All 4
    - BBC iPlayer
    - Funimation Now
    - ITV Hub
    - UKTV Play
    - My5
    - Discovery Plus
    - Plex

tmdb:
  api_key: ****

radarr:
  url: 'http://localhost:7878'
  api_key: ****
  verify_ssl: false
  exclude:
    - 'Dave Chappelle: The Closer'

sonarr:
  url: 'http://localhost:8989'
  api_key: ****
  verify_ssl: false
  exclude:
    - Queen of the South

I have added a full debug here although it looks to be as expected until the point I posted in the original report.

Interestingly it does seem to successfully the delete the file for the movie it errors on, but it does not proceed to the next movie.

Thanks again, I hope I can get this working as it is a very useful app

[haijeploeg]

Hmm thats strange, maybe the api is returning something unexpected. I will have to debug this and try to reproduce the error. I will come back to you once I know more!

[coolius]

Thank you for your help. I try again with the latest version of Radarr but it made no difference. I thought it might be helpful to attach the debug log from Radarr

2022-04-17 11:43:50.9|Info|MediaFileDeletionService|Deleting movie file: /mnt/sdb1/Films/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv
2022-04-17 11:43:50.9|Debug|RecycleBinProvider|Attempting to send '/mnt/sdb1/Films/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv' to recycling bin
2022-04-17 11:43:50.9|Debug|RecycleBinProvider|Creating folder /mnt/sdb1/Recycling Bin/A View to a Kill (1985)
2022-04-17 11:43:50.9|Debug|RecycleBinProvider|Moving '/mnt/sdb1/Films/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv' to '/mnt/sdb1/Recycling Bin/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv'
2022-04-17 11:43:50.9|Debug|DiskTransferService|Move [/mnt/sdb1/Films/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv] > [/mnt/sdb1/Recycling Bin/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv]
2022-04-17 11:43:51.0|Debug|RecycleBinProvider|File has been moved to the recycling bin: /mnt/sdb1/Recycling Bin/A View to a Kill (1985)/A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv
2022-04-17 11:43:51.0|Debug|MovieService|Detaching movie 21 from file.
2022-04-17 11:43:51.0|Debug|Api|[DELETE] /api/v3/moviefile/21: 200.OK (121 ms)
2022-04-17 11:43:51.0|Debug|SubtitleFileService|Deleting Extra from database for movie file: [21] A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv
2022-04-17 11:43:51.0|Debug|OtherExtraFileService|Deleting Extra from database for movie file: [21] A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv
2022-04-17 11:43:51.0|Debug|MetadataFileService|Deleting Extra from database for movie file: [21] A View to a Kill (1985) [Bluray-1080p x264 DTS].mkv
2022-04-17 11:43:56.0|Error|Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware|An unhandled exception has occurred while executing the request.

[v4.1.0.6175] NzbDrone.Core.Datastore.ModelNotFoundException: MovieFile with ID 21 does not exist
   at NzbDrone.Core.Datastore.BasicRepository`1.Get(Int32 id) in D:\a\1\s\src\NzbDrone.Core\Datastore\BasicRepository.cs:line 97
   at NzbDrone.Core.MediaFiles.MediaFileService.GetMovie(Int32 id) in D:\a\1\s\src\NzbDrone.Core\MediaFiles\MediaFileService.cs:line 107
   at Radarr.Api.V3.MovieFiles.MovieFileController.DeleteMovieFile(Int32 id) in D:\a\1\s\src\Radarr.Api.V3\MovieFiles\MovieFileController.cs:line 167
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.<>c__DisplayClass33_0.<WrapVoidMethod>b__0(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.VoidResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Radarr.Http.Middleware.BufferingMiddleware.InvokeAsync(HttpContext context) in D:\a\1\s\src\Radarr.Http\Middleware\BufferingMiddleware.cs:line 28
   at Radarr.Http.Middleware.IfModifiedMiddleware.InvokeAsync(HttpContext context) in D:\a\1\s\src\Radarr.Http\Middleware\IfModifiedMiddleware.cs:line 41
   at Radarr.Http.Middleware.CacheHeaderMiddleware.InvokeAsync(HttpContext context) in D:\a\1\s\src\Radarr.Http\Middleware\CacheHeaderMiddleware.cs:line 33
   at Radarr.Http.Middleware.UrlBaseMiddleware.InvokeAsync(HttpContext context) in D:\a\1\s\src\Radarr.Http\Middleware\UrlBaseMiddleware.cs:line 27
   at Radarr.Http.Middleware.VersionMiddleware.InvokeAsync(HttpContext context) in D:\a\1\s\src\Radarr.Http\Middleware\VersionMiddleware.cs:line 28
   at Microsoft.AspNetCore.ResponseCompression.ResponseCompressionMiddleware.InvokeCore(HttpContext context)
   at Microsoft.AspNetCore.Authorization.Policy.AuthorizationMiddlewareResultHandler.HandleAsync(RequestDelegate next, HttpContext context, AuthorizationPolicy policy, PolicyAuthorizationResult authorizeResult)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)

2022-04-17 11:43:56.2|Debug|Api|[DELETE] /api/v3/moviefile/21: 404.NotFound (204 ms)

Is it just me or is it attempting to delete the moviefile twice?

[coolius]

Managed to debug the code myself and found that because the DELETE call does not return any JSON, it was throwing the JSONDecode exception and causing the retry mechanism to kick in despite the first request returning 200. Restoring the try block in filter_api_error from the previous version solves the problem.

def _filter_api_error(self, data):
        if data.status_code == 400:
            raise RadarrInvalidIdSupplied(
                "Invalid ID supplied! The error message is: {}".format(data.text)
            )
        elif data.status_code == 401:
            raise RadarrInvalidApiKey("Invalid API key")
        elif data.status_code == 404:
            raise RadarrMovieNotFound("Movie not found")
        elif data.status_code == 405:
            raise RadarrValidationException("Validation exception")

        try:
            result_json = data.json()
        except JSONDecodeError:
            return data.text

        return result_json

Not sure why know one else has encountered this issue though!

[haijeploeg]

Thanks for debugging it yourself. That is indeed correct, I'm going to replace my own Radarr and Sonarr clients by PyArr clients, those are already finished and maintained well. I hope to release it by the end of this week.

[haijeploeg]

Hi, I started the development of this in https://github.com/haijeploeg/excludarr/tree/feature/pyarr_intergration. I need to wait before intergrate this, because the sonarr support is broken as PyArr does not support the v3 api endpoint. I have requested a feature request: https://github.com/totaldebug/pyarr/issues/101. Once this is fixed I can release a new version.

[haijeploeg]

I have released a new version: v1.0.7. I have replaced my own libraries with the PyArr library, this issue should be fixed now.

[coolius]

Many thanks