Page 1 of 1

post processing issues

Posted: Sun May 12, 2019 11:41 am
by ludwig
Mylar Version: development
-- git build 7696edbc8b6fd893550965a0ea892143e53e23bd.
Python Version : 2.7.15rc1
Language : en_US.UTF-8

Ubuntu 18.04.2 LTS

sometime in the past few weeks, I've begun having an issue where I can no longer complete post-processing. mylar find the original file, runs through the the tagging but then cannot move the file from cache to its final destination. As far as I can tell, all permissions appear to be fine although the cbz that's created shows up with 600 which seems like it should work but is odd.

Looking into it further, i see that the cbz IS placed in the appropriate directory. however, the cache file/folder is not removed and Mylar is not updated with the fact that the file is there. meaning, if I go to (from the example below) this issue is shown as snatched. if i recheck files, it will see the file there and change do downloaded.


12-May-2019 13:05:59 - DEBUG :: mylar.run.50 : Thread-21 : Filepath: /mnt/processing/watch/mylar/Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:05:59 - DEBUG :: mylar.run.51 : Thread-21 : Filename: Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:05:59 - DEBUG :: mylar.run.53 : Thread-21 : New_Folder: /opt/Mylar/cache/mylar_QWnJ5t
12-May-2019 13:05:59 - DEBUG :: mylar.run.55 : Thread-21 : New_Filepath: /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:05:59 - DEBUG :: mylar.run.73 : Thread-21 : [META-TAGGER] Paths / Locations:
12-May-2019 13:05:59 - DEBUG :: mylar.run.74 : Thread-21 : [META-TAGGER] scriptname : Mylar.py
12-May-2019 13:05:59 - DEBUG :: mylar.run.75 : Thread-21 : [META-TAGGER] downloadpath : /mnt/processing/watch/mylar
12-May-2019 13:05:59 - DEBUG :: mylar.run.76 : Thread-21 : [META-TAGGER] sabnzbdscriptpath : /opt/Mylar
12-May-2019 13:05:59 - DEBUG :: mylar.run.77 : Thread-21 : [META-TAGGER] comicpath : /opt/Mylar/cache/mylar_QWnJ5t
12-May-2019 13:05:59 - DEBUG :: mylar.run.78 : Thread-21 : [META-TAGGER] Running the ComicTagger Add-on for Mylar
12-May-2019 13:06:00 - DEBUG :: mylar.run.119 : Thread-21 : [META-TAGGER] ComicTagger 1.25.2 [ninjas.walk.alone / SHURIKEN] being used - using personal ComicVine API key supplied via mylar.
12-May-2019 13:06:00 - DEBUG :: mylar.run.131 : Thread-21 : [META-TAGGER] CR Tagging enabled.
12-May-2019 13:06:00 - DEBUG :: mylar.run.136 : Thread-21 : [META-TAGGER] CBL Tagging enabled.
12-May-2019 13:06:00 - DEBUG :: mylar.run.146 : Thread-21 : [META-TAGGER] Will modify existing tag blocks even if it exists.
12-May-2019 13:06:00 - DEBUG :: mylar.run.190 : Thread-21 : [META-TAGGER] Enabling ComicTagger script: ['/usr/bin/python', '/opt/Mylar/comictagger.py'] with options: ['-e', '--delete-rar', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:00 - DEBUG :: mylar.run.198 : Thread-21 : [META-TAGGER] Executing command: ['/usr/bin/python', '/opt/Mylar/comictagger.py', '-e', '--delete-rar', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:00 - DEBUG :: mylar.run.199 : Thread-21 : [META-TAGGER] Absolute path to script: /usr/bin/python
12-May-2019 13:06:01 - DEBUG :: mylar.run.240 : Thread-21 : [META-TAGGER] Output: Archive is not a RAR.
12-May-2019 13:06:01 - WARNING :: mylar.run.241 : Thread-21 : [META-TAGGER][COMIC-TAGGER] file is not in a RAR format: Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:06:01 - INFO :: mylar.run.184 : Thread-21 : [META-TAGGER] ComicRack tagging meta-tagging processing started.
12-May-2019 13:06:01 - DEBUG :: mylar.run.194 : Thread-21 : [META-TAGGER] Enabling ComicTagger script: ['/usr/bin/python', '/opt/Mylar/comictagger.py'] with options: ['-s', '-m', 'volume=3', '--cv-api-key', u'REDACTED', '-o', '--id', u'707483', '--type', 'cr', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:01 - DEBUG :: mylar.run.198 : Thread-21 : [META-TAGGER] Executing command: ['/usr/bin/python', '/opt/Mylar/comictagger.py', '-s', '-m', 'volume=3', '--cv-api-key', u'REDACTED', '-o', '--id', u'707483', '--type', 'cr', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:01 - DEBUG :: mylar.run.199 : Thread-21 : [META-TAGGER] Absolute path to script: /usr/bin/python
12-May-2019 13:06:13 - INFO :: mylar.run.264 : Thread-21 : [META-TAGGER][COMIC-TAGGER] Successfully wrote ComicRack tagging [/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz]
12-May-2019 13:06:13 - INFO :: mylar.run.184 : Thread-21 : [META-TAGGER] Comicbooklover tagging meta-tagging processing started.
12-May-2019 13:06:13 - DEBUG :: mylar.run.194 : Thread-21 : [META-TAGGER] Enabling ComicTagger script: ['/usr/bin/python', '/opt/Mylar/comictagger.py'] with options: ['-s', '-m', 'volume=3', '--cv-api-key', u'REDACTED', '-o', '--id', u'707483', '--type', 'cbl', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:13 - DEBUG :: mylar.run.198 : Thread-21 : [META-TAGGER] Executing command: ['/usr/bin/python', '/opt/Mylar/comictagger.py', '-s', '-m', 'volume=3', '--cv-api-key', u'REDACTED', '-o', '--id', u'707483', '--type', 'cbl', u'/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz']
12-May-2019 13:06:13 - DEBUG :: mylar.run.199 : Thread-21 : [META-TAGGER] Absolute path to script: /usr/bin/python
12-May-2019 13:06:16 - INFO :: mylar.run.264 : Thread-21 : [META-TAGGER][COMIC-TAGGER] Successfully wrote Comicbooklover tagging [/opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz]
12-May-2019 13:06:16 - INFO :: mylar.Process_next.2406 : Thread-21 : [POST-PROCESSING] Sucessfully wrote metadata to .cbz (Batman 070 (2019) (Digital) (Zone-Empire).cbz) - Continuing..
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2452 : Thread-21 : [POST-PROCESSING] ofilename: Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2460 : Thread-21 : [POST-PROCESSING] odir: /opt/Mylar/cache/mylar_QWnJ5t
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2461 : Thread-21 : [POST-PROCESSING] ofilename: Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2463 : Thread-21 : [POST-PROCESSING] ext: .cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2473 : Thread-21 : [POST-PROCESSING] Original Filename: Batman 070 (2019) (Digital) (Zone-Empire).cbz [.cbz]
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2501 : Thread-21 : [POST-PROCESSING] New Filename: Batman 070 (2019)
12-May-2019 13:06:16 - INFO :: mylar.validateAndCreateDirectory.1619 : Thread-21 : [POST-PROCESSING][DIRECTORY-CHECK] Found comic directory: /mnt/shared2/mylar/Batman (2016)
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2518 : Thread-21 : [POST-PROCESSING] Source: /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2519 : Thread-21 : [POST-PROCESSING] Destination: /mnt/shared2/mylar/Batman (2016)/Batman 070 (2019).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2566 : Thread-21 : [POST-PROCESSING] Renaming /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz ..to.. /mnt/processing/watch/mylar/Batman 070 (2019).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2570 : Thread-21 : [POST-PROCESSING] odir src : /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.Process_next.2571 : Thread-21 : [POST-PROCESSING][move] /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz ... to ... /mnt/shared2/mylar/Batman (2016)/Batman 070 (2019).cbz
12-May-2019 13:06:16 - DEBUG :: mylar.get_free_space.3643 : Thread-21 : [FREESPACE-CHECK] /mnt/shared2/mylar/Batman (2016) has 1.4TiB free
12-May-2019 13:06:19 - ERROR :: mylar.file_ops.3990 : Thread-21 : [MOVE] error : [Errno 1] Operation not permitted: '/mnt/shared2/mylar/Batman (2016)/Batman 070 (2019).cbz'
12-May-2019 13:06:19 - ERROR :: mylar.Process_next.2582 : Thread-21 : [POST-PROCESSING] Failed to move /opt/Mylar/cache/mylar_QWnJ5t/Batman 070 (2019) (Digital) (Zone-Empire).cbz:
12-May-2019 13:06:19 - ERROR :: mylar.Process_next.2583 : Thread-21 : [POST-PROCESSING] Post-Processing ABORTED.
12-May-2019 13:06:19 - INFO :: mylar.Process.1668 : Thread-21 : [POST-PROCESSING] Manual post-processing completed for 2 issues [FAILED: 2]
12-May-2019 13:06:19 - INFO :: mylar.run.2822 : Thread-21 : [FOLDER-CHECK] Finished checking for newly snatched downloads

Re: post processing issues

Posted: Mon May 13, 2019 4:20 pm
by evilhero
The error in those logs would indicate that it's having problems setting the permissions on that particular folder

Code: Select all

MOVE] error : [Errno 1] Operation not permitted: '/mnt/shared2/mylar/Batman (2016)/Batman 070 (2019).cbz'
The reason it's not updating the status is because it's failing during the move so it's assuming it's not a finished move, doesn't initiate a tidy-up process and thereby never changes the status to Downloaded. Does the user running Mylar have full access to the cache folder and/or the series directories where the comics are being moved to ?

So either the perms on your /mnt/shared2/mylar/ (or the subsequent series folders) aren't open enough for the mylar user to create/delete files, or it can't initiate a remove from the cache folder due to lack of permissions on the cache folder.

A move command from an OS perspective is literally just a copy and then a delete. So the fact that it's able to actually copy it into the series folder, but cannot delete the cache would point to some kind of permissions problem.

Re: post processing issues

Posted: Tue May 14, 2019 6:22 am
by ludwig
I thought it looked like permissions but I can't find any issues with those.

The destination (/mnt/shared2/mylar/) allows the mylar user full access and as mentioned, the file does get copied into the proper directory.

the cache directory itself is owned by the mylar user with full access.

the working directory (ie mylar_01mOwm) itself is 700, with the cbz it creates at 600. should be fine for what it needs to do.

Re: post processing issues

Posted: Wed May 22, 2019 11:54 am
by ludwig
any other thoughts? I've checked and rechecked permissions and can't find any issues with those.

(for a different reason) i moved my install to a new VM, as well as moving the data dir into the home folder of the user running mylar. still no luck.

I was wondering if it my be something related to python, or more specifically the version in use?

Re: post processing issues

Posted: Thu May 23, 2019 4:08 pm
by ludwig
for anyone else seeing this issue, it appears that there is an incompatibility of sorts with vboxsf and mv (at least in Ubuntu 18.04)

i had recently switched my mapping from cifs to vboxsf and it appears that this is when things broke.

I changed back to cifs and everything seems to be working again.

odd thing though, none of my other applications (sonarr, radarr, etc) had any issues with moving files when using vboxsf

Re: post processing issues

Posted: Sat Jun 08, 2019 4:14 pm
by atomikplayboy
So I am having the exact same problem but I'm running Mylar from the linuxserver Docker Container from within unRAID.

Mylar searches through NZBHydra2 on the same unRAID machine to locate the nzb file for the download, the nzb file gets sent over to SABnzbd (which sits on another machine on the network) which downloads the file to a shared temporary directory on a NAS drive (which isn't the unRAID server but is mounted in unRAID), SABnzbd then proceeds to process the file through the ComicRN.py script and ultimately fails with a Post-Processing ABORTED message.

But it's renaming and moving the file to where it should go on the same NAS in a different directory it just can't perform the clean-up afterwords as the original files are still in the downloads directory.

To complicate matters I'm new to linux, new to unRAID, new to Docker and new to Mylar so I'm trying to tread water here :D But I did get NZBHydra2, Organizrv2 and pihole all running so I'm not a total loss.

Code: Select all

2019-06-08 11:15:21	ERROR	[POST-PROCESSING] Post-Processing ABORTED
2019-06-08 11:15:21	ERROR	[POST-PROCESSING] Failed to move /config/mylar/cache/mylar_DvD61K/War Of The Realms - Uncanny X-Men 02 (of 03) (2019) (Oroboros-DCP).cbz:
2019-06-08 11:15:21	ERROR	[MOVE] error : [Errno 1] Operation not permitted: '/comics/War of the Realms Uncanny X-Men (2019)/War of the Realms Uncanny X-Men 002 (2019).cbz'
Any help in getting me on the right path would be greatly appreciated.

Re: post processing issues

Posted: Wed Jun 12, 2019 2:03 pm
by evilhero
@atomikplayboy:
The operation not permitted error would mean that there's a permissions problem somewhere along your path. If the files are being moved properly during post-processing, but failing during cleanup then it could be due to:
- the user running Mylar does not have full permissions in either the cache folder location (as it has to move the files into the cache folder, extract, then move that file into the series directory and then delete/cleanup anything thereafter).
- you're trying to enforce the permissions from within Mylar and it doesn't have the authority to perform a chown/chmod command and failing.
- alot of times permissions can be/are enforced from the mount point itself (when you do the mount command) - so it's also possible that you're mounting stuff within incorrect default permissions.
- you need to make sure that you have the 'SABnzbd/Mylar are on separate machines' option enabled if it's notl.
Would need to see a debug log (from the files, not the GUI) showing the post-processing (so from the start of the post-processing right up until the error).

You could also try to enable Completed Download Handling (CDH) within Mylar for SABnzbd, and see if that helps at all (note that you cannot have both ComicRN and CDH being used at the same time as it will create a race condition and one will fail with an error which would lock the other up - so disable your ComicRN if you are trying CDH).

Re: post processing issues

Posted: Sun Jun 30, 2019 2:40 am
by atomikplayboy
Took me a while to get back to Mylar because of reasons but I took a look at what you suggested and tried the easiest stuff first which for me was to change using the SABnzbd post processing to using the post processing in Mylar. This didn't fix the problem so I switched it back.

With that new found information I decided to take the SMB share out of the equation and created a share on the local unRAID server still using /comics as my starting point. With this I ended up with /mnt/user/comics/Comics and /mnt/user/comics/Downloads. I made the shares Public so that it would be easy to see them from my SABnzbd machine. I updated Mylar and SABnzbd to use the new folders... and it worked! I was able to find a comic, mark it for download, have SAB download, process it successfully and move it over to the Comics folder.

So there is definitely a SMB and / or Permissions issue. I'm not 100% convinced that it's not both causing problems because one minute I can create and mount an SMB share in unRAID with no problems and the next it's acting up, wont allow me to unmount the share or even see it across the network.

I don't know enough about Docker, Linux and unRAID yet to diagnose the permissions issue considering I thought that I had given full read and write permissions already but I'll get there. Thank you for your help.