RDTClient with sonarr: stuck on "Torrent finished, waiting to download"

[Raiiyzen]

Hello,

New user of RDCTClient since 2 days, I have a problem to make rdtclient work with sonarr.

Torrents containing several real debrid links are stuck on the "Torrent finished, waiting to download" state.

Unfortunately the logs don't really help me, no error message even with the debug option enabled.

In order to be as accurate as possible, I specify that real debrid torrents generating only one link are working fine.

Any help would be appreciated

Thank you

rdtclient_001.log

[Raiiyzen]

EDIT: rollback to 1.7.8 solves the problem....

[rogerfar]

Did you try restarting the service?

And did it occur multiple times?

Did the interface report any errors on the downloads? Because the last few days I've gotten a lot of "hoster_unavailable" errors from RealDebrid.

[Raiiyzen]

Did you try restarting the service?

My RDTClient instance is on Docker, i try to delete completely the container then fresh install, but the problem is still present.

And did it occur multiple times?

Yes, it happens every times with real debrid torrents containing several real debrid links

Did the interface report any errors on the downloads? Because the last few days I've gotten a lot of "hoster_unavailable" errors from RealDebrid.

No. zero errors from the interface.

[DaisyF8]

For me the same. Also on Docker, multiple times, also after restarting, no error after restarting.

Below from the log after restart, let me know if you need more info :

EDIT : it looks like it was file-dependant. I tried a few other sources and they worked. So I'm not having a problem anymore.

ORDER BY "MigrationId";

[18:29:41 INF] Executed DbCommand (2ms) [Parameters=[], CommandType='Text', CommandTimeout='30']

SELECT "MigrationId", "ProductVersion"

FROM "__EFMigrationsHistory"

ORDER BY "MigrationId";

[18:29:41 DBG] A data reader was disposed.

[18:29:41 DBG] Closing connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:41 DBG] Closed connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 INF] No migrations were applied. The database is already up to date.

[18:29:42 DBG] Compiling query expression: 

'DbSet<Setting>()'

[18:29:42 DBG] Generated query execution expression: 

'queryContext => new SingleQueryingEnumerable<Setting>(

    (RelationalQueryContext)queryContext, 

    RelationalCommandCache.SelectExpression(

        Projection Mapping:

            EmptyProjectionMember -> Dictionary<IProperty, int> { [Property: Setting.SettingId (string) Required PK AfterSave:Throw, 0], [Property: Setting.Type (string), 1], [Property: Setting.Value (string), 2], }

        SELECT s.SettingId, s.Type, s.Value

        FROM Settings AS s), 

    Func<QueryContext, DbDataReader, ResultContext, SingleQueryResultCoordinator, Setting>, 

    RdtClient.Data.Data.DataContext, 

    False, 



e

)'

[18:29:42 DBG] Creating DbCommand for 'ExecuteReader'.

[18:29:42 DBG] Created DbCommand for 'ExecuteReader' (0ms).

[18:29:42 DBG] Opening connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Opened connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']

SELECT "s"."SettingId", "s"."Type", "s"."Value"

FROM "Settings" AS "s"

[18:29:42 INF] Executed DbCommand (1ms) [Parameters=[], CommandType='Text', CommandTimeout='30']

SELECT "s"."SettingId", "s"."Type", "s"."Value"

FROM "Settings" AS "s"

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] Context 'DataContext' started tracking 'Setting' entity. Consider using 'DbContextOptionsBuilder.EnableSensitiveDataLogging' to see key values.

[18:29:42 DBG] A data reader was disposed.

[18:29:42 DBG] Closing connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Closed connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Compiling query expression: 

'DbSet<Setting>()

    .FirstOrDefault(m => m.SettingId == "LogLevel")'

[18:29:42 DBG] Generated query execution expression: 

'queryContext => ShapedQueryCompilingExpressionVisitor.SingleOrDefaultAsync<Setting>(

    asyncEnumerable: new SingleQueryingEnumerable<Setting>(

        (RelationalQueryContext)queryContext, 

        RelationalCommandCache.SelectExpression(

            Projection Mapping:

                EmptyProjectionMember -> Dictionary<IProperty, int> { [Property: Setting.SettingId (string) Required PK AfterSave:Throw, 0], [Property: Setting.Type (string), 1], [Property: Setting.Value (string), 2], }

            SELECT TOP(1) s.SettingId, s.Type, s.Value

            FROM Settings AS s

            WHERE s.SettingId == 'LogLevel'), 

        Func<QueryContext, DbDataReader, ResultContext, SingleQueryResultCoordinator, Setting>, 

        RdtClient.Data.Data.DataContext, 

        False, 

        False

    ), 

    cancellationToken: queryContext.CancellationToken)'

[18:29:42 DBG] Creating DbCommand for 'ExecuteReader'.

[18:29:42 DBG] Created DbCommand for 'ExecuteReader' (0ms).

[18:29:42 DBG] Opening connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Opened connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']

SELECT "s"."SettingId", "s"."Type", "s"."Value"

FROM "Settings" AS "s"

WHERE "s"."SettingId" = 'LogLevel'

LIMIT 1

[18:29:42 INF] Executed DbCommand (1ms) [Parameters=[], CommandType='Text', CommandTimeout='30']

SELECT "s"."SettingId", "s"."Type", "s"."Value"

FROM "Settings" AS "s"

WHERE "s"."SettingId" = 'LogLevel'

LIMIT 1

[18:29:42 DBG] A data reader was disposed.

[18:29:42 DBG] Closing connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 DBG] Closed connection to database 'main' on server '/data/db/rdtclient.db'.

[18:29:42 WRN] Using an in-memory repository. Keys will not be persisted to storage.

[18:29:42 WRN] Neither user profile nor HKLM registry available. Using an ephemeral key repository. Protected data will be unavailable when application exits.

[18:29:42 WRN] No XML encryptor configured. Key {f8119268-769a-4ac1-b9e0-a5bc3e73b0f1} may be persisted to storage in unencrypted form.

[18:29:49 WRN] The query uses the 'First'/'FirstOrDefault' operator without 'OrderBy' and filter operators. This may lead to unpredictable results.

[18:29:50 WRN] 401: /api/v2/torrents/info

[18:30:06 WRN] 401: /api/v2/torrents/info

[18:30:06 WRN] 401: /api/v2/torrents/info

[18:30:09 WRN] 401: /Api/Authentication/IsLoggedIn

[18:30:18 WRN] 101: /hub

[18:31:11 WRN] 401: /api/v2/torrents/info

[18:31:11 WRN] 401: /api/v2/torrents/info

[18:31:40 WRN] 304: /index.html

[18:34:26 WRN] 101: /hub

[rogerfar]

If this is still happening could you post your db file? Now your real debrid api key is in stored there too so you will want to empty that setting first. It's fine if you want to send it to me privately too. It's hard to debug without knowing what state stuff is in.

[DaisyF8]

I'll trigger the problem after the current download. What is the db location ?

Nvm found it

[rogerfar]

Does this problem always occur with the same torrent? If so, can you send me that torrent in a pastebin?

[rogerfar]

I think Ifound the issue, I'm pushing 1.8.1 to Docker now, that should fix it.

[DaisyF8]

Okay I'll check tomorrow

[Raiiyzen]

I think Ifound the issue, I'm pushing 1.8.1 to Docker now, that should fix it.

Ok it seems working now ! but real debrid is buggy at this time. I've some files failed to download but manually retry download fix the issue.

[DaisyF8]

Bit busy to help testing. I hope you have enough info.

[DaisyF8]

I'm on your latest update, but still I get "Waiting for download".

This is the magnet : https://pastebin.com/PPLBmF0X

Can I send you my db privately ?

EDIT : and categories aren't working anymore after restart I think ? I'm getting this :

[12:24:56 ERR] An unhandled exception has occurred while executing the request.

System.ArgumentException: An item with the same key has already been added. Key: movies

[rogerfar]

Different issue indeed, I fixed it in 1.8.2.

Sometimes Real-Debrid gives you 1 link with all files, sometimes multiple files. Because I don't know how much it will give it checks if there enough links, but it wasn't counting the links vs selected files properly.

[DaisyF8]

I'll test when you update the docker-image. Thx

[DaisyF8]

With 1.8.2 it's working now. Thanks.

Quick question : I want to use category names "music" for lidarr, "tv" for sonarr, "movies" for radar, "anime" for my other sonarr and "prowlarr" for prowlarr. This shouldn't be a problem right ? Because I'm seeing errors now when I use test and want to save (in Radarr, Sonarr, ... But it gets saved). I'll test some more before opening another Issue here on Git.

[rogerfar]

No that shouldn't be an issue. You can now save and use different categories.

I'm going to close this issue now, if you still have an issue with the categories, please open a new ticket.