post processing issues

Post any problems / bugs / issues that are Mylar-related in here.
Post Reply
ludwig
Posts: 48
Joined: Wed Oct 21, 2015 10:30 am

post processing issues

Post by ludwig » Sun May 12, 2019 11:41 am

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

User avatar
evilhero
Site Admin
Posts: 2369
Joined: Sat Apr 20, 2013 3:43 pm
Contact:

Re: post processing issues

Post by evilhero » Mon May 13, 2019 4:20 pm

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.

ludwig
Posts: 48
Joined: Wed Oct 21, 2015 10:30 am

Re: post processing issues

Post by ludwig » Tue May 14, 2019 6:22 am

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.

ludwig
Posts: 48
Joined: Wed Oct 21, 2015 10:30 am

Re: post processing issues

Post by ludwig » Wed May 22, 2019 11:54 am

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?

ludwig
Posts: 48
Joined: Wed Oct 21, 2015 10:30 am

Re: post processing issues

Post by ludwig » Thu May 23, 2019 4:08 pm

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

Post Reply