search

clinton-hall / nzbToMedia

Provides NZB and Torrent postprocessing To CouchPotatoServer, SickBeard/SickRage, HeadPhones, Mylar and Gamez
GNU General Public License v3.0
674 stars 176 forks source link

Radarr v4 Returns Status 415 #1862

Closed gerbil42 closed 7 months ago

gerbil42 commented 3 years ago

Somehow I ended up on the Radarr Nightly Branch, currently on 4.0.0.5471.

I noticed that new movies weren't showing up with the regular frequency that I expected, so I looked at my Radarr history and since Oct 30th, every PostProc request via nzbToRadarr.py has ended in error with Radarr returning status 415.

Last night I turned on all the logging toggles I can think of in the cfg file and it doesn't seem to make a difference to the output to the log files, so I'm not sure what's going on there

Technical Specs

  1. Windows Server
  2. Python v 3.9.7 (no issues with NzbToSickbeard with Medusa)
  3. Download Client: NZBGet
  4. Radarr

Expected behavior Expected behavior is that Radarr successfully detects the incoming file that was successfully downloaded and moved to the correct destination folder.

Log 2021-11-10 10:39:55 INFO ::MAIN: Python v3.9 will reach end of life in 1425 days. 2021-11-10 10:39:55 INFO ::MAIN: Checking database structure... 2021-11-10 10:39:55 INFO ::MAIN: Checking if git needs an update 2021-11-10 10:39:57 INFO ::MAIN: No update needed 2021-11-10 10:39:57 INFO ::MAIN: nzbToMedia Version:48154d0c3c27b337355a184cb25fc8d0e30800d9 Branch:nightly (Windows 10) 2021-11-10 10:39:57 INFO ::MAIN: ######################################################### 2021-11-10 10:39:57 INFO ::MAIN: ## ..::[nzbToMedia.py]::.. ## 2021-11-10 10:39:57 INFO ::MAIN: ######################################################### 2021-11-10 10:39:57 INFO ::MAIN: Script triggered from NZBGet Version 21.2-testing-r2333. 2021-11-10 10:39:57 INFO ::MAIN: Auto-detected SECTION:Radarr 2021-11-10 10:39:57 INFO ::MAIN: Calling Radarr:Radarr to post-process: 2021-11-10 10:39:57 INFO ::MAIN: Attemping imdbID lookup for 2021-11-10 10:39:57 INFO ::MAIN: Searching folder and file names for imdbID ... 2021-11-10 10:39:57 INFO ::MAIN: Searching IMDB for imdbID ... 2021-11-10 10:39:57 INFO ::MAIN: Unable to determine imdbID: No api key provided for omdbapi.com. 2021-11-10 10:39:58 INFO ::TRANSCODER: Checking for corruption, please stand by ... 2021-11-10 10:39:59 INFO ::TRANSCODER: SUCCESS: has no corruption. 2021-11-10 10:39:59 POSTPROCESS::RADARR: Starting DownloadedMoviesScan scan for 2021-11-10 10:39:59 ERROR ::RADARR: Server returned status 415 2021-11-10 10:39:59 ERROR ::MAIN: A problem was reported in the D:\NZBToMedia\nzbToRadarr.py script.

clinton-hall commented 3 years ago

to increase logging, in nzbToMedia.cfg

[General]
   log_debug = 1

hopefully this will show which api call causes the issue. Also, look in Radarr logs at 2021-11-10 10:39:59 to see what Radarr logged.

Out of curiosity, do you access Radarr via http or https? in autoProcessMedia.cfg have you set ssl (if using https in Radarr).

[Radarr]
    [[radarr]]
        ssl = 0
gerbil42 commented 3 years ago

No SSL between NZBGet, Radarr, and NzbToMedia. They're all on the same system, so it's also not network connectivity.

log_debug was on for the log snippet I pasted. I also expected more to be there.

[General]
    # Enable/Disable update notifications
    version_notify = 1
    # Enable/Disable automatic updates
    auto_update = 1
    # Set to the full path to the git executable
    git_path = C:\Program Files\Git\bin\git.exe
    # GitHUB user for repo
    git_user = ""
    # GitHUB branch for repo
    git_branch = nightly
    # Enable/Disable forceful cleaning of leftover files following postprocess
    force_clean = 1
    # Enable/Disable logging debug messages to nzbtomedia.log
    log_debug = 1
    # Enable/Disable logging database messages to nzbtomedia.log
    log_db = 1
    # Enable/Disable logging environment variables to debug nzbtomedia.log (helpful to track down errors calling external tools.)
    log_env = 1
    # Enable/Disable logging git output to debug nzbtomedia.log (helpful to track down update failures.)
    log_git = 1

Here's the Radarr log snippet for the same time period

2021-11-10 10:39:57.8|Info|Radarr.Http.Authentication.ApiKeyAuthenticationHandler|AuthenticationScheme: API was challenged.
2021-11-10 10:41:15.4|Info|NzbSearchService|Searching indexers for <movie>. 2 active indexers
2021-11-10 10:41:16.2|Info|DownloadDecisionMaker|Processing 39 releases
2021-11-10 10:41:18.7|Info|Nzbget|Adding report <movie> to the queue.
2021-11-10 10:41:21.5|Info|DownloadService|Report sent to NZBGet. <movie>
2021-11-10 10:41:21.5|Info|MovieSearchService|Movie search completed. 1 reports downloaded.
2021-11-10 10:44:35.2|Info|Radarr.Http.Authentication.ApiKeyAuthenticationHandler|AuthenticationScheme: API was challenged.
2021-11-10 10:45:45.4|Info|NzbSearchService|Searching indexers for <movie>. 2 active indexers
2021-11-10 10:45:48.0|Info|DownloadDecisionMaker|Processing 38 releases
2021-11-10 10:45:48.2|Info|MovieSearchService|Movie search completed. 0 reports downloaded.
gerbil42 commented 3 years ago 
2021-11-10 13:44:21 INFO    ::MAIN: Python v3.9 will reach end of life in 1425 days.
2021-11-10 13:44:21 INFO    ::MAIN: Checking database structure...
2021-11-10 13:44:21 DEBUG   ::MAIN: Checking Initial Schema database upgrade
2021-11-10 13:44:21 DB      ::MAIN: nzbtomedia.db: SELECT 1 FROM sqlite_master WHERE name = ?; with args ('db_version',)
2021-11-10 13:44:21 DB      ::MAIN: nzbtomedia.db: SELECT db_version FROM db_version
2021-11-10 13:44:21 DEBUG   ::MAIN: InitialSchema upgrade not required
2021-11-10 13:44:21 DEBUG   ::MAIN: Checking if we can use git commands: "C:\Program Files\Git\bin\git.exe" version
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" version with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: git version 2.31.1.windows.1
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" version : returned successful
2021-11-10 13:44:21 DEBUG   ::MAIN: Using: "C:\Program Files\Git\bin\git.exe"
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" symbolic-ref -q HEAD with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: refs/heads/nightly
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" symbolic-ref -q HEAD : returned successful
2021-11-10 13:44:21 INFO    ::MAIN: Checking if git needs an update
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" rev-parse HEAD with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: 48154d0c3c27b337355a184cb25fc8d0e30800d9
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" rev-parse HEAD : returned successful
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" fetch origin with your shell in D:\NZBToMedia
2021-11-10 13:44:22 DEBUG   ::MAIN: git output: 
2021-11-10 13:44:22 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" fetch origin : returned successful
2021-11-10 13:44:22 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" rev-parse --verify --quiet '@{upstream}' with your shell in D:\NZBToMedia
2021-11-10 13:44:22 DEBUG   ::MAIN: git output: fatal: no such branch: '''
2021-11-10 13:44:22 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" rev-parse --verify --quiet '@{upstream}' returned : fatal: no such branch: '''
2021-11-10 13:44:22 DEBUG   ::MAIN: git didn't return newest commit hash
2021-11-10 13:44:22 INFO    ::MAIN: No update needed
2021-11-10 13:44:22 INFO    ::MAIN: nzbToMedia Version:48154d0c3c27b337355a184cb25fc8d0e30800d9 Branch:nightly (Windows 10)
2021-11-10 13:44:22 INFO    ::MAIN: #########################################################
2021-11-10 13:44:22 INFO    ::MAIN: ## ..::[nzbToMedia.py]::.. ##
2021-11-10 13:44:22 INFO    ::MAIN: #########################################################
2021-11-10 13:44:22 DEBUG   ::MAIN: Options passed into nzbToMedia: ['D:\\NZBToMedia\\nzbToRadarr.py']
2021-11-10 13:44:22 INFO    ::MAIN: Script triggered from NZBGet Version 21.2-testing-r2333.
2021-11-10 13:44:22 DEBUG   ::MAIN: Adding NZB download info for directory D:\NZBGet\AppData\complete\Radarr\<movie> to database
2021-11-10 13:44:22 DB      ::MAIN: nzbtomedia.db: UPDATE downloads SET input_name = ?, input_hash = ?, input_id = ?, client_agent = ?, status = ?, last_update = ? WHERE input_directory = ? with args ['<movie>', '3628e1c882e94fb8a906ad93d15002db', '3628e1c882e94fb8a906ad93d15002db', 'nzbget', 0, 738104, 'D:\\NZBGet\\AppData\\complete\\Radarr\\<movie>']
2021-11-10 13:44:22 DB      ::MAIN: nzbtomedia.db: INSERT OR IGNORE INTO downloads (input_name, input_hash, input_id, client_agent, status, last_update) VALUES (?, ?, ?, ?, ?, ?) with args ['<movie>', '2021-11-10 13:44:21 INFO    ::MAIN: Python v3.9 will reach end of life in 1425 days.
2021-11-10 13:44:21 INFO    ::MAIN: Checking database structure...
2021-11-10 13:44:21 DEBUG   ::MAIN: Checking Initial Schema database upgrade
2021-11-10 13:44:21 DB      ::MAIN: nzbtomedia.db: SELECT 1 FROM sqlite_master WHERE name = ?; with args ('db_version',)
2021-11-10 13:44:21 DB      ::MAIN: nzbtomedia.db: SELECT db_version FROM db_version
2021-11-10 13:44:21 DEBUG   ::MAIN: InitialSchema upgrade not required
2021-11-10 13:44:21 DEBUG   ::MAIN: Checking if we can use git commands: "C:\Program Files\Git\bin\git.exe" version
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" version with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: git version 2.31.1.windows.1
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" version : returned successful
2021-11-10 13:44:21 DEBUG   ::MAIN: Using: "C:\Program Files\Git\bin\git.exe"
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" symbolic-ref -q HEAD with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: refs/heads/nightly
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" symbolic-ref -q HEAD : returned successful
2021-11-10 13:44:21 INFO    ::MAIN: Checking if git needs an update
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" rev-parse HEAD with your shell in D:\NZBToMedia
2021-11-10 13:44:21 DEBUG   ::MAIN: git output: 48154d0c3c27b337355a184cb25fc8d0e30800d9
2021-11-10 13:44:21 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" rev-parse HEAD : returned successful
2021-11-10 13:44:21 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" fetch origin with your shell in D:\NZBToMedia
2021-11-10 13:44:22 DEBUG   ::MAIN: git output: 
2021-11-10 13:44:22 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" fetch origin : returned successful
2021-11-10 13:44:22 DEBUG   ::MAIN: Executing "C:\Program Files\Git\bin\git.exe" rev-parse --verify --quiet '@{upstream}' with your shell in D:\NZBToMedia
2021-11-10 13:44:22 DEBUG   ::MAIN: git output: fatal: no such branch: '''
2021-11-10 13:44:22 DEBUG   ::MAIN: "C:\Program Files\Git\bin\git.exe" rev-parse --verify --quiet '@{upstream}' returned : fatal: no such branch: '''
2021-11-10 13:44:22 DEBUG   ::MAIN: git didn't return newest commit hash
2021-11-10 13:44:22 INFO    ::MAIN: No update needed
2021-11-10 13:44:22 INFO    ::MAIN: nzbToMedia Version:48154d0c3c27b337355a184cb25fc8d0e30800d9 Branch:nightly (Windows 10)
2021-11-10 13:44:22 INFO    ::MAIN: #########################################################
2021-11-10 13:44:22 INFO    ::MAIN: ## ..::[nzbToMedia.py]::.. ##
2021-11-10 13:44:22 INFO    ::MAIN: #########################################################
2021-11-10 13:44:22 DEBUG   ::MAIN: Options passed into nzbToMedia: ['D:\\NZBToMedia\\nzbToRadarr.py']
2021-11-10 13:44:22 INFO    ::MAIN: Script triggered from NZBGet Version 21.2-testing-r2333.
2021-11-10 13:44:22 DEBUG   ::MAIN: Adding NZB download info for directory D:\NZBGet\AppData\complete\Radarr\<movie> to database
2021-11-10 13:44:22 DB      ::MAIN: nzbtomedia.db: UPDATE downloads SET input_name = ?, input_hash = ?, input_id = ?, client_agent = ?, status = ?, last_update = ? WHERE input_directory = ? with args ['Shang-chi.and.the.Legend.of.the.Ten.Rings.2021.720p.BluRay.x264-x0r', '3628e1c882e94fb8a906ad93d15002db', '3628e1c882e94fb8a906ad93d15002db', 'nzbget', 0, 738104, 'D:\\NZBGet\\AppData\\complete\\Radarr\\<movie>']
2021-11-10 13:44:22 DB      ::MAIN: nzbtomedia.db: INSERT OR IGNORE INTO downloads (input_name, input_hash, input_id, client_agent, status, last_update) VALUES (?, ?, ?, ?, ?, ?) with args ['<movie>', '3628e1c882e94fb8a906ad93d15002db', '3628e1c882e94fb8a906ad93d15002db', 'nzbget', 0, 738104]
2021-11-10 13:44:22 INFO    ::MAIN: Auto-detected SECTION:Radarr
2021-11-10 13:44:22 INFO    ::MAIN: Calling Radarr:Radarr to post-process:<movie>
2021-11-10 13:44:22 INFO    ::MAIN: Attemping imdbID lookup for <movie>
2021-11-10 13:44:22 INFO    ::MAIN: Searching folder and file names for imdbID ...
2021-11-10 13:44:22 INFO    ::MAIN: Searching IMDB for imdbID ...
2021-11-10 13:44:22 INFO    ::MAIN: Unable to determine imdbID: No api key provided for omdbapi.com.
2021-11-10 13:44:22 DEBUG   ::SERVER: Attempting to connect to server at http://localhost:7878/api/v3/command
2021-11-10 13:44:22 DEBUG   ::SERVER: Server responded at http://localhost:7878/api/v3/command
2021-11-10 13:44:22 DEBUG   ::EXCEPTION: Replacing file name YWDA4zSOHtPkE with directory name <movie>
2021-11-10 13:44:22 DEBUG   ::EXCEPTION: Replacing file name D:\NZBGet\AppData\complete\Radarr\<movie>.mkv with download name D:\NZBGet\AppData\complete\Radarr\<movie>.mkv
2021-11-10 13:44:22 DEBUG   ::MAIN: calling command: D:\NZBToMedia\FFMpeg\bin\ffprobe.exe -v quiet -print_format json -show_format -show_streams -show_error D:\NZBToMedia\tests\test.mp4
2021-11-10 13:44:22 INFO    ::TRANSCODER: Checking [<movie>.mkv] for corruption, please stand by ...
2021-11-10 13:44:22 DEBUG   ::MAIN: calling command: D:\NZBToMedia\FFMpeg\bin\ffprobe.exe -v quiet -print_format json -show_format -show_streams -show_error D:\NZBGet\AppData\complete\Radarr\<movie>\<movie>.mkv
2021-11-10 13:44:22 INFO    ::TRANSCODER: SUCCESS: [<movie>.mkv] has no corruption.
2021-11-10 13:44:22 DEBUG   ::RADARR: Opening URL: http://localhost:7878/api/v3/command with PARAMS: {'name': 'DownloadedMoviesScan', 'path': 'D:\\NZBGet\\AppData\\complete\\Radarr\\<movie>', 'downloadClientId': '3628e1c882e94fb8a906ad93d15002db', 'importMode': 'Move'}
2021-11-10 13:44:22 POSTPROCESS::RADARR: Starting DownloadedMoviesScan scan for <movie>
2021-11-10 13:44:22 ERROR   ::RADARR: Server returned status 415
2021-11-10 13:44:22 ERROR   ::MAIN: A problem was reported in the D:\NZBToMedia\nzbToRadarr.py

Looks like I have git update check issues, which explains why I usually have to manually check for updates, but that doesn't seem to be related.

clinton-hall commented 3 years ago

Radarr.Http.Authentication.ApiKeyAuthenticationHandler|AuthenticationScheme: API was challenged.

check that the api key is correct:

[Radarr]
    [[Radarr]]
        apikey =
gerbil42 commented 3 years ago

Confirmed that the API key IS correct

buzzke commented 3 years ago

Endured the same problem. Seems like an issue in the nightly version of Radarr. Nightly version of Radarr and Nzbtomedia branch master or nightly had the same issue --> Server returned status 415 Went back to latest version of Radarr with branch master or nighty --> no more issues.

gerbil42 commented 3 years ago

I'll probably bite the bullet and rollback to Radarr Master which looks to be on 3.2.2.5080 from June. Was hoping this was another case of a breaking change by Radarr that would take Clinton a couple minutes to fix.

clinton-hall commented 3 years ago

It "may" only take me a few minutes to fix... the problem is the logs don't tell me what is going wrong. I read the Radarr api guidance and I couldn't see anything different. But that guidance may be for master (not sure where to get guidance for the nightly). Likewise I tried having a look at changes in nightly and nothing stood out regarding api...

If you are able to find anything about changes to api in v4... hmm... it's not something really basic like having to change the api version from 4 to 3?

Is there anything within Radarr itself that gives guidance on the api usage?

buzzke commented 3 years ago

Do u want us to reproduce the issue?

gerbil42 commented 3 years ago

I don't see anything in Radarr itself that would explain API usage The API documents on the site only mention v3 https://radarr.video/docs/api/ with no mention of v4.

I've rolled back to the latest master branch build at 3.2.x and can take a backup of this version working, roll forward, and test if needed.

BradKollmyer commented 3 years ago

I reviewed my Radarr logs and it looks like the problem started after this change was merged: https://github.com/Radarr/Radarr/pull/6628

I have trace and debug logs from Radarr, but they don't indicated anything else other than an API challenge that is unauthorized.

operinko commented 3 years ago

Seems to me that they changed the API to require a Content-Type: application/json header for the API calls. So, I attempted to edit core\auto_process\movies.py: Line 72-75, I added the header to it.

if section == 'Radarr':
        base_url = '{0}{1}:{2}{3}/api/v3/command'.format(protocol, host, port, web_root)
        url2 = '{0}{1}:{2}{3}/api/v3/config/downloadClient'.format(protocol, host, port, web_root)
        headers = {'X-Api-Key': apikey, "Content-Type": "application/json"}

And just to be sure, I did a similar thing on lines 365 and 509, where I just added: headers={'Content-Type': 'application/json'} to the existing requests.get line, like so:

#365
r = requests.get(url, params={'media_id': media_id}, verify=False, timeout=(30, 600), headers={'Content-Type': 'application/json'})

#509
r = requests.get(url, params=params, verify=False, timeout=(30, 60), headers={'Content-Type': 'application/json'})

After testing this for a few releases, I seem to have no more issues with "Server responded with 415"

operinko commented 3 years ago

I would do a PR, but python really isn't my strong suite and I'm not 100% sure if this is the right way to fix it

clinton-hall commented 3 years ago

Ok, thanks for this. I saw that they added the Content-Type, but thought that was a prompt/reminder that the data needed to be Json. Since we already were sending json data I never realised they now required this to be stated in the header.

The edits to lines 365 and 509 aren't required. they only pertain to CouchPotato calls. so All that is required is adding the "Content-Type": "application/json" in the headers at line 75.

I also don't know if this will cause any issues with Radarr V3 (master).

BradKollmyer commented 3 years ago

The fix worked for me! Thanks.

clinton-hall commented 3 years ago

currently in Radarr-V4 branch. I am ready to merge into nightly, but ideally would like confirmation this:

  1. Works with Radarr V4
  2. Still works with Radarr V3
gerbil42 commented 3 years ago

I'll test the Radarr V3 scenario with my rolled-back install shortly

Edit#2 - Success on V3

Styl4s commented 3 years ago

I can also confirm that this works successfully for V4 now.. I was also getting the dreaded 415 error when updated to the latest Radarr nightly. I also had a v3 container which continues to working using the same script!

Thanks @operinko @clinton-hall

clinton-hall commented 3 years ago

Merged in to nightly now.

daNutzzzzz commented 2 years ago

did this get merged into master? as im getting the same error running the lastest version of master.

clinton-hall commented 2 years ago

Yes, this was merged into master some time ago. What version is Radarr on now?

daNutzzzzz commented 2 years ago

Yes, this was merged into master some time ago. What version is Radarr on now?

4.1.0.6175