Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Post Processing Issues via Sonarr v4 - NZBDRONE: Server returned status 405 #1964

Closed
neil-bh opened this issue Mar 25, 2023 · 15 comments
Closed

Comments

@neil-bh
Copy link

neil-bh commented Mar 25, 2023

Describe the bug
I have upgraded my version of Sonarr to v4 which is the newest release which uses .NET instead of Mono. This lines up with Radarr v4. It looks great, but back on topic... After getting over the fact that I refreshed the API key for Sonarr and Radarr, I went back and updated any apps that used with the correct API key as well as updating the autoProcessMedia.cfg with the new API keys.

I now seem to be getting a 405 error when the post processing runs the nzbToMedia script. From the logs I can see that the TV show is downloaded successfully and unzipped etc. Then when the post processing starts I noticed a line in the logs that says:
nzbToMedia: [00:01:36] [WARNING]::MAIN: Connection to NzbDrone:TV failed! Check your configuration
then further on it says:
nzbToMedia: [00:01:37] [ERROR]::NZBDRONE: Server returned status 405. I've enabled the logging options to get a more verbose output which I will paste below.

Technical Specs

  1. Running on: Linux (Ubuntu 22.04.2 LTS)
  2. Python version: 3.10.6
  3. Download Client: NZBget (21.2-testing-r2333)
  4. Intended Media Management: Radarr (4.4.2.6956) and Sonarr (4.0.0.412)

Expected behaviour
My expectations are that it would perform as it previously did so when using Sonarr v3. I'm not sure what the 405 error is representing, nor do I understand or know how to troubleshoot the fact that the script is claiming it has an issue talking to Sonarr/Nzbdrone. The log file also mentions 2023-03-25 20:21:22 INFO ::MAIN: NzbDrone:TV Could not create a fork object for default. Probably class not added yet. which looks unusual. Do you have any ideas or pointers that can help?

Note: It is worth pointing out that the post processing on Radarr downloads (using the Radarr script category 'Movies' is working fine).

Log

2023-03-25 20:01:54 INFO    ::MAIN: Python v3.10 will reach end of life in 1286 days.
2023-03-25 20:01:54 INFO    ::MAIN: Checking database structure...
2023-03-25 20:01:54 DEBUG   ::MAIN: Checking Initial Schema database upgrade
2023-03-25 20:01:54 DB      ::MAIN: nzbtomedia.db: SELECT 1 FROM sqlite_master WHERE name = ?; with args ('db_version',)
2023-03-25 20:01:54 DB      ::MAIN: nzbtomedia.db: SELECT db_version FROM db_version
2023-03-25 20:01:54 DEBUG   ::MAIN: InitialSchema upgrade not required
2023-03-25 20:01:54 DEBUG   ::MAIN: Checking if we can use git commands: git version
2023-03-25 20:01:54 DEBUG   ::MAIN: Executing git version with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:54 DEBUG   ::MAIN: git output: git version 2.34.1
2023-03-25 20:01:54 DEBUG   ::MAIN: git version : returned successful
2023-03-25 20:01:54 DEBUG   ::MAIN: Using: git
2023-03-25 20:01:54 DEBUG   ::MAIN: Executing git symbolic-ref -q HEAD with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:54 DEBUG   ::MAIN: git output: refs/heads/master
2023-03-25 20:01:54 DEBUG   ::MAIN: git symbolic-ref -q HEAD : returned successful
2023-03-25 20:01:54 INFO    ::MAIN: Checking if git needs an update
2023-03-25 20:01:54 DEBUG   ::MAIN: Executing git rev-parse HEAD with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:54 DEBUG   ::MAIN: git output: bd9c91ff5e8ee801d9b7a52843a2be8317eb688e
2023-03-25 20:01:54 DEBUG   ::MAIN: git rev-parse HEAD : returned successful
2023-03-25 20:01:54 DEBUG   ::MAIN: Executing git fetch origin with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:55 DEBUG   ::MAIN: git output: 
2023-03-25 20:01:55 DEBUG   ::MAIN: git fetch origin : returned successful
2023-03-25 20:01:55 DEBUG   ::MAIN: Executing git rev-parse --verify --quiet '@{upstream}' with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:55 DEBUG   ::MAIN: git output: bd9c91ff5e8ee801d9b7a52843a2be8317eb688e
2023-03-25 20:01:55 DEBUG   ::MAIN: git rev-parse --verify --quiet '@{upstream}' : returned successful
2023-03-25 20:01:55 DEBUG   ::MAIN: Executing git rev-list --left-right '@{upstream}'...HEAD with your shell in /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia
2023-03-25 20:01:55 DEBUG   ::MAIN: git output: 
2023-03-25 20:01:55 DEBUG   ::MAIN: git rev-list --left-right '@{upstream}'...HEAD : returned successful
2023-03-25 20:01:55 DEBUG   ::MAIN: cur_commit = bd9c91ff5e8ee801d9b7a52843a2be8317eb688e % (newest_commit)= bd9c91ff5e8ee801d9b7a52843a2be8317eb688e, num_commits_behind = 0, num_commits_ahead = 0
2023-03-25 20:01:55 INFO    ::MAIN: No update needed
2023-03-25 20:01:55 INFO    ::MAIN: nzbToMedia Version:bd9c91ff5e8ee801d9b7a52843a2be8317eb688e Branch:master (Linux 5.15.0-67-generic)
2023-03-25 20:01:55 INFO    ::MAIN: #########################################################
2023-03-25 20:01:55 INFO    ::MAIN: ## ..::[nzbToMedia.py]::.. ##
2023-03-25 20:01:55 INFO    ::MAIN: #########################################################
2023-03-25 20:01:55 DEBUG   ::MAIN: Options passed into nzbToMedia: ['/diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia/nzbToMedia.py']
2023-03-25 20:01:55 INFO    ::MAIN: Script triggered from NZBGet Version 21.2-testing-r2333.
2023-03-25 20:01:55 DEBUG   ::MAIN: Adding NZB download info for directory /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta to database
2023-03-25 20:01:55 DB      ::MAIN: nzbtomedia.db: UPDATE downloads SET input_name = ?, input_hash = ?, input_id = ?, client_agent = ?, status = ?, last_update = ? WHERE input_directory = ? with args ['Bel-Air.S02E05.720p.HEVC.x265-MeGusta', '44afa7a48323465aadfa2f44492ff632', '44afa7a48323465aadfa2f44492ff632', 'nzbget', 0, 738604, '/diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta']
2023-03-25 20:01:55 DB      ::MAIN: nzbtomedia.db: INSERT OR IGNORE INTO downloads (input_name, input_hash, input_id, client_agent, status, last_update) VALUES (?, ?, ?, ?, ?, ?) with args ['Bel-Air.S02E05.720p.HEVC.x265-MeGusta', '44afa7a48323465aadfa2f44492ff632', '44afa7a48323465aadfa2f44492ff632', 'nzbget', 0, 738604]
2023-03-25 20:01:55 INFO    ::MAIN: Auto-detected SECTION:NzbDrone
2023-03-25 20:01:55 INFO    ::MAIN: Calling NzbDrone:TV to post-process:Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55 DEBUG   ::SERVER: Attempting to connect to server at http://127.0.0.1:6002/sonarr
2023-03-25 20:01:55 DEBUG   ::SERVER: Server responded at http://127.0.0.1:6002/sonarr
2023-03-25 20:01:55 INFO    ::MAIN: Attempting to verify TV fork
2023-03-25 20:01:55 WARNING ::MAIN: Connection to NzbDrone:TV failed! Check your configuration
2023-03-25 20:01:55 INFO    ::MAIN: NzbDrone:TV fork set to default
2023-03-25 20:01:55 DEBUG   ::MAIN: Create object for fork default
2023-03-25 20:01:55 INFO    ::MAIN: NzbDrone:TV Could not create a fork object for default. Probaly class not added yet.
2023-03-25 20:01:55 DEBUG   ::EXCEPTION: Replacing file name e37f7c53dac44a679172dd026c2ca813 with directory name Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55 DEBUG   ::EXCEPTION: Replacing file name /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta/e37f7c53dac44a679172dd026c2ca813.mkv with download name /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta/Bel-Air.S02E05.720p.HEVC.x265-MeGusta.mkv
2023-03-25 20:01:55 INFO    ::MAIN: FLATTEN: Flattening directory: /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55 DEBUG   ::MAIN: Checking for empty folders in:/diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55 DEBUG   ::MAIN: calling command: /usr/bin/ffprobe -v quiet -print_format json -show_format -show_streams -show_error /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia/tests/test.mp4
2023-03-25 20:01:55 INFO    ::TRANSCODER: Checking [Bel-Air.S02E05.720p.HEVC.x265-MeGusta.mkv] for corruption, please stand by ...
2023-03-25 20:01:55 DEBUG   ::MAIN: calling command: /usr/bin/ffprobe -v quiet -print_format json -show_format -show_streams -show_error /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta/Bel-Air.S02E05.720p.HEVC.x265-MeGusta.mkv
2023-03-25 20:01:55 INFO    ::TRANSCODER: SUCCESS: [Bel-Air.S02E05.720p.HEVC.x265-MeGusta.mkv] has no corruption.
2023-03-25 20:01:55 POSTPROCESS::NZBDRONE: SUCCESS: The download succeeded, sending a post-process request
2023-03-25 20:01:55 DEBUG   ::NZBDRONE: path: /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55 DEBUG   ::NZBDRONE: Opening URL: http://127.0.0.1:6002/sonarr/api/command with data: {"name": "DownloadedEpisodesScan", "path": "/diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.720p.HEVC.x265-MeGusta", "downloadClientId": "44afa7a48323465aadfa2f44492ff632", "importMode": "Copy"}
2023-03-25 20:01:55 ERROR   ::NZBDRONE: Server returned status 405
2023-03-25 20:01:55 ERROR   ::MAIN: A problem was reported in the /diskpool1-raidz1/NAS/LinuxStore/nzbget/scripts/nzbToMedia/nzbToMedia.py script.
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: LANG: en_GB.UTF-8
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: LANGUAGE: en_GB:en
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: PATH: /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: HOME: /home/wizzkidd
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: LOGNAME: wizzkidd
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: USER: wizzkidd
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: SHELL: /bin/bash
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: INVOCATION_ID: a99f4f1a1f084c1f8c06c17de6a77d8c
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: JOURNAL_STREAM: 8:24473
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: SYSTEMD_EXEC_PID: 1730
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_NZBID: 5261
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_NZBNAME: Bel-Air.S02E05.Excellence.Is.Everywhere.1080p.STAN.WEB-DL.DDP5.1.H.264-NTb
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_DIRECTORY: /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV/Bel-Air.S02E05.Excellence.Is.Everywhere.1080p.STAN.WEB-DL.DDP5.1.H.264-NTb
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_NZBFILENAME: Bel-Air.S02E05.Excellence.Is.Everywhere.1080p.STAN.WEB-DL.DDP5.1.H.264-NTb.nzb
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_QUEUEDFILE: /diskpool1-raidz1/NAS/LinuxStore/nzbget/nzb/Bel-Air.S02E05.Excellence.Is.Everywhere.1080p.STAN.WEB-DL.DDP5.1.H.264-NTb.nzb.9.queued
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_URL: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_FINALDIR: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPP_CATEGORY: TV
### TRUNCATED SOME LINES ###
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPR_nzbToMedia.py:: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPR_NZBTOMEDIA_PY_: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_auto_update: 1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_AUTO_UPDATE: 1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_check_media: 1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_CHECK_MEDIA: 1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_safe_mode: 1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_SAFE_MODE: 1
### TRUNCATED SOME LINES ###
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndCategory: TV
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDCATEGORY: TV
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndhost: 127.0.0.1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDHOST: 127.0.0.1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndport: 6002
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDPORT: 6002
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndapikey: ed5e002cb9cc4da2b6f435d9543a2633
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDAPIKEY: ed5e002cb9cc4da2b6f435d9543a2633
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndssl: 0
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDSSL: 0
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_ndweb_root: /sonarr
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_NDWEB_ROOT: /sonarr
### TRUNCATED SOME LINES ###
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_raCategory: Movies
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RACATEGORY: Movies
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_rahost: 127.0.0.1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RAHOST: 127.0.0.1
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_raport: 6003
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RAPORT: 6003
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_raapikey: f1c8fccb9b7d4ab38d3636dfe54bac70
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RAAPIKEY: f1c8fccb9b7d4ab38d3636dfe54bac70
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_rassl: 0
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RASSL: 0
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_raweb_root: /radarr
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBPO_RAWEB_ROOT: /radarr
### TRUNCATED SOME LINES ###
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category1.Name: TV
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY1_NAME: TV
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category1.DestDir: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY1_DESTDIR: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category1.Unpack: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY1_UNPACK: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category1.Extensions: nzbToMedia.py
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY1_EXTENSIONS: nzbToMedia.py
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category1.Aliases: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY1_ALIASES: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category2.Name: Movies
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY2_NAME: Movies
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category2.DestDir: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY2_DESTDIR: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category2.Unpack: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY2_UNPACK: yes
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category2.Extensions: nzbToMedia.py
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY2_EXTENSIONS: nzbToMedia.py
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_Category2.Aliases: 
2023-03-25 20:21:20 INFO    ::ENVIRONMENT: NZBOP_CATEGORY2_ALIASES: 
### TRUNCATED SOME LINES ###
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndCategory: TV
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDCATEGORY: TV
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndhost: 127.0.0.1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDHOST: 127.0.0.1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndport: 6002
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDPORT: 6002
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndapikey: ed5e002cb9cc4da2b6f435d9543a2633
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDAPIKEY: ed5e002cb9cc4da2b6f435d9543a2633
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndssl: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDSSL: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndweb_root: /sonarr
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDWEB_ROOT: /sonarr
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndwait_for: 2
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDWAIT_FOR: 2
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:nddelete_failed: 1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDDELETE_FAILED: 1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:ndremote_path: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_NDREMOTE_PATH: 0
### TRUNCATED SOME LINES ###
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:raCategory: Movies
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RACATEGORY: Movies
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:rahost: 127.0.0.1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAHOST: 127.0.0.1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:raport: 6003
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAPORT: 6003
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:raapikey: f1c8fccb9b7d4ab38d3636dfe54bac70
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAAPIKEY: f1c8fccb9b7d4ab38d3636dfe54bac70
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:rassl: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RASSL: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:raweb_root: /radarr
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAWEB_ROOT: /radarr
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:rawait_for: 2
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAWAIT_FOR: 2
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:radelete_failed: 1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RADELETE_FAILED: 1
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:raremote_path: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_RAREMOTE_PATH: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_nzbToMedia.py:sbignore_subs: 0
2023-03-25 20:21:21 INFO    ::ENVIRONMENT: NZBOP_NZBTOMEDIA_PY_SBIGNORE_SUBS: 0
### TRUNCATED SOME LINES ###
@clinton-hall
Copy link
Owner

are there any sonarr logs generated at 2023-03-25 20:01:55 ?

The 405 error indicates the url is not a valid method. So I wonder if sonarr no longer supports the api/command "DownloadedEpisodesScan"

@neil-bh
Copy link
Author

neil-bh commented Mar 28, 2023

I've had a look at the Radarr logs, and I can see on the 5th line at 2023-03-25 20:01:55.5 what looks to be an error complaining that the Authorization header information was missing during authentication...

2023-03-25 19:58:10.1|Info|ReleaseSearchService|Searching indexers for [Bel-Air : S02E05]. 1 active indexers
2023-03-25 19:58:11.0|Info|DownloadDecisionMaker|Processing 17 releases
2023-03-25 20:01:12.0|Info|Nzbget|Adding report [Bel-Air.S02E05.720p.HEVC.x265-MeGusta] to the queue.
2023-03-25 20:01:12.2|Info|DownloadService|Report sent to NZBGet. Indexer NzbPlanet (Prowlarr). Bel-Air.S02E05.720p.HEVC.x265-MeGusta
2023-03-25 20:01:55.5|Info|Sonarr.Http.Authentication.BasicAuthenticationHandler|Basic was not authenticated. Failure message: Authorization header missing.
2023-03-25 20:02:37.7|Info|ImportListSyncService|Starting Import List Sync
2023-03-25 20:02:37.7|Info|ImportListSyncService|Processing 0 list items

I've seen in previously raised issues on this github that there were changes made in the past that required additional header details to be included in the API calls, could this be similar?

UPDATE 1 (25/02/2023): I just stumbled across this post while googling and although the post hasn't been answered, it appears that the line in the log file might be misleading. I noticed in Sonarr v4, they've enforced authentication during the first run wizard. However unlike Radarr v4 I am able to modifying the config.xml to <AuthenticationMethod>None</AuthenticationMethod> in order for the GUI to display "None". I'm behind a reverse proxy and have basic authentication setup at the proxy level to avoid double-authentication. Sonarr v4 doesn't seem to allow me to chose "None" in the GUI or via the XML, so I have modified the config.xml to <AuthenticationMethod>Basic</AuthenticationMethod> with the additional line <AuthenticationRequired>DisabledForLocalAddresses</AuthenticationRequired>. The docs say this is the way to prevent authentication for local addresses.

There is a possibility that this is a "me problem" and I need to figure out how to configure the authentication method so that nzbToMedia is happy.

UPDATE 2 (28/02/2023): I'm starting to think that this isn't necessarily a "me problem" after all. I have tried every auth option available in the GUI and the External method suggested in the docs, but having spent hours trying each method and then downloading a TV episode, they all show the same error in the logs (I'm paying more attention to the Sonarr logs this time too). The only potentially useful feedback from my troubleshooting is that I noticed that Sonarr have their authentication be mandatory whereas Radarr doesn't. Sonarr make you select a auth method and then provide a username and password, but Radarr allows you to select None therefore not asking for a username and password. I've no idea if that feedback is helpful but it's all I can conclude thus far.

UPDATE 3 (02/04/2023): I spent some more time trying to get clarity on the authentication method and it seems that with my setup, the correct settings are to set <AuthenticationMethod>External</AuthenticationMethod> and <AuthenticationRequired>DisabledForLocalAddresses</AuthenticationRequired>. As I understand it, this tells Sonarr that I only want to enforce authentication when accessing the services from an outside/external network, and accessing from a local network address will not be challenged. Unfortunately, the nzbToMedia post processing script still falls over when trying to communicate with Sonarr.

I hope someone is willing to help work through this with me - I'm pretty convinced this is an issue between nzbToMedia trying to talk to Radarr v4 and how it deals with auth (which seems to be a lot more strict compared to a few of the other *arr services).

I eagerly sit patiently hoping that this gets looked at, thanks.

@breezytm
Copy link

breezytm commented Apr 1, 2023

I started having issues as well. I think it began after upgrading Sonarr.

ERROR	Fri Mar 31 2023 22:33:07	Post-process-script nzbToMedia/nzbToNzbDrone.py for Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES failed
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: NzbDrone: Failed to post-process - Returned log from NzbDrone was not as expected.!
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: -- Cleanup finished --
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: Returning to directory: /
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: No folders to clean
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: -- Cleaning folders: ['libs', 'core'] --
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: b'Removing __pycache__/\n'
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: b'Removing __pycache__/\n'
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: -- Cleaning bytecode --
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: Changing to directory: /opt/nzbget/scripts/nzbToMedia
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [ERROR]::MAIN: A problem was reported in the /opt/nzbget/scripts/nzbToMedia/nzbToNzbDrone.py script.
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [WARNING]::NZBDRONE: No scan id was returned due to: list indices must be integers or slices, not str
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::NZBDRONE: Opening URL: http://localhost:8989/api/command with data: {"name": "DownloadedEpisodesScan", "path": "/opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES", "downloadClientId": "4bf22bb2d54447debb3855f736e5c132", "importMode": "Move"}
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::NZBDRONE: path: /opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [POSTPROCESS]::NZBDRONE: SUCCESS: The download succeeded, sending a post-process request
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::TRANSCODER: DISABLED: ffprobe failed to analyse test file. Stopping corruption check.
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [ERROR]::TRANSCODER: Checking [/opt/nzbget/scripts/nzbToMedia/tests/test.mp4] has failed
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: /usr/local/bin/ffprobe: error while loading shared libraries: libx264.so.148: cannot open shared object file: No such file or directory
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: calling command: /usr/local/bin/ffprobe -v quiet -print_format json -show_format -show_streams /opt/nzbget/scripts/nzbToMedia/tests/test.mp4
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: /usr/local/bin/ffprobe: error while loading shared libraries: libx264.so.148: cannot open shared object file: No such file or directory
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: calling command: /usr/local/bin/ffprobe -v quiet -print_format json -show_format -show_streams -show_error /opt/nzbget/scripts/nzbToMedia/tests/test.mp4
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: Checking for empty folders in:/opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: FLATTEN: Flattening directory: /opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: NzbDrone:tv Could not create a fork object for default. Probaly class not added yet.
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: Create object for fork default
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: NzbDrone:tv fork set to default
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: Attempting to verify tv fork
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::SERVER: Server responded at http://localhost:8989
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::SERVER: Attempting to connect to server at http://localhost:8989
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: Calling NzbDrone:tv to post-process:Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: Checking for archives to extract in directory: /opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: Auto-detected SECTION:NzbDrone
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::MAIN: Adding NZB download info for directory /opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES to database
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: Script triggered from NZBGet Version 21.1.
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBhUG]::MAIN: Options passed into nzbToMedia: ['/opt/nzbget/scripts/nzbToMedia/nzbToNzbDrone.py']
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: #########################################################
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: ## ..::[nzbToMedia.py]::.. ##
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [INFO]::MAIN: #########################################################

I think this where the problem lies

NFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [ERROR]::MAIN: A problem was reported in the /opt/nzbget/scripts/nzbToMedia/nzbToNzbDrone.py script.
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [WARNING]::NZBDRONE: No scan id was returned due to: list indices must be integers or slices, not str
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::NZBDRONE: Opening URL: http://localhost:8989/api/command with data: {"name": "DownloadedEpisodesScan", "path": "/opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES", "downloadClientId": "4bf22bb2d54447debb3855f736e5c132", "importMode": "Move"}
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [DEBUG]::NZBDRONE: path: /opt/nzbget/downloads/completed/tv/Real.Time.with.Bill.Maher.S21E10.720p.WEB.H264-CAKES
INFO	Fri Mar 31 2023 22:33:07	nzbToMedia/nzbToNzbDrone: [22:33:07] [POSTPROCESS]::NZBDRONE: SUCCESS: The download succeeded, sending a post-process request

@neil-bh
Copy link
Author

neil-bh commented Apr 2, 2023

What version of Sonarr are you using @breezytm ?

Your logs look different to mine. Your logs imply that the script is able to communicate with Radarr, which is where mine is failing.

@breezytm
Copy link

breezytm commented Apr 2, 2023

What version of Sonarr are you using @breezytm ?

Your logs look different to mine. Your logs imply that the script is able to communicate with Radarr, which is where mine is failing.

Sonarr version 2.0.0.5344

@breezytm
Copy link

breezytm commented Apr 2, 2023

I just realized I misread your issue. It is regarding the beta version of Sonarr. Unrelated. I will open my own issue.

@neil-bh
Copy link
Author

neil-bh commented Apr 17, 2023

Hi @clinton-hall et al,

Where is/are the TV Show files saved before the post processing starts?

My reason for asking is because the TV show begins downloading, gets to 100%, then unpacks successfully, but when the post processing fails, the files are deleted.

Ideally for the time being I'd like to manually copy the TV show file(s) into their correct location and rename them manually. At least that way I can still get the TV Shows in a semi-automated way while further investigations can continue into why the PP script is not playing ball with Sonarr v4.

Thanks.

@kmr1962
Copy link

kmr1962 commented Apr 17, 2023

From memory the issue is (partly) because the URL for API access has changed in V4 Sonarr
from "......./api/command" to"......../api/v3/command" (see https://sonarr.tv/docs/api/#/)

Edit the nzbToMedia file "nzbToMedia/core/auto_process/tv.py", and in the "elif section == 'NzbDrone':" section
change the 3 lines after "elif section == 'NzbDrone':" as below

    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"}

These are lines 320 to 322 in the version of tv.py that I have

It has been working for me for some time but I cant take credit for the solution, unfortunately I can't remember where I found it.

@clinton-hall
Copy link
Owner

@neil-bh
According to your previous logs the files are saved into /diskpool1-raidz1/NAS/LinuxStore/nzbget/completed/TV

from your logs, I can't see nzbToMedia deleting these files when the script fails... I would expect them to still be there.

I have added the above mentioned fix into a new branch Sonarr-apiv3 if you are able to change branch to that and test that would be great. Thanks @kmr1962 for the fix.

@kmr1962
Copy link

kmr1962 commented Apr 18, 2023

For info
I removed my modified nzbToMedia folder and replaced it with the "master" branch
and confirmed it fails PostProcessing (as expected).

I then replaced the "master" branch with the "Sonarr-apiv3" branch and that works.

@neil-bh
Copy link
Author

neil-bh commented Apr 18, 2023

I can also confirm that this is working when using the Sonarr-apiv3 branch.

@neil-bh
Copy link
Author

neil-bh commented Apr 20, 2023

From memory the issue is (partly) because the URL for API access has changed in V4 Sonarr from "......./api/command" to"......../api/v3/command" (see https://sonarr.tv/docs/api/#/)

Edit the nzbToMedia file "nzbToMedia/core/auto_process/tv.py", and in the "elif section == 'NzbDrone':" section change the 3 lines after "elif section == 'NzbDrone':" as below

    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"}

These are lines 320 to 322 in the version of tv.py that I have

It has been working for me for some time but I cant take credit for the solution, unfortunately I can't remember where I found it.

For credit purposes, I found the fix was discovered in this thread: #1908 (comment)

@brianredbeard
Copy link

@ulrick65
Copy link

Wow...I spent a lot of hours trying to figure this one out. I installed the V4 beta of Sonarr and had this issue...I don't know why my Google searches didn't show this earlier!

Great work @clinton-hall , you always amaze me with this program. Works like a champ now.

I assume at some point this would get merged in the master...but for now everything is working great!

Thank you!

@clinton-hall
Copy link
Owner

now in master branch

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

When branches are created from issues, their pull requests are automatically linked.

6 participants