Occassional Failure when adding to RTorrent - Could Not Find Info-hash

Continuing the discussion from Rtorrent - Adding new download sometimes fails:

Getting the same issue as Jackson’s post above, which was unanswered and closed automatically hence the new post.

Any ideas? It’s strange because the failed torrents sit in Rtorrent as stopped, and need to be started manually, after which they work fine.

Logs similar to OP here:

17-2-3 11:21:22.9|Warn|ProcessDownloadDecisions|Couldn’t add report to download queue. TVSERIESNAME S01E06 WEB X264-DEFLATE

[v2.0.0.4427] CookComputing.XmlRpc.XmlRpcFaultException: Server returned a fault exception: [-501] Could not find info-hash.
at CookComputing.XmlRpc.XmlRpcSerializer.DeserializeResponse (System.Xml.XmlDocument xdoc, System.Type returnType) <0x4223f1b0 + 0x0045b> in :0
at CookComputing.XmlRpc.XmlRpcSerializer.DeserializeResponse (System.IO.Stream stm, System.Type svcType) <0x422377a0 + 0x0023f> in :0
at CookComputing.XmlRpc.XmlRpcClientProtocol.ReadResponse (CookComputing.XmlRpc.XmlRpcRequest req, System.Net.WebResponse webResp, System.IO.Stream respStm, System.Type returnType) <0x422374e0 + 0x00197> in :0
at CookComputing.XmlRpc.XmlRpcClientProtocol.Invoke (System.Object clientObj, System.Reflection.MethodInfo mi, System.Object[] parameters) <0x42189230 + 0x007cf> in :0
at CookComputing.XmlRpc.XmlRpcClientProtocol.Invoke (System.Reflection.MethodInfo mi, System.Object[] Parameters) <0x42188630 + 0x00027> in :0
at XmlRpcProxy1d7a5951-aa6c-403b-99bb-5cb0f3699600.Remove (System.String hash) <0x42551e30 + 0x00093> in :0
at NzbDrone.Core.Download.Clients.RTorrent.RTorrentProxy.RemoveTorrent (System.String hash, NzbDrone.Core.Download.Clients.RTorrent.RTorrentSettings settings) <0x42551d30 + 0x00059> in :0
at NzbDrone.Core.Download.Clients.RTorrent.RTorrent.RemoveItem (System.String downloadId, Boolean deleteData) <0x42551480 + 0x00084> in :0
at NzbDrone.Core.Download.Clients.RTorrent.RTorrent.AddFromTorrentFile (NzbDrone.Core.Parser.Model.RemoteEpisode remoteEpisode, System.String hash, System.String filename, System.Byte[] fileContent) <0x424171f0 + 0x00247> in :0
at NzbDrone.Core.Download.TorrentClientBase1[TSettings].DownloadFromWebUrl (NzbDrone.Core.Parser.Model.RemoteEpisode remoteEpisode, System.String torrentUrl) <0x4240c9d0 + 0x0069f> in <filename unknown>:0 at NzbDrone.Core.Download.TorrentClientBase1[TSettings].Download (NzbDrone.Core.Parser.Model.RemoteEpisode remoteEpisode) <0x4240c380 + 0x0059b> in :0
at NzbDrone.Core.Download.DownloadService.DownloadReport (NzbDrone.Core.Parser.Model.RemoteEpisode remoteEpisode) <0x4240b810 + 0x0055d> in :0
at NzbDrone.Core.Download.ProcessDownloadDecisions.ProcessDecisions (System.Collections.Generic.List`1 decisions) <0x423e0930 + 0x00909> in :0

We typically see this with magnet’s (and rTorrent being slow to fetch them), haven’t seen many instances of this, but it looks like rTorrent isn’t adding the torrent quickly enough so Sonarr attempts to remove it, which fails because it’s still not there, but it shows up later.

Either Sonarr and rTorrent disagree about the torrent hash (which impossible given what the hash is) or rTorrent is actually taking a while to add it.

Sonarr relies on rTorrent having the torrent there, so it can set the label, priority, directory and finally start it as there is no way to set all that when adding the torrent.

Side note: you should be running mono with the --debug switch so Sonarr has more information in the stack traces.
The following information would also be helpful:

Sonarr version (exact version):
Mono version (if Sonarr is not running on Windows):
OS:
((Debug logs)):
(Make sure debug logging is enabled in settings and post the full log to hastebin/pastebin/dropbox/google drive or something similar, do not post them directly here)

Sorry about the lack of info. I’ve asked my hosts to enable --debug for mono so will come back if this is possible.

In the meantime:
Sonarr Version: 2.0.0.4427
Mono Version: Mono JIT compiler version 4.2.3 (Stable 4.2.3.4/832de4b Wed Mar 16 13:19:08 UTC 2016)
OS: Ubuntu (3.13.0-107-generic)

This only occurs when Sonarr sends and entire series of individual torrents to Rtorrent, so I think its just overloading Rtorrent with too many requests. Do you think adding an option for a 1 second sleep delay per torrent when using Rtorrent may resolve this?

Depends when it starts happening, Sonarr generally adds items sequentially (the logs will confirm the order). Does it start with the first episode, the last or somewhere in the middle?

It seemed to be around the middle, but its difficult to reproduce so I can’t be sure.

I’ve had difficulty getting mono to run with debug as it is running with start-stop-daemon and adding the switch --debug doesn’t seem to work. I’m probably just being ignorant and will figure it out!

However here are the debug logs containing a few instances of the error :slight_smile:
https://drive.google.com/file/d/0B74OZqDJCOuEMWoxX0FiYUpQMDA/view?usp=sharing

@markus101 The RemoveTorrent doesn’t make sense, if rtorrent couldn’t add the torrent, then it won’t be there to remove. It’s not an issue, but it puts the user on the wrong trail with the Warn message.
As for the real issue: We may have to give it a bit more retries, upping it from 2 to 5. Giving it a total of 500ms to add the file.

@theCheek Can you check your rtorrent logfile?

hi @taloth.

I looked at the log directory for the first time and found a bunch of rtorrent.log.xxxx files (where xxxx are a bunch of numbers) and tried to locate the one made around the time of the errors in the debug logs i posted above. Unfortunately I then realised that all of these files are 0 bytes for some reason. In my rtorrent.rc I believe I have the correct log lines:

log.open_file = “rtorrent.log”, (cat,/home/hd1/thecheek/.config/rtorrent/rtorrent.log.,(system.pid))
log.add_output = “error”, “rtorrent.log”

So I am assuming rtorrent is simply not responding to sonarr’s commands in a timely fashion, hence Sonarr bombarding it with the same torrent from different trackers, and thus rtorrent does not log any errors.

Another thing to note is that when this does happen, I see the same torrent from different trackers sitting in RTorrent in a stopped state, and none of them have any labels of tv-sonarr which is what Sonarr is told to label them as.

For now I have switched over to Deluge, but if you want me to switch back to capture more data please let me know and I will happy to oblige.

Tnx for looking at the logs.

It’s quite a stretch to get from ‘empty log files’ to the assumption ‘sonarr is bombarding rtorrent’.
The assumption is understandable, but considering the way Sonarr calls the rtorrent api, it’s extremely unlikely.
If the rtorrent api doesn’t respond, then Sonarr would log a http timeout, for example.

In rtorrent the log.add_output "error", "rtorrent.log" should be something like log.add_output "info", "rtorrent.log". (there are several levels: critical error warn notice info debug)
After all, from rtorrent’s perspective it might not be an error at all, simply a delay.

The reason I asked to look in the rtorrent log file is because that might allow you to correlate between the sonarr log files and rtorrent.

As for the missing label etc, that’s coz Sonarr adds those later, it simply doesn’t get around to it.

But you don’t have to investigate further, only if you want confirmation on what’s going on.

Hi @Taloth, sorry for the assumption, and poor choice of words aka bombardment!

Personally I am liking Deluge and its working seemlessly with Sonarr, however if this is something you would like to fix for other users who encounter the issue, then I would be more than happy to switch back to rtorrent after enabling the info logging to rtorrent. After all, Sonarr’s functionality and dev team are so incredible it’s the least I can do (apart from donations, which I do any time I can afford).

However if this is just a niche or edge case, let me know :slight_smile: and I’ll continue with Deluge.

Not really an edge-case, just a combination of unpredictable factors.

However, we’ve upped the period (from 200ms to 1s) during which we check whether rtorrent finished adding the torrent. So it’s unlikely that the problem will occur for other users in the future.

Thank you for reporting the issue.

1 Like

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.