Downloads stop with "ENCRYPTED" proper password is already supplied

Report & discuss bugs found in SABnzbd
Forum rules
Help us help you:
  • Are you using the latest stable version of SABnzbd? Downloads page.
  • Tell us what system you run SABnzbd on.
  • Adhere to the forum rules.
  • Do you experience problems during downloading?
    Check your connection in Status and Interface settings window.
    Use Test Server in Config > Servers.
    We will probably ask you to do a test using only basic settings.
  • Do you experience problems during repair or unpacking?
    Enable +Debug logging in the Status and Interface settings window and share the relevant parts of the log here using [ code ] sections.
Post Reply
User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

I've noticed that with 3.1.0 it happens more often again that downloads are stopped/paused with "ENCRYPTED" when they are in fact not. Well, they actually are, of course, but the proper password is already supplied and known to SABnzbd. When this happens, all I have to do is to klick the "Play/Continue" button, and SABnzbd goes on as usual, downloads the rest and unpacks the RAR just fine. I do not have to change/reenter the password, this works fine with exactly the same data that SABnzbd started with right from the beginning.

Unfortunately this problem is not reproducible. As I said, once I klick "continue" without adding/changing anything else, everything works just fine. If I try to download the exact same NZB once again, usually everything works just fine as well. One thing that I did notice, however, is that SABnzbd seems to have to go and get some additional PAR2 files and do a little repair before the original paused & continued download can be unpacked. So this is probably somehow related ... maybe SABnzbd thinks it has a wrong password, when in fact it has only downloaded a broken/incomplete RAR?

SABnzbd 3.1.0 running on Linux (Slackware 14.2 i686), download dir is on NFS (provided by a QNAP NAS).

Startup log:

Code: Select all

2020-10-20 22:33:29,852::INFO::[SABnzbd:1142] --------------------------------
2020-10-20 22:33:29,853::INFO::[SABnzbd:1143] SABnzbd.py-3.1.0 (rev=23f86e95f1f980963c4e4017276b3a3e2adfc6e2)
2020-10-20 22:33:29,853::INFO::[SABnzbd:1144] Full executable path = /usr/local/stow/SABnzbd-3.1.0/lib/python3.8/site-packages/SABnzbd-3.1.0/SABnzbd.py
2020-10-20 22:33:29,854::INFO::[SABnzbd:1154] Platform = posix
2020-10-20 22:33:29,854::INFO::[SABnzbd:1155] Python-version = 3.8.5 (default, Sep 22 2020, 05:50:13) 
[GCC 5.5.0]
2020-10-20 22:33:29,854::INFO::[SABnzbd:1156] Arguments = "./SABnzbd.py" "-d" "-f" "/home/zlatko/.sabnzbd/sabnzbd.ini" "--pidfile" "/var/local/run/sabnzbd/sabnzbd-9090.pid"
2020-10-20 22:33:29,854::INFO::[SABnzbd:1160] Not inside a docker container
2020-10-20 22:33:29,854::INFO::[SABnzbd:1163] Preferred encoding = UTF-8
2020-10-20 22:33:29,854::INFO::[SABnzbd:1179] SSL version = OpenSSL 1.1.1g  21 Apr 2020
2020-10-20 22:33:29,858::INFO::[SABnzbd:1188] Certifi version: 2017.11.05
2020-10-20 22:33:29,858::INFO::[SABnzbd:1189] Loaded additional certificates from: /usr/local/lib/python3.6/site-packages/certifi/cacert.pem
2020-10-20 22:33:29,858::INFO::[SABnzbd:1234] Using INI file /home/zlatko/.sabnzbd/sabnzbd.ini
2020-10-20 22:33:29,874::INFO::[postproc:140] Loading postproc queue
2020-10-20 22:33:29,875::INFO::[__init__:951] [N/A] /home/zlatko/.sabnzbd/admin/Rating.sab missing
2020-10-20 22:33:29,876::INFO::[scheduler:216] Setting schedule for midnight BPS reset
2020-10-20 22:33:29,876::INFO::[__init__:349] All processes started
2020-10-20 22:33:29,877::INFO::[SABnzbd:297] Template location for Glitter is /usr/local/stow/SABnzbd-3.1.0/lib/python3.8/site-packages/SABnzbd-3.1.0/interfaces/Glitter
2020-10-20 22:33:29,877::INFO::[SABnzbd:297] Template location for Config is /usr/local/stow/SABnzbd-3.1.0/lib/python3.8/site-packages/SABnzbd-3.1.0/interfaces/Config
2020-10-20 22:33:29,878::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n', '10', '/usr/bin/ionice', '-c2', '-n4', '/usr/local/bin/unrar']
2020-10-20 22:33:29,900::INFO::[misc:986] [N/A] Running external command: ['/usr/bin/nice', '-n', '10', '/usr/bin/ionice', '-c2', '-n4', '/usr/local/bin/par2_tbb', '-h']
2020-10-20 22:33:29,920::INFO::[SABnzbd:398] SABYenc module (v4.0.2)... found!
2020-10-20 22:33:29,921::INFO::[SABnzbd:417] Cryptography module (v3.1.1)... found!
2020-10-20 22:33:29,921::INFO::[SABnzbd:422] par2 binary... found (/usr/local/bin/par2_tbb)
2020-10-20 22:33:29,921::INFO::[SABnzbd:429] UNRAR binary... found (/usr/local/bin/unrar)
2020-10-20 22:33:29,921::INFO::[SABnzbd:439] UNRAR binary version 5.50
2020-10-20 22:33:29,922::INFO::[SABnzbd:447] 7za binary... found (/usr/local/bin/7za)
2020-10-20 22:33:29,922::INFO::[SABnzbd:458] nice binary... found (/usr/bin/nice)
2020-10-20 22:33:29,922::INFO::[SABnzbd:462] ionice binary... found (/usr/bin/ionice)
2020-10-20 22:33:29,926::INFO::[SABnzbd:1293] HTTPS keys are OK
2020-10-20 22:33:29,932::INFO::[SABnzbd:1421] Starting web-interface on 127.0.0.1:9090
2020-10-20 22:33:29,933::INFO::[_cplogging:213] [20/Oct/2020:22:33:29] ENGINE Bus STARTING
2020-10-20 22:33:30,084::INFO::[_cplogging:213] [20/Oct/2020:22:33:30] ENGINE Serving on https://127.0.0.1:9090
2020-10-20 22:33:30,186::INFO::[_cplogging:213] [20/Oct/2020:22:33:30] ENGINE Serving on http://127.0.0.1:8095
2020-10-20 22:33:30,187::INFO::[_cplogging:213] [20/Oct/2020:22:33:30] ENGINE Bus STARTED
2020-10-20 22:33:30,188::INFO::[SABnzbd:1458] Starting SABnzbd.py-3.1.0
2020-10-20 22:33:30,192::INFO::[dirscanner:117] Dirscanner starting up
2020-10-20 22:33:30,195::INFO::[urlgrabber:96] URLGrabber starting up
2020-10-20 22:33:30,197::INFO::[notifier:122] Sending notification: SABnzbd - SABnzbd 3.1.0 started (type=startup, job_cat=None)
2020-10-20 22:33:30,203::INFO::[postproc:232] Completed Download Folder /home/zlatko/mnt/nas/_/Downloads is not on FAT
2020-10-20 22:33:30,491::INFO::[notifier:182] Send to NotifyOSD: SABnzbd / SABnzbd 3.1.0 started
Please let me know if you need any additional information.

Thanks,
Thomas

User avatar
sander
Release Testers
Release Testers
Posts: 7229
Joined: January 22nd, 2008, 2:22 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by sander »

if you set SAB's logging to +Debug (under the Wrench symbol), your sabnzbd.log will tell in detail what SAB does and doesn't

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

Okay, I'll do that and wait for the next "ENCRYPTED" pause to happen. Thanks! :)

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

Okay, well that didn't take long, did it? ;) I would have posted the logs here, but as it seems I can't because of:
The submitted form was invalid. Try submitting again.
Your message contains 99904 characters.
The maximum number of allowed characters is 20000.
So instead I'll put it up on pastebin.com and post the links here. Here we go;

This is the full log from the initial download attempt: https://pastebin.com/CdCniYuC
There were another few entries while the download was paused: https://pastebin.com/tL3SjX4G
And this is after I simply clicked "Continue" without doing anything else: https://pastebin.com/E8MQcgve

And that was that, the NZB was fully downloaded and decrypted without any further input from my side (except for clicking "Continue/Resume", of course). Does any of this explain why it pauses the download as "ENCRYPTED"?

User avatar
sander
Release Testers
Release Testers
Posts: 7229
Joined: January 22nd, 2008, 2:22 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by sander »

Did you read the log yourselves? What did you see?

Reason: at passwords, I'm just a user, and in your first log, I see a few "Trying password" (2 from the NZB, 4 or so from password.ini), and that fails. I see no password trying in the other log files ...

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

sander wrote:
October 25th, 2020, 2:35 am
Did you read the log yourselves? What did you see?

Reason: at passwords, I'm just a user, and in your first log, I see a few "Trying password" (2 from the NZB, 4 or so from password.ini), and that fails. I see no password trying in the other log files ...
Ummm ... why, yes, of course I did. And what I did not see is any reason to go looking for passwords in passwords.ini, because the password was already supplied in the URL, and was detected and extracted by SABnzbd just fine, as stated in the logs:

Code: Select all

2020-10-24 20:58:46,138::DEBUG::[nzbstuff:1890] Saving attributes {'cat': '*', 'pp': 3, 'script': 'None', 'priority': 0, 'final_name': 'Die.Vulkan.Haie.von.La.Reunion.GERMAN.DOKU.HDTVRip.x264-TMSF', 'password': 'ygVcSHJD0KHaRdQ0BxxQHN0XsTylEJ8F7z8LxT3', 'url': 'Die.Vulkan.Haie.von.La.Reunion.GERMAN.DOKU.HDTVRip.x264-TMSF{{ygVcSHJD0KHaRdQ0BxxQHN0XsTylEJ8F7z8LxT3}}.nzb'} for Die.Vulkan.Haie.von.La.Reunion.GERMAN.DO KU.HDTVRip.x264-TMSF
And I already did mention several times in both my original report and my followup containing the logs that I do not have to change or reenter the password once the download gets stopped, and it still gets completed and decrypted properly once I click "Resume". So this suggests to me that a missing or wrong password is not the problem here.

Or did I misunderstand what you were trying to point me at?

User avatar
sander
Release Testers
Release Testers
Posts: 7229
Joined: January 22nd, 2008, 2:22 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by sander »

Sorry, I don't understand what you mean.

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

Oooh, I think I misread your reply ... sorry! So you're saying that there's an indication in the logs somewhere that also the password from the NZB itself failed, ie. the one that's encoded within the curly brackets {{...}} in the filename? I guess I must have missed that one. I'm going back to re-read the logs.

But even if that*s the case, the question remains: why does it fail to decrypt with the NZB-supplied password on the first try, and succeeds to decrypt the very same NZB with the very same password on the second try (ie. after I hit "Resume)?

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

Yes, you're right, now I see what you mean: in lines 246 - 250 from the first log it collects a total of 8 passwords (1 "user supplied" + 2 "from nzb metadata" + 5 "from passwords.ini", and then later on in line 267 it builds what looks like a 100% correct commandline for unpacking (including the correct password), but still claims that it didn't work out in line 283.

Which is no big wonder, actually, as (if I read the logs correctly) it only has the first 3 of 7 RARs downloaded at this time so far ... could it be that this is related to me having "[x] Direct Unpack" enabled? The description of this option warns that it "Only works for jobs that do not need repair.", but from the third log in lines 167 - 174 it seems that repair was actually not needed here, so it should have succeeded ... or am I missing something?

User avatar
safihre
Administrator
Administrator
Posts: 3973
Joined: April 30th, 2015, 7:35 am
Location: Switzerland
Contact:

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by safihre »

Do you maybe have the original NZB for me?
This could be a bug in the rarfile module that we use, because it says:

Code: Select all

2020-10-24 20:58:54,343::INFO::[assembler:317] Trying password "ygVcSHJD0KHaRdQ0BxxQHN0XsTylEJ8F7z8LxT3" on job "Die.Vulkan.Haie.von.La.Reunion.GERMAN.DOKU.HDTVRip.x264-TMSF"
Which I assume is the correct password since it was part of the NZB filename, however it is not detected as such.
If you like our support, check our special newsserver deal or donate at: https://sabnzbd.org/donate

User avatar
ZlatkO
Newbie
Newbie
Posts: 18
Joined: April 22nd, 2016, 11:57 pm

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by ZlatkO »

Sure, no problem, here's the link. But it probably won't help much, because the problem doesn't seem to be reproducible. Just for kicks, I re-downloaded it again just now, and it worked fine on the first try this time.

I also noticed that I had "Action when encrypted RAR is downloaded: Pause" configured, could that maybe conflict with "[x] Direct Unpack"? I have now changed it to "Action when encrypted RAR is downloaded: Off" just to see if that makes a difference.

User avatar
safihre
Administrator
Administrator
Posts: 3973
Joined: April 30th, 2015, 7:35 am
Location: Switzerland
Contact:

Re: Downloads stop with "ENCRYPTED" proper password is already supplied

Post by safihre »

No I think it is more of a fundamental problem with rarfile module, which I know can be unreliable sometimes. Just need to make it a bit more robust :) Direct unpack is a bit blunt, it just goes ahead and tries to unpack with the first password it can find. It doesn't care about that other detection that pauses it :P
But indeed if you switch encrypted detection off, it disables any checking behavior.
If you like our support, check our special newsserver deal or donate at: https://sabnzbd.org/donate

Post Reply