Radarr Snatching the same or previously snatched quality

[Rouzax]

Describe the bug
Even though a 2160p Remux is already downloaded it will grab another one

Desktop (please complete the following information):

• OS: Windows 2019
  radarr.debug.txt

Debug Logs
Turn on debug logs under Settings -> General and wait for the bug to occur again. Upload the full log file here (or another site and link it). Issues will be closed, if they do not include this!

[issue-label-bot[bot]]

Issue-Label Bot is automatically applying the label bug to this issue, with a confidence of 0.97. Please mark this comment with :thumbsup: or :thumbsdown: to give our bot feedback!

Links: app homepage, dashboard and code for this bot.

[Rouzax]

And another one

radarr.debug.txt

[fryfrog]

Start by switching from preferred tags to custom formats. The preferred tags don't work very well because they only apply when there are many results to pick from, like during a triggered search. They won't help in normal operation via RSS feed.

Turn logging up to Debug or Trace so you can see why it is making these decisions.

Edit: Duh, you've done that. :)

[Rouzax]

Start by switching from preferred tags to custom formats. The preferred tags don't work very well because they only apply when there are _many_ results to pick from, like during a triggered search. They won't help in normal operation via RSS feed.

~Turn logging up to Debug or Trace so you can see why it is making these decisions.~

Edit: Duh, you've done that. :)

The problem with the custom formats is that they are counted as an individual download.
My wish is:

1. Remux-2160p
2. Remux-1080p
3. Bluray-1080p

Every release has a Bluray-1080p, most a Remux-1080p and some a Remux-2160p.
If a movie has a Remux-2160p right now, most of the times I already download it 3 times since in general the releases start with the lower qualities first.
With Custom Formats they are treated as an individual releases, while not all for instance Remux-2160p releases have HDR which will result in me downloading maybe first the Remux-2160p and then the Remux-2160 HDR bringing the total to 4 downloaded

[fryfrog]

As long as you know your preferred words are only helping anything in the case of a search, but not during the normal operation via RSS... you're fine. You could achieve similar by making HDR/whatever optional for one custom format and disabling the None custom format. At least it'd apply during RSS and search.

Also, I'd maybe suggest that the edition is something you probably don't want to hard code anyway.

I had a quick look through the logs, but there is a lot there. Do you know for sure if you caught the moment when it came down RSS and was selected?

[Rouzax]

Yes I understand the limitation of the tags.

Yes it should have captured that.
Once upon a Time was added for the third time at: 9:32:43
It Chapter Two was added (in a lower quality) at: 20:31:50

EDIT: Once upon a Time might be showing the wrong added on date, somehow it only says that the download was finished in the Radarr log.
EDIT2: It looks like I uploaded the wrong debug log for It Chapter Two 😠 and since debug has such a high rotation they are not there any more.

Is there any way to increase the logging size?
I'll see if I can restore a backup and recover the debug logs.

[Rouzax]

Managed to retrieve it again from a backup
radarr.debug.29.txt

It looks to be the same weird error that it coudn't reach the qBittorent client, but that still does not explain why it would want to add it anyway.
qBittorrent was running.
This is the log of qBittorrent.

(N) 2019-11-30T19:47:40 - Torrent: Once.Upon.a.Time.in.Hollywood.2019.UHD.BluRay.2160p.DTS-HD.MA.7.1.HEVC.REMUX-FraMeSToR, running external program, command: C:\Scripts\TorrentScript.cmd "C:\TEMP\Torrent\Downloads" "Once.Upon.a.Time.in.Hollywood.2019.UHD.BluRay.2160p.DTS-HD.MA.7.1.HEVC.REMUX-FraMeSToR" "Radarr"
(N) 2019-11-30T19:54:22 - Torrent: It.Chapter.Two.2019.UHD.BluRay.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR, running external program, command: C:\Scripts\TorrentScript.cmd "C:\TEMP\Torrent\Downloads" "It.Chapter.Two.2019.UHD.BluRay.2160p.TrueHD.Atmos.7.1.HEVC.REMUX-FraMeSToR" "Radarr"
(N) 2019-11-30T20:26:58 - WebAPI login success. IP: ::ffff:192.168.2.12
(N) 2019-11-30T20:31:50 - Download first and last piece first: Off, torrent: 'It.Chapter.Two.2019.1080p.Bluray.Atmos.TrueHD.7.1.x264-EVO'
(N) 2019-11-30T20:31:50 - 'It.Chapter.Two.2019.1080p.Bluray.Atmos.TrueHD.7.1.x264-EVO' added to download list.
(N) 2019-11-30T20:33:08 - Torrent: It.Chapter.Two.2019.1080p.Bluray.Atmos.TrueHD.7.1.x264-EVO, running external program, command: C:\Scripts\TorrentScript.cmd "C:\TEMP\Torrent\Downloads" "It.Chapter.Two.2019.1080p.Bluray.Atmos.TrueHD.7.1.x264-EVO" "Radarr"
(N) 2019-11-30T21:07:17 - WebAPI login success. IP: ::ffff:192.168.2.12

So the Remux-2160p was finished at: 19:54:22 after which it was post processes and picked up by Radarr at: 20:31:26
Which also seems to be the time it decided to download the Bluray-1080p again

[Rouzax]

It just looks like it randomly decided to download the Bluray-1080p.
At 19-11-30 20:31:46.1 it gets the release in RSS.
Which gets rejected at: 19-11-30 20:31:46.3 since Existing file meets cutoff: Remux-2160p
Then at: 19-11-30 20:31:47.4 it tries to add it from TorrentDay which fails somehow because qBittorrent wasn't listening (which it was)
Then immediately it adds the same torrent but now from DigitalCore

[Rouzax]

Just had another happening, currently on mobile so can't capture the debug logs.
In this case it downloaded the Remux-2160p and while it got the API call to import it, it decide to start another download of the Bluray-1080p (which was already there before the Remux-2160p)
I think it might have to do with a timeout between the download finishing in qBittorrent and when it is actually ready to be imported by Radarr.
It needs to be unpacked etc.
At the end I do a Radarr API call to do the import from the final location.

[fryfrog]

If Radarr/Sonarr think sending the torrent to the client failed and it really was successful, I'm not sure what you can do besides solve that. Are you using black hole or direct connection? Does it see them while they're downloading? That is the weird part to me, even though it "failed" the send... they are there and should show up, but I'm not sure if Sonarr/Radarr check items in the download client. They must not? Are the "failed" torrents getting the right category?

[Rouzax]

I'll post a complete overview of my setup later. Might be this weekend.
Using direct connection and Radarr does see the download progress.
So I think it is getting itchy when qBittorrent has completed but Radarr does not yet get to import anything.
Nothing actually fails, it is just downloading a different release while it is importing the correct one.

[Rouzax]

Here is the debug log and screenshots, don't have time to post my entire flow.

radarr.debug.33.txt

[Rouzax]

Here is my Radarr settings, I don't let Radarr auto import. I give it an import command through the API when the download is finished

My flow:

1. Radarr uses Jackett in the backend to add movies
2. Movie is added to qBittorrent with Label Radarr.
3. Radarr see the download in qBittorrent under the Activity tab
4. qBittorrent downloads in C:\TEMP\Torrent\Downloads
5. When download finishes I kick of a script in qBittorrent to do processing
6. This script does a few things
7. Unpack or copy to C:\TEMP\Torrent\PROCD\Radarr\MOVIENAME
8. Stripout any unwanted subtitles languages
9. Lastly it does an Radarr API call to pick it up:

    url = protocol + host + ":" + port + web_root + "api/command"
    payload = {'name': 'DownloadedMoviesScan', 'path': dir_to_process}
    headers = {'X-Api-Key': apikey}

[Rouzax]

Proof that Radar does see download activity

[Rouzax]

And it happened again, and snatched a 1080 Remux while the 2160 Remux was already there.

radarr.debug.1.txt
radarr.debug.2.txt
radarr.debug.3.txt
radarr.debug.txt
radarr.debug.0.txt

[Rouzax]

To test I've also disabled failed download handing

[Rouzax]

With Redownload Setting disabled it just happened again.
It snatched the 1080-Remux while Radarr was processing the 2160-Remux

The added and import time is the same for both.

qBittorrent did not restart at that time, the only thing that it might be doing is running a command line script because a torrent is finished. I assume qBittorent will still accept API calls at that time.
My Medussa install never has any of these issues.

20-2-1 03:39:13.4|Debug|ParsingService|Quality parsed: BR-DISK v1 (None)
20-2-1 03:39:13.5|Debug|DownloadDecisionMaker|Release rejected for the following reasons: [Permanent] Could not find Rambo Last Blood
20-2-1 03:39:14.7|Debug|QBittorrent|Downloading torrent for movie 'Ford v Ferrari 2019 1080p BluRay REMUX AVC DTS-HD MA 7.1-EPSiLON' finished (157085 bytes from http://download:9117/dl/privatehd/?jackett_apikey=(removed)&path=Q2ZESjhJVTU0WGRFZlR4QWtjT1lpVHJzTjVZa1ZpMzBfeGZRLUZ0ZlFjczdTYmEyYWw3cE5LWE95N29TNXFTc3FyaVdMb25LZXhOU2hSWG5VQmtBSzF0U1RrRjBObEk5UDZBZmVjVkxGdUZ6VmtKTnlTQWF2U05hTHNMaWloQm5FdEx6aTV2dDBLQm4wYWRqYkRsYVF2MWt3WG5ydWdxWnlmbDUtZWZnNnluMWhWZDc1X0YxV1g0QWEtQjN6YXpJemlyU1VKMEsycEdMMkVuRzlxUVFPV19TTmpYUjZHdFV3STF1eDJzYVB5OGEyUXFQb2U2TkV2Sk9CRml3Y2dZa0Z4ZGFjb051OElKa2dsTEZmNXhWRWlhcl9saw&file=Ford+v+Ferrari+2019+1080p+BluRay+REMUX+AVC+DTS-HD+MA+7.1-EPSiLON)
20-2-1 03:39:14.7|Warn|ProcessDownloadDecisions|Couldn't add report to download queue. Ford v Ferrari 2019 1080p BluRay REMUX AVC DTS-HD MA 7.1-EPSiLON

[v0.2.0.1450] NzbDrone.Core.Download.Clients.DownloadClientException: Download client failed to add torrent
   at NzbDrone.Core.Download.Clients.QBittorrent.QBittorrentProxyV2.AddTorrentFromFile(String fileName, Byte[] fileContent, QBittorrentSettings settings) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\Clients\QBittorrent\QBittorrentProxyV2.cs:line 144
   at NzbDrone.Core.Download.Clients.QBittorrent.QBittorrent.AddFromTorrentFile(RemoteMovie remoteMovie, String hash, String filename, Byte[] fileContent) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\Clients\QBittorrent\QBittorrent.cs:line 67
   at NzbDrone.Core.Download.TorrentClientBase`1.DownloadFromWebUrl(RemoteMovie remoteMovie, String torrentUrl) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\TorrentClientBase.cs:line 184
   at NzbDrone.Core.Download.TorrentClientBase`1.Download(RemoteMovie remoteMovie) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\TorrentClientBase.cs:line 118
   at NzbDrone.Core.Download.DownloadService.DownloadReport(RemoteMovie remoteMovie, Boolean foceDownload) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\DownloadService.cs:line 64
   at NzbDrone.Core.Download.ProcessDownloadDecisions.ProcessDecisions(List`1 decisions) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\ProcessDownloadDecisions.cs:line 88

20-2-1 03:39:16.1|Debug|QBittorrent|Downloading torrent for movie 'Ford v Ferrari 2019 1080p BluRay Remux AVC DTS-HD MA 7.1-EPSiLON' finished (78691 bytes from http://download:9117/dl/hdtorrents/?jackett_apikey=(removed)&path=Q2ZESjhJVTU0WGRFZlR4QWtjT1lpVHJzTjViVlFwMlZiNnFxTDFBTFJKMWJ3OFFRdGlaeVdHajVvQmFzSWhrVkJWN004M1owTnZ6UG1HeWpEQzBUdkJFb1dyZUN3RmV5UkxaUVNVc3E1YktkUV8zNlY5OGZPT3hHVVpXYnRPWUlteGlKMmRiaW9CYnlOUHZSMTRxQlNja0pzWlJuLW5WX0g2YlNPemw4bHktRU9vT2xfa1BTSXVRSXpsM0RxTFZGcE4wWVBsQlBadElqbmhwblZFNkVRXzItSTZEMDBNN2Y2dkVQdEh0VTVLVFJiOXNsTlBxbC1XQmRnWXRNWlBzVFlhS3ZTR0F5SklJTGE1U3VzcXpEVEhocHktVUgwemtmXzhzY0RyQ2FXd2FDdTdKOWdJeUdKemJJbUVkNU94VVhRUkJVTnc&file=Ford+v+Ferrari+2019+1080p+BluRay+Remux+AVC+DTS-HD+MA+7.1-EPSiLON)
20-2-1 03:39:16.2|Info|DownloadService|Report sent to qBittorent. Ford v Ferrari 2019 1080p BluRay Remux AVC DTS-HD MA 7.1-EPSiLON

radarr.debug.8.txt
radarr.debug.7.txt

[Rouzax]

Happened again.

Should I still upload my debug logs?

20-2-7 16:16:11.3|Debug|ParsingService|Quality parsed: Bluray-720p v1 (None)
20-2-7 16:16:11.3|Debug|DownloadDecisionMaker|Release rejected for the following reasons: [Permanent] Could not find Black Site
20-2-7 16:16:11.6|Debug|QBittorrent|Downloading torrent for movie 'Jojo Rabbit 2019 UHD BluRay 2160p DTS-HD MA 5.1 HEVC REMUX-FraMeSToR' finished (248759 bytes from http://download:9117/dl/beyond-hd/?jackett_apikey=(removed)&path=Q2ZESjhJVTU0WGRFZlR4QWtjT1lpVHJzTjVhTm0wVE9feFhlcWQxaGJKN2tNOVFrdTkzRkJ2WkdpbkJRNGg3UkRPb0VvVEgwSUF1c0xaR3o4ajRNYjNyczlGZElYSF9QUC0xUmZaQ3dMRGt0cHZ3ZnZTZDF3blc0dHBFWWZHRHpaa0pwaEFTaUwxcWlvendnWFdnNF8yczNkU09Dc0F2Tk1OSVlRN2dRUE5JM3IzVUhud1NzNjNOLV9IRU9fRzlESDllcmZxZ0lVdWxvRkdQekF1M0ZwUUU3QTRkRGVyYjBBYjVmenEzaFlYMGQyR3F5Ull2ZjZMTzV0cmh3SFJiWnF1TTBSZw&file=Jojo+Rabbit+2019+UHD+BluRay+2160p+DTS-HD+MA+5.1+HEVC+REMUX-FraMeSToR)
20-2-7 16:16:11.6|Warn|ProcessDownloadDecisions|Couldn't add report to download queue. Jojo Rabbit 2019 UHD BluRay 2160p DTS-HD MA 5.1 HEVC REMUX-FraMeSToR

[v0.2.0.1450] NzbDrone.Core.Download.Clients.DownloadClientException: Download client failed to add torrent
   at NzbDrone.Core.Download.Clients.QBittorrent.QBittorrentProxyV2.AddTorrentFromFile(String fileName, Byte[] fileContent, QBittorrentSettings settings) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\Clients\QBittorrent\QBittorrentProxyV2.cs:line 144
   at NzbDrone.Core.Download.Clients.QBittorrent.QBittorrent.AddFromTorrentFile(RemoteMovie remoteMovie, String hash, String filename, Byte[] fileContent) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\Clients\QBittorrent\QBittorrent.cs:line 67
   at NzbDrone.Core.Download.TorrentClientBase`1.DownloadFromWebUrl(RemoteMovie remoteMovie, String torrentUrl) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\TorrentClientBase.cs:line 184
   at NzbDrone.Core.Download.TorrentClientBase`1.Download(RemoteMovie remoteMovie) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\TorrentClientBase.cs:line 118
   at NzbDrone.Core.Download.DownloadService.DownloadReport(RemoteMovie remoteMovie, Boolean foceDownload) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\DownloadService.cs:line 64
   at NzbDrone.Core.Download.ProcessDownloadDecisions.ProcessDecisions(List`1 decisions) in C:\projects\radarr-usby1\src\NzbDrone.Core\Download\ProcessDownloadDecisions.cs:line 88

20-2-7 16:16:13.6|Debug|QBittorrent|Downloading torrent for movie 'Jojo Rabbit 2019 1080p Bluray DTS-HD MA 5 1 X264-EVO' finished (136634 bytes from http://download:9117/dl/iptorrents/?jackett_apikey=(removed)&path=Q2ZESjhJVTU0WGRFZlR4QWtjT1lpVHJzTjVhWUtSSVlOUXJreE04aXhpRTc4R3JtczVUZkRzNjVLbHpSRDEyTGxTRjNUellaSTgyX1c1VTNLWEhjM0xybG9HeXpOQlFiTHVCbmpYQklQWDVodjIydTYwUXI4WEdMWERUR0NBenNpaFpQNkRKS1lUV0hmb1hpcnFLV0luejRycHV0TmRETDRpd2hGdmtGVGhPZVdqaTNIeF9tRENNMlBuNEw3LUtJVmY5cXNoemQ2VU9DS3NkcXV4UDJ3Uy1jdm9RSm1tTExIbkJ5dHFxcnRXMmNHak9md2NOeTVFYUVNXzVSbEJ3ck95a2N6UQ&file=Jojo+Rabbit+2019+1080p+Bluray+DTS-HD+MA+5+1+X264-EVO)
20-2-7 16:16:13.6|Info|DownloadService|Report sent to qBittorent. Jojo Rabbit 2019 1080p Bluray DTS-HD MA 5 1 X264-EVO

Again my qBittorrent is running and reachable, and even if it was down it does not explain why it would download a 1080p while the 2160p is also being processed.

[Rouzax]

Happened again.

It might have something to do with the way I pick it up.
Always did a https://github.com/Radarr/Radarr/wiki/API:Command#downloadedmoviesscan to pick up the download.
When it happens I also see in the logging that Radarr cannot see which DownloadId it was, so I'm no adding that to the downloadedmoviesscan API call.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. Please verify that this is still an issue with the latest version of Radarr and report back. Otherwise this issue will be closed.