sab 0.7.3 not downloading additional par2 files

[DarkCuddles]

Hey guys.

Just wondering if someone can help me with this. It MIGHT be a dodgy nzb thing but I thought I'd check anyway.

I have sickbeard feeding info into sab running on freenas (BSD). It is all mostly working fine. One of the hiccups I've come across is a particular file is failing on the Par verify. I ran it manually myself and it's short 1 block. The incomplete download directy only contains the single par2 file that sab downloads as normal. It doesn't appear to have downloaded any extra par2 files. I decided to remove it from the history, including the nzb and all files and start over, triggering the search and download from sickbeard to start over.
As soon as sickbeard had done its thing, I jumped over to sab and forced it to the top of the queue. It indicated, as soon as it started that it had already downloaded 429MB, the exact combined size of the par2 files.

(Treat this as seperate) I also decided to download all the par2 files in a seperate nzb to run a manual repair on it and it downloaded only a single par2 file taking all of 3 seconds despite indicating the size would be 429mb. I was able to successfully repair the file manually (and even stashed the par2 file into the directory that primary files were downloading to, on the offchance it would run a successful repair - it didn't).

I am using premium services so I can tell you that retention isn't the issue.

I'm not sure what I'm missing, but it seems strange to me that sab would start an nzb thinking it had downloaded all the par2 files when it hadn't. Perhaps if someone could also confirm if the par2 files are downloaded into the same folder as the rars?

I guess the other question I have is that I have a now repaired download ready for post processing. Is there a way to force it to go through post processing as the retry button doesn't seem to do much?

Thanks for having a look at this.

[sander]

I think SAB will only download par2-files when they are needed. So, if they are not downloaded, SAB apparently thinks the rar's are OK. You could check the log file to see if there is any info.

In the retry you can 'feed' SAB ad additonal (NZB?) file. Have you tried that?

[DarkCuddles]

Hi Sander,

2012-09-02 05:08:46,704::INFO::[postproc:546] Par2 check starting on
2012-09-02 05:08:46,704::INFO::[postproc:561] Running repair on set
2012-09-02 05:08:46,708::INFO::[newsunpack:1301] Quick-check of file
2012-09-02 05:08:46,708::INFO::[newsunpack:789] Scanning
2012-09-02 05:08:46,781::INFO::[newsunpack:807] Par verify failed on par2!
2012-09-02 05:08:46,782::INFO::[postproc:574] Par2 check finished on
Update (Just in case this is worth noting - as part of the cleanup process it can't remove these folders)
2012-09-02 08:11:10,928::INFO::[misc:1260] Cannot remove folder .../__ADMIN__
2012-09-02 08:11:10,951::INFO::[misc:1260] Cannot remove folder .../__ADMIN__

That's from the log I've stripped out directory/name stuff. It's worth noting I switched off Fail on yEnc CRC Errors (it certainly made the log more readable).

I have tried that. I've got a big queue for downloading, so I don't know if that waits until the download queue is cleared before doing anything, but at the moment it's just sitting there with the down arrow icon and the retry link.
The only status it gave me was "Failed". Didn't mention par2 failures or sfv failures or anything like that. It downloaded with the inital par2, but it isnt downloading the additional ones. Does it download the additional par2 files into the _ADMIN_ folder or is that just for category and other stuff?

Update: I've also tried an nzb generated from a different site for the same file content and have the same issue, even when I include all the par2 files it does exactly the same thing.

I guess another follow up question I have is, is it normal behaviour for sab to just consider par2's as downloaded initially and that's why it reports as having already completed the par2 size content?

[shypike]

Did you click on the failed entry so see the download report?
What does it say?

[DarkCuddles]

I surely did! The status just says "Failed". It doesn't offer any useful info or reasons as to why. It does not display any unpack, repair or script fields.
A more recent attempt shows something I must've missed. It's failing on the nfo quick check as well. I was able to open the nfo in getdiz without running any manual repairs or anything like that. What does it check in the nfo?

[shypike]

There's no such thing as an "nfo quick check", do you mean sfv?
Other than that, we don't really support unraid, because it's just too hard to do.
For one thing: it cannot be virtualized and we're not going to setup a hardware box for it.

Please send the NZB file to [email protected],
maybe it is a bug in SABnzbd, but there are plenty of goofy posts on Usenet...

[DarkCuddles]

Sorry, it was running a quick check of the nfo (poor wording on my part):
2012-09-02 05:08:46,708::INFO::[newsunpack:1301] Quick-check of file ....nfo failed!

I'm not using unraid, but I'll shoot the nzb through to you. Thanks mate.

[shypike]

There's nothing wrong with the NZB as you sent it.
Which SABnzbd are you using?
You said you repaired it manually; was that on the same freenas system or on a PC or Mac?
SABnzbd indeed skips the major par2 files and will download those only when the first repair run fails.
There have been some releases that were a bit buggy in this area.
0.7.3 should handle this NZB properly.

[DarkCuddles]

Thanks for looking at it shypike. I'm running 0.7.3. Because FreeNAS uses a plugin system now, it'll be a custom .pbi using the Python install.
The check fails on the nfo file, I manually ran quickpar over the network through a temp cifs share i'd configured (and pointed quickpar to the incomplete folder) but I did have to create an nzb with just the par2 files in order to get that single extra par2 file to repair the nfo (and dump the par2 file into the relevant folder). I then just manually used sickbeard to run post proc.

Is there any chance I could get a look at what a log file looks like when it has actually downloaded the additional par2s? It really does look like that's what is not happening. Also, is there any reason you can think of why it wouldn't grab the extra par2's after a failed check (such as a large queue)?

[shypike]

The point is, nothing goes wrong on my test systems.
Meaning that, if a bug exists (and it could very well), it manifests itself on your system, but not on most other systems.
It would be more useful when you create a (debug) log file for what goes wrong on your system.
(Or do you happen to have such a log file already?)
One thing you could try is this: disable QuickCheck in Config->Switches.
The effect will be that the par2 program will always be run and that any discrepancy between
QuickCheck and par2 will be reported as a warning.

[B3nson]

I have the exact same behavior for all my queue since i upgraded to 0.7.2 AND 0.7.3.
I'm on Mac OS X Lion.
Manually getting the par2 files and doing the repair by hand (using SabNZBd's own par2 utility) works.
The log is not verbose at all, just saying that that par2 check failed.

Extract from log:

2012-09-05 18:08:58,425::INFO::[assembler:143] <Article: article=723$4fcd2b82$c3b86ad8$[email protected], bytes=55038, partnum=3, art_id=None> missing
2012-09-05 18:08:58,711::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzo_aERhRJ removed
2012-09-05 18:08:58,711::INFO::[nzbqueue:176] Saving queue
2012-09-05 18:08:58,711::INFO::[__init__:895] Saving data for queue9.sab in /Users/mstation/Public/nzb/admin/queue9.sab
2012-09-05 18:08:58,750::INFO::[postproc:84] Saving postproc queue
2012-09-05 18:08:58,750::INFO::[__init__:895] Saving data for postproc1.sab in /Users/mstation/Public/nzb/admin/postproc1.sab
2012-09-05 18:08:58,816::INFO::[postproc:280] Starting PostProcessing on x_s02e10 => Repair:True, Unpack:True, Delete:True, Script:None, Cat:series tv
2012-09-05 18:08:58,817::INFO::[notifier:87] Sending registration to localhost:23053
2012-09-05 18:08:59,318::INFO::[postproc:546] Par2 check starting on x
2012-09-05 18:08:59,319::INFO::[postproc:561] Running repair on set x
2012-09-05 18:08:59,322::INFO::[newsunpack:789] Scanning "/Users/mstation/Public/nzb/incomplete/x/x.vol000+01.par2"
2012-09-05 18:08:59,387::INFO::[newsunpack:807] Par verify failed on /Users/mstation/Public/nzb/incomplete/x/x.vol000+01.par2!
2012-09-05 18:08:59,388::INFO::[postproc:574] Par2 check finished on x
2012-09-05 18:08:59,391::INFO::[notifier:87] Sending registration to localhost:23053
2012-09-05 18:08:59,971::INFO::[postproc:519] Cleaning up x (keep_basic=True)
2012-09-05 18:08:59,971::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_f0C4OE removed
2012-09-05 18:08:59,972::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_aV9wzp removed
2012-09-05 18:08:59,972::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_4Ufrkx removed
2012-09-05 18:08:59,972::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_spZ7xR removed
2012-09-05 18:08:59,972::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_gDMjnm removed
2012-09-05 18:08:59,972::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_58WcPQ removed
2012-09-05 18:08:59,973::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_anwUeC removed
2012-09-05 18:08:59,973::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_Eqd_SN removed
2012-09-05 18:08:59,973::INFO::[__init__:884] /Users/mstation/Public/nzb/incomplete/x/__ADMIN__/SABnzbd_nzf_5lvtfk removed
2012-09-05 18:08:59,974::INFO::[misc:1260] Cannot remove folder /Users/mstation/Public/nzb/incomplete/x/__ADMIN__
2012-09-05 18:08:59,974::INFO::[misc:1260] Cannot remove folder /Users/mstation/Public/nzb/incomplete/x/__ADMIN__
2012-09-05 18:08:59,975::INFO::[postproc:84] Saving postproc queue
2012-09-05 18:08:59,975::INFO::[__init__:895] Saving data for postproc1.sab in /Users/mstation/Public/nzb/admin/postproc1.sab
2012-09-05 18:08:59,975::INFO::[downloader:243] Post-processing finished, resuming download

[shypike]

You first need to set the logging level to "Debug", otherwise it's useless.
Can you email a debug log of a failed session to [email protected] ?

[DarkCuddles]

Hi Shypike,

Sorry for the delay in replying. I've emailed you a full debug log with an example (and appropriate timecode).

I have just enabled "Pause download during post processing" and "Only get articles from top of queue" just in case this an issue with non availability of connections or something. I'll see if that makes any difference. Hopefully the logs will give you some useful information.

Thanks.

[B3nson]

You first need to set the logging level to "Debug", otherwise it's useless.
Can you email a debug log of a failed session to [email protected] ?

I changed log level to 2 in the sabnzbd.ini file and restarted the app. Assuming it will work you sould reeive the debug log tonight.

[shypike]

Analysing DarkCuddles material, my preliminary diagnose is this:

This is a case of a foolish poster.
The par2 files specify files like this: "This.Show.S01E22",
but the actual downloaded files are like: "this.show.s01e22".
On Windows and OSX, this is not an issue, but it is on Linux,
Especially because par2 isn't too clever about this, files will never repair.
We've looked at work-arounds in the past, but it's hard to make it solid.
One method is to add a * as a parameter for par2.
That will make par2 reconstruct (or just rename) the files.
The side effect is that most verification runs will be considerably slower,
which is the reason we never did this. (Plus it has some major other side-effects,
requiring extensive code changes).

So far, I'm not quite sure whether this is a case of not loading enough par2 files.
In this case there are never enough.

I will look further into the log files of both of you, but it may take a while.