rogerfar / rdt-client

Real-Debrid Client Proxy
MIT License
885 stars 113 forks source link

Launch issue after update / sudden spike in CPU usage #84

Closed IrealiTY closed 3 years ago

IrealiTY commented 3 years ago

What version are you using? 1.9.4

Wat OS are you running? Synology

Are you using Docker or as a service? Docker

I noticed an extremely high bandwidth usage on my Synology NAS and noticed that rdt-client was using a huge amount of CPU and memory, killed the process and decided to restart. (it was running fine for a few months now) And now it just hangs with the log below and doesn't boot up. I also noticed the 1.9.3.0 in the logs but I did run docker-pull latest before posting here.

today at 23:29:54 Changing to /app folder
today at 23:29:54 Starting rtdclient
today at 23:29:54 Changing to /app folder
today at 23:29:54 Starting rtdclient
today at 23:29:57 [21:29:57 WRN] Starting host on version 1.9.3.0
today at 23:29:57 [21:29:57 WRN] Starting host on version 1.9.3.0
today at 23:29:57 [21:29:57 WRN] Using an in-memory repository. Keys will not be persisted to storage.
today at 23:29:57 [21:29:57 WRN] Using an in-memory repository. Keys will not be persisted to storage.
today at 23:29:57 [21:29:57 WRN] Neither user profile nor HKLM registry available. Using an ephemeral key repository. Protected data will be unavailable when application exits.
today at 23:29:57 [21:29:57 WRN] Neither user profile nor HKLM registry available. Using an ephemeral key repository. Protected data will be unavailable when application exits.
today at 23:29:57 [21:29:57 WRN] No XML encryptor configured. Key {bbc1ebaf-0e49-4e05-a586-59bb2409b773} may be persisted to storage in unencrypted form.
today at 23:29:57 [21:29:57 WRN] No XML encryptor configured. Key {bbc1ebaf-0e49-4e05-a586-59bb2409b773} may be persisted to storage in unencrypted form.
today at 23:29:57 [21:29:57 FTL] Host terminated unexpectedly
today at 23:29:57 System.FormatException: Input string was not in a correct format.
today at 23:29:57    at System.Number.ThrowOverflowOrFormatException(ParsingStatus status, TypeCode type)
today at 23:29:57    at System.Number.ParseInt32(ReadOnlySpan`1 value, NumberStyles styles, NumberFormatInfo info)
today at 23:29:57    at System.Int32.Parse(String s)
today at 23:29:57    at RdtClient.Data.Data.SettingData.<ResetCache>g__GetInt32|7_1(String name, <>c__DisplayClass7_0& ) in /appserver/server/RdtClient.Data/Data/SettingData.cs:line 30
today at 23:29:57    at RdtClient.Data.Data.SettingData.ResetCache() in /appserver/server/RdtClient.Data/Data/SettingData.cs:line 32
today at 23:29:57    at RdtClient.Service.Services.Settings.ResetCache() in /appserver/server/RdtClient.Service/Services/Settings.cs:line 179
today at 23:29:57    at RdtClient.Service.Services.Startup.StartAsync(CancellationToken cancellationToken) in /appserver/server/RdtClient.Service/Services/Startup.cs:line 24
today at 23:29:57    at Microsoft.Extensions.Hosting.Internal.Host.StartAsync(CancellationToken cancellationToken)
today at 23:29:57    at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
today at 23:29:57    at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
today at 23:29:57    at RdtClient.Web.Program.Main(String[] args) in /appserver/server/RdtClient.Web/Program.cs:line 57
today at 23:29:57 [21:29:57 FTL] Host terminated unexpectedly
today at 23:29:57 System.FormatException: Input string was not in a correct format.
today at 23:29:57    at System.Number.ThrowOverflowOrFormatException(ParsingStatus status, TypeCode type)
today at 23:29:57    at System.Number.ParseInt32(ReadOnlySpan`1 value, NumberStyles styles, NumberFormatInfo info)
today at 23:29:57    at System.Int32.Parse(String s)
today at 23:29:57    at RdtClient.Data.Data.SettingData.<ResetCache>g__GetInt32|7_1(String name, <>c__DisplayClass7_0& ) in /appserver/server/RdtClient.Data/Data/SettingData.cs:line 30
today at 23:29:57    at RdtClient.Data.Data.SettingData.ResetCache() in /appserver/server/RdtClient.Data/Data/SettingData.cs:line 32
today at 23:29:57    at RdtClient.Service.Services.Settings.ResetCache() in /appserver/server/RdtClient.Service/Services/Settings.cs:line 179
today at 23:29:57    at RdtClient.Service.Services.Startup.StartAsync(CancellationToken cancellationToken) in /appserver/server/RdtClient.Service/Services/Startup.cs:line 24
today at 23:29:57    at Microsoft.Extensions.Hosting.Internal.Host.StartAsync(CancellationToken cancellationToken)
today at 23:29:57    at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
today at 23:29:57    at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
today at 23:29:57    at RdtClient.Web.Program.Main(String[] args) in /appserver/server/RdtClient.Web/Program.cs:line 57
rogerfar commented 3 years ago

1.9.4 should be the latest version: https://hub.docker.com/r/rogerfar/rdtclient/tags

But it looks like somehow your settings got corrupt, if you're adventurous you can open the .DB file with something like https://sqlitebrowser.org/, otherwise you can simply delete the DB file and re-start the service, this will re-create it.

IrealiTY commented 3 years ago

Resetting the config fixed it. The setting that crashed it must've been either something with Aria2 (didn't get around to test it, I only entered my data in it) or me entering 0.2 in the filesize limit field :D image

rogerfar commented 3 years ago

That would break it yes! I will add some more checks so it doesn't crash as hard and change the input to only accept full numbers.

IrealiTY commented 3 years ago

Glad I could find the bug? haha

would it be somehow possible to have the simple download method to have speed limits? that's the reason I went to look for aria2 and so on

IrealiTY commented 3 years ago

Found a bug that caused this whole investigation:

image The download bandwidth is the RDT client alone. So I was wondering where this came from....

I can access the WEB UI everything works except the Test Real-Debrid download speed button. image The archive never stops downloading :D

I've set the logging to debug but nothing seems to spring up that could be related to this, nothing indicates that it keeps downloading / stopping / resuming said download.

Also had the feeling that a previous torrent file caused the same issue but I couldn't verify it. I will check again.

rogerfar commented 3 years ago

Are you testing with Aria2? That's a bug yes, it changed how it handles the progress and it never stop it no.

If you browse away from the page it should stop it though.

IrealiTY commented 3 years ago

no, this is on simple, basically a fresh install since I wiped my config

IrealiTY commented 3 years ago

I think I found the issue.

I started a new torrent to test, reladebrid processed it fine. But the client got stuck looping between Torrent finished, waiting to download and Queued for download.

The log looked like this

today at 00:24:35 [22:24:35 DBG] Updating torrent info from Real-Debrid
today at 00:24:35 [22:24:35 DBG] Finished updating torrent info from Real-Debrid, next update in 0 seconds
today at 00:24:35 [22:24:35 DBG] Processing 1 torrents
today at 00:24:35 [22:24:35 DBG] Processing to download for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:35 [22:24:35 DBG] Unrestricting links for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:35 [22:24:35 DBG] Unrestricting link for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Marking download as started for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Setting download path to /data/downloads/sonarr for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Starting download for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Starting download of https://file.mkv, writing to path: /data/downloads/sonarr/file.mkv/file.mkv
today at 00:24:36 [22:24:36 DBG] No ID received for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Processing for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] Waiting for downloads to complete. 0/1 complete for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:36 [22:24:36 DBG] TorrentRunner Tick End (took 2395ms)
today at 00:24:37 [22:24:37 DBG] TorrentRunner Tick Start, 1 active downloads, 0 active unpacks
today at 00:24:37 [22:24:37 DBG] Processing 1 completed downloads
today at 00:24:37 [22:24:37 DBG] Processing download for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:37 [22:24:37 DBG] Download reported an error: The SSL connection could not be established, see inner exception. for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:37 [22:24:37 DBG] Download retry count 0/3, torrent retry count 0/2 for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:37 [22:24:37 DBG] Retrying download for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:37 [22:24:37 DBG] Removed from ActiveDownloadClients for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:37 [22:24:37 DBG] Updating torrent info from Real-Debrid
today at 00:24:40 [22:24:40 DBG] Finished updating torrent info from Real-Debrid, next update in 0 seconds
today at 00:24:40 [22:24:40 DBG] Processing 1 torrents
today at 00:24:40 [22:24:40 DBG] Processing to download for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Unrestricting links for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Unrestricting link for download https://real-debrid.com/d/xxxxxxxxxxx 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Marking download as started for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Setting download path to /data/downloads/sonarr for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Starting download for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Starting download of https://file.mkv, writing to path: /data/downloads/sonarr/file.mkv/file.mkv
today at 00:24:40 [22:24:40 DBG] No ID received for download file.mkv 0% (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx) for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Processing for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] Waiting for downloads to complete. 0/1 complete for file.mkv (xxxxxxxxxxxxx - downloaded 100%) (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx)
today at 00:24:40 [22:24:40 DBG] TorrentRunner Tick End (took 3364ms)

basically looping over and over trying to download it and maxing out my bandwidth. Went to check on the file on real-debrid, and turns out they seem to have network issues on some files, maybe a bad CDN. image

I'm not sure you can do any checks on that end for the client but it would nice for it not to cap out the bandwidth haha

rogerfar commented 3 years ago

Are you sure you are on 1.9.4 because there were some issues with that before.

IrealiTY commented 3 years ago

image today at 00:39:14 [22:39:13 WRN] Starting host on version 1.9.4.0 yep I'm sure, doublechecked the tag on the container

what I also found weird is that it created a folder with the file name, as in name-of-torrent.mkv was the folder, not the file maybe this caused the issue of it not properly downloading? (in the end I managed to download the file manually from real-debrid via the browser, when rdt still had issues)

rogerfar commented 3 years ago

There was something wrong with the simple downloader, that's now fixed in 1.9.5.

IrealiTY commented 3 years ago

Thanks a lot for looking into it! I'll have a check tomorrow :) For now, I fixed it by using Multi Part Downloader

rogerfar commented 3 years ago

If you have still issues, feel free to comment on this ticket or create a new one.