failed message received right after success message.

[diamaunt]

sab 1.1.0 from source.

occasionally, I'll get a completion email, immediately followed by an failed email.

the only thing I can find in the log is:

2016-10-24 19:13:17,681::DEBUG::[misc:1224] Renaming "oldname" to "newname"
2016-10-24 19:13:18,232::INFO::[emailer:147] Notification e-mail successfully sent
2016-10-24 19:13:18,425::ERROR::[postproc:532] Post Processing Failed for [name]
2016-10-24 19:13:18,425::INFO::[postproc:534] Traceback:
Traceback (most recent call last):
File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 507, in process_job
cleanup_list(workdir_complete, False)
File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 722, in cleanup_list
path = os.path.join(wdir, filename)
File "/usr/lib/python2.7/posixpath.py", line 80, in join
path += '/' + b
UnicodeDecodeError: 'utf8' codec can't decode byte 0xbd in position 2: invalid start byte

everything *seems* to have worked ok.

[sander]

Code: Select all

UnicodeDecodeError: 'utf8' codec can't decode byte 0xbd in position 2: invalid start byte

That's probably a post with a strangely encoded filename in it. Strangely as in "non-ASCII and non-Unicode" encoded. So possibly ü or é with a Windows-like encoding (for example cp1252).

Can you verify that?

[diamaunt]

Code: Select all

UnicodeDecodeError: 'utf8' codec can't decode byte 0xbd in position 2: invalid start byte

That's probably a post with a strangely encoded filename in it. Strangely as in "non-ASCII and non-Unicode" encoded. So possibly ü or é with a Windows-like encoding (for example cp1252).

Can you verify that?

how can I find out? sab downloads, drops the desired file into the output directory, throws the error and deletes all the files except for the _ADMIN_ directory under inproc/$nzbname

[sander]

Really? Strange. Nothing in that ADMIN directory

Are you using a postprocessing script? If so, turn it off, and try the download again.

AND: set SAB logging to +Debug, and redownload, and then:

Code: Select all

cat sabnzbd.log | grep -i -e extracting -e existence

HTH

[diamaunt]

Really? Strange. Nothing in that ADMIN directory

Are you using a postprocessing script? If so, turn it off, and try the download again.

AND: set SAB logging to +Debug, and redownload, and then:

Code: Select all

cat sabnzbd.log | grep -i -e extracting -e existence

HTH

there were some files. SABnzbd_attrib, __verified__ and the nzb file.

I PMd you the result of the grep, trying not to violate the "don't be stupid" forum rule... (good rule, that)

no postprocessing script.

[sander]

In your logging I see no non-ASCII characters. Only: ( ) ,

Can you PM me the NZB or a link to the NZB so that I can download it myself?

Furthermore: what kind of filesystem is used for Imcomplete and Complete?

[diamaunt]

In your logging I see no non-ASCII characters. Only: ( ) ,

Can you PM me the NZB or a link to the NZB so that I can download it myself?

Furthermore: what kind of filesystem is used for Imcomplete and Complete?

I'll PM you a link.

filesystem? it's all running on zfs, if that's what you mean.

[sander]

No problems with downloading that NZB on my Ubuntu (with ext4).

In the traceback, you can see the problem comes from:

cleanup_list(workdir_complete, False)
path = os.path.join(wdir, filename)
path += '/' + b
UnicodeDecodeError: 'utf8' codec can't decode byte 0xbd in position 2: invalid start byte

That 0xbd can mean different things in different encodings:
ISO-8859-1/CP-1252 ½
ISO-8859-15: œ
... but I don't expect them in your workdir (right?) nor the downloaded files


What is the encoding you use? Check with:

Code: Select all

cat sabnzbd.log | grep -i encoding

[diamaunt]

No problems with downloading that NZB on my Ubuntu (with ext4).

In the traceback, you can see the problem comes from:

cleanup_list(workdir_complete, False)
path = os.path.join(wdir, filename)
path += '/' + b
UnicodeDecodeError: 'utf8' codec can't decode byte 0xbd in position 2: invalid start byte

That 0xbd can mean different things in different encodings:
ISO-8859-1/CP-1252 ½
ISO-8859-15: œ
... but I don't expect them in your workdir (right?) nor the downloaded files


What is the encoding you use? Check with:

Code: Select all

cat sabnzbd.log | grep -i encoding

I had to go back 5 log files before 'encoding' showed up, and that was:
sabnzbd.log.5:2016-10-21 16:49:28,013::INFO::[SABnzbd:1248] Preferred encoding = UTF-8
sabnzbd.log.5:2016-10-21 16:49:29,894::INFO::[SABnzbd:1248] Preferred encoding = UTF-8

[diamaunt]

here's another bit of data... I noticed that it's only movies that are causing me problems. so I downloaded into another category.

no error.

when it's assigned to the 'Movie Sorting' category, it gives the failure. I've got sort string set to '%title (%y).%ext', multi-part label to "CD%1". "keep loose downloads in extra folders' is not checked.

[sander]

Even with that setting filled out, it works well on my setup. So I still can't reproduce.

So ... back to you:

Code: Select all

File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 507, in process_job
cleanup_list(workdir_complete, False)
File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 722, in cleanup_list
path = os.path.join(wdir, filename)

So in sabnzbd/postproc.py, before those commands you could put in a print command

Code: Select all

logging.debug('MyDebug:  workdir is %s', workdir)

resp

Code: Select all

logging.debug('MyDebug:  wdir is %s', wdir)
logging.debug('MyDebug:  filename is %s', filename)

Then redownload the file. Hopefully the logging will make clear the offending name.

[diamaunt]

Even with that setting filled out, it works well on my setup. So I still can't reproduce.

So ... back to you:

Code: Select all

File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 507, in process_job
cleanup_list(workdir_complete, False)
File "/opt/SABnzbd-1.1.0/sabnzbd/postproc.py", line 722, in cleanup_list
path = os.path.join(wdir, filename)

So in sabnzbd/postproc.py, before those commands you could put in a print command

Code: Select all

logging.debug('MyDebug:  workdir is %s', workdir)

resp

Code: Select all

logging.debug('MyDebug:  wdir is %s', wdir)
logging.debug('MyDebug:  filename is %s', filename)

Then redownload the file. Hopefully the logging will make clear the offending name.

I'll PM you the results..

[diamaunt]

for anybody following this, it looks like the abort was caused by a *completely* unrelated file in the output directory that had been there for some long time (the error had been happening for a while, I'd just gotten around to asking about it).

why sab is running through my output directory after dropping something new into it, I've no idea, hoping that Sander can enlighten me on that.

[safihre]

We do that to check if the extraction went well! A final check if a expected files were unpacked.

[diamaunt]

We do that to check if the extraction went well! A final check if a expected files were unpacked.

well, ah, maybe there's a way to check the directory without barfing on unrelated files in the dir? or, at least, if it must barf on unrelated files, if it could indicate that it barfed on an unrelated file and not lead to this kind of questioning and spurious errors?

there were several times when I'd see in the gui that the post processing failed, and I'd naturally assume the download was bad in some way or another... and I'd do another download, and sometimes another... and then happen to look in the directory and see that they all had actually apparently succeeded, and SAB had rather mislead me about the success.

until the extra debugging statements that Sander suggested, there was no indication whatsoever as to where the problem actually was.