search

sabnzbd / sabnzbd

SABnzbd - The automated Usenet download tool
http://sabnzbd.org
Other
2.24k stars 338 forks source link

3.4.0 beta1: postproc.y has incorrect `newfiles` in certain cases (causing deobfuscate not working) #1930

Closed sanderjo closed 3 years ago

sanderjo commented 3 years ago

newfiles in postproc.py sometimes has two times the job name as dir. That is wrong, as that directory does not exist.

See the /media/sander/6665-6464/Tree Car 1234/Tree Car 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv below.

It seems to happen if the job names ends with a number with 2 decimals or more. @jcfp something to do with guessit? Althought I have Sorting turned off (AFAIK)

Result: the call deobfuscate.deobfuscate_list(newfiles, nzo.final_name) has incorrect input, and so deobfuscate does not work.

2021-07-18 19:05:51,581::INFO::[postproc:523] Running deobfuscate
2021-07-18 19:05:51,581::DEBUG::[postproc:524] SJ000: newfiles ['/media/sander/6665-6464/Tree Car 1234/Tree Car 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:51,581::DEBUG::[postproc:525] SJ001: nzo.final_name Tree Car 1234
2021-07-18 19:05:51,581::DEBUG::[deobfuscate_filenames:145] SJ100: filelist ['/media/sander/6665-6464/Tree Car 1234/Tree Car 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:51,582::DEBUG::[deobfuscate_filenames:147] SJ200: filelist []

OK (no decimals at end):

2021-07-18 19:05:23,524::DEBUG::[postproc:524] SJ000: newfiles ['/media/sander/6665-6464/Seven Eight Nine/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:23,524::DEBUG::[postproc:525] SJ001: nzo.final_name Seven Eight Nine

Bad (double dir), 4 decimals at end

2021-07-18 19:05:51,581::DEBUG::[postproc:524] SJ000: newfiles ['/media/sander/6665-6464/Tree Car 1234/Tree Car 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:51,581::DEBUG::[postproc:525] SJ001: nzo.final_name Tree Car 1234

Bad (double dir), 2 decimals at end

2021-07-18 19:12:16,199::DEBUG::[postproc:524] SJ000: newfiles ['/media/sander/6665-6464/One One One 11/One One One 11/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:12:16,199::DEBUG::[postproc:525] SJ001: nzo.final_name One One One 11

OK, 1 decimal at end:

2021-07-18 19:12:36,602::DEBUG::[postproc:524] SJ000: newfiles ['/media/sander/6665-6464/two two 2/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:12:36,602::DEBUG::[postproc:525] SJ001: nzo.final_name two two 2
sanderjo commented 3 years ago

In postproc.py, close after line 422, newfiles becomes: ['/media/sander/6665-6464/hello moon 1234/_UNPACK_hello moon 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv'] ... looks suspicious already ... twice the job name

At line 503, newfiles has turned into:

['/media/sander/6665-6464/hello moon 1234/hello moon 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']

That's bad

Ah, logging tells it too:

2021-07-18 19:20:46,439::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/hello moon 1234/_UNPACK_hello moon 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']

Ah, here we go:

2021-07-18 18:49:04,928::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/_UNPACK_test_download_100MB.2/sometestfile-100MB.bin']
2021-07-18 18:50:26,630::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/_UNPACK_My Own Download/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 18:54:40,689::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/Another Download 1234/_UNPACK_Another Download 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:02:20,433::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/_UNPACK_One Two Three/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:02:48,969::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/Four Five Six 1234/_UNPACK_Four Five Six 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:23,511::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/_UNPACK_Seven Eight Nine/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:05:51,576::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/Tree Car 1234/_UNPACK_Tree Car 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:12:16,197::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/One One One 11/_UNPACK_One One One 11/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:12:36,600::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/_UNPACK_two two 2/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-18 19:20:46,439::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/hello moon 1234/_UNPACK_hello moon 1234/b082fa0beaa644d3aa01045d5b8d0b11.mkv']

Also problem with jobname "One 4444 Two"

2021-07-18 19:35:41,827::INFO::[postproc:431] Unpacked files ['/media/sander/6665-6464/One 4444 Two/_UNPACK_One 4444 Two/b082fa0beaa644d3aa01045d5b8d0b11.mkv']

sanderjo commented 3 years ago

https://github.com/sabnzbd/sabnzbd/commit/b2cbb8c8d0ab7172c05bd99b08ae51c5c41919d0#diff-5242b2869e77ea17dd2047e446434821a82db00800f901458e40a39b8b5979dbL518-R519 has changes to/with newfiles

After revert / drop commit b2cbb8c8d0ab7172c05bd99b08ae51c5c41919d0, it works again

Good: 2021-07-18 21:41:31,632::INFO::[postproc:435] Unpacked files ['/media/sander/6665-6464/_UNPACK_Bla One 7777/b082fa0beaa644d3aa01045d5b8d0b11.mkv']

Good result: /media/sander/6665-6464/Bla One 7777/Bla One 7777.mkv

So, @jcfp , could you have a look at this issue please

puzzledsab commented 3 years ago

From what I can tell, this is triggered because 1234 is now detected as season 12 episode 34, which means it's an episode. That makes it call code added in this commit from 2008, which adds the nzb name to the complete dir: https://github.com/sabnzbd/sabnzbd/commit/18e7530f8f07096b3ca046fcbd68a5fa088ea1be (line 625).

I have no idea why it works like this but it seems intentional. Adding the extra level didn't cause problems when I tested with an nzb that ended in 1234.

sanderjo commented 3 years ago

Adding the extra level didn't cause problems when I tested with an nzb that ended in 1234.

Reference NZB, which you can put directly into SAB's "Fetch NZB from URL": https://raw.githubusercontent.com/sanderjo/NZBs/master/My%20Very%20Very%20Important%20Download%202021.nzb

With "Deobfuscate" on, what is your result with 3.4.0 Beta1 resp 3.3.1?

With 3.4.0 Beta 1, it results in /media/zeegat/My Very Very Important Download 2021/b082fa0beaa644d3aa01045d5b8d0b11.mkv ... so the filename is not deobfuscated.

$ cat .sabnzbd/logs/sabnzbd.log | grep -i -e deob -e "Unpacked files" 
2021-07-19 17:15:49,417::INFO::[postproc:431] Unpacked files ['/media/zeegat/My Very Very Important Download 2021/_UNPACK_My Very Very Important Download 2021/b082fa0beaa644d3aa01045d5b8d0b11.mkv']
2021-07-19 17:15:49,420::INFO::[postproc:523] Running deobfuscate
2021-07-19 17:15:49,421::DEBUG::[deobfuscate_filenames:152] No par2 files found to process, running renamer
2021-07-19 17:15:49,421::DEBUG::[deobfuscate_filenames:210] Trying to see if there are qualifying files to be deobfuscated

That first line is the culprit, IMHO. That path-file does not exist at that moment in time.

puzzledsab commented 3 years ago

Yes, it does break deobfuscate. I also noticed that if there is an existing dir with the same name in the complete dir, instead of adding a .1 dir, it will move the new files to the same dir but rename them to for instance existingfile.1.jpg. I tried returning just self.original_path instead of os.path.join(self.original_path, self.original_job_name), but then the new files will be moved to the root of the incoming dir.

I don't know how to make it consistent because I don't understand why the old code is the way it is. Maybe @jcfp will understand it quickly so I won't spend any more time on it for now.

sanderjo commented 3 years ago

OK, so confirmed. Good.

More hypotheses:

Yes, my hope is on @jcfp too.

Safihre commented 3 years ago

The problem is that file_sorter.detect doesn't seem to check if Sorting is enabled or not, it always returns a path. https://github.com/sabnzbd/sabnzbd/blob/1052f37d02724417fd36cfff3af07a075becaae6/sabnzbd/postproc.py#L695

Safihre commented 3 years ago

Oke I fixed this. Next problem: the sorter renames folders and files, but doesn't update newfiles.

Safihre commented 3 years ago

I will close this, as Deobfuscate never worked with Sorting. It's not 3.4.0 specific.

sanderjo commented 3 years ago

I will close this, as Deobfuscate never worked with Sorting. It's not 3.4.0 specific.

So it's caused by Sorting? I checked, and AFAIK I haven't sorting on.

Safihre commented 3 years ago

355d02faa3d27ac2096d130ce5eabdecbdc623a4 fixes the problem if Sorting is not enabled.