search

evilhero / mylar

An automated Comic Book downloader (cbr/cbz) for use with SABnzbd, NZBGet and torrents
GNU General Public License v3.0
977 stars 173 forks source link

Post-processing issue #1053

Closed skywayskase closed 9 years ago

skywayskase commented 9 years ago

So a couple of weeks ago I rebuilt my server and installed fresh versions of SABnzbd, Mylar, the clinton-hall scripts, and my other automatic downloaders. I'm running Window 7 64-bit, and the Development branch of mylar. I've set everything up the way it was on my last build (I even compared my old mylar config file to the new one line by line), but for some reason my post-processing script times out in Mylar (post-processing seems to work fine in both SickRage and Couch Potato). I've tried with both the clinton-hall scripts as well as the scripts that came with Mylar, and neither seem to work. The clinton hall script eventually times out with a 

exit(1) requests.exceptions.ReadTimeout: HTTPConnectionPool(host='localhost', port=8090): Read timed out. (read timeout=300)

message, and when i use the default Mylar script SABnzbd just says that the script is running until I eventually restart the computer (tried letting it run for several hours before), and when the computer comes back on the message just says "Ran ComicRN.py" and if I look at the script output, it's blank.

I just captured the following when Mylar grabbed the most recent issue of Spawn. This is using Clinton-Hall's script because I'm lazy and don't want to restart my computer..

From the Mylar Log:

09-Jun-2015 18:00:08 - INFO    :: Thread-18 : Successfully sent nzb file to SABnzbd
09-Jun-2015 18:00:08 - DEBUG   :: CP Server Thread-4 : Recieved API command: downloadNZB
09-Jun-2015 18:00:08 - DEBUG   :: Thread-18 : Found matching comic...preparing to send to Updater with IssueID: 489371 and nzbname: Spawn.252.2015.Digital-Empire[Spawn.252..2015...Digital-Empire.]
09-Jun-2015 18:00:08 - INFO    :: Thread-18 : setting the nzbid for this download grabbed by NZBGeek (newznab) in the nzblog to : 0ffe21cdc3a4ff6f5337f2193bfd894b
09-Jun-2015 18:00:08 - INFO    :: Thread-18 : setting the alternate nzbname for this download grabbed by NZBGeek (newznab) in the nzblog to : Spawn.252..2015...Digital-Empire.
09-Jun-2015 18:00:09 - INFO    :: Thread-18 : Sending Pushbullet notification
09-Jun-2015 18:00:09 - INFO    :: Thread-18 : [NOTIFIER] PushBullet notifications sent.
09-Jun-2015 18:00:09 - DEBUG   :: Thread-18 : findit = found!
09-Jun-2015 18:00:09 - INFO    :: Thread-18 : passing to updater.
09-Jun-2015 18:00:09 - DEBUG   :: Thread-18 : [UPDATER] comicid: 4937
09-Jun-2015 18:00:09 - DEBUG   :: Thread-18 : [UPDATER] issueid: 489371
09-Jun-2015 18:00:09 - INFO    :: Thread-18 : [UPDATER] Updating status to snatched
09-Jun-2015 18:00:09 - DEBUG   :: Thread-18 : [UPDATER] Provider is newznab
09-Jun-2015 18:00:09 - INFO    :: Thread-18 : [UPDATER] Updated the status (Snatched) complete for Spawn Issue: 252
09-Jun-2015 18:00:33 - WARNING :: CP Server Thread-3 : ComicRN should be v1.01 and autoProcessComics.py should be v1.0, but they are not and are out of date. Post-Processing may or may not work.
09-Jun-2015 18:00:33 - INFO    :: CP Server Thread-3 : Starting postprocessing for : Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [POST-PROCESSING] nzb name: Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [POST-PROCESSING] nzb folder: D:\Downloads\To Sort\Comics\Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [POST-PROCESSING] SABnzbd Download folder option enabled. Directory set to : D:\Downloads\To Sort\Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [NZBNAME]: Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [NZBNAME] nzbname (remove chars): Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [NZBNAME] nzbname (remove extensions, double spaces, convert underscores to spaces): Spawn 252 2015 Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [POST-PROCESSING] After conversions, nzbname is : Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - DEBUG   :: Post-Processing : [POST-PROCESSING] Issueid: 489371
09-Jun-2015 18:00:33 - INFO    :: Post-Processing : [POST-PROCESSING] issuenzb found.
09-Jun-2015 18:00:33 - INFO    :: Post-Processing : [DUPECHECK] Duplicate check for D:\Downloads\To Sort\Spawn.252.2015.Digital-Empire
09-Jun-2015 18:00:33 - ERROR   :: Post-Processing : Uncaught exception: Traceback (most recent call last):
  File "C:\Program Files (x86)\mylar\mylar\logger.py", line 159, in new_run
    old_run(*args, **kwargs)
  File "C:\Python27\lib\threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
  File "C:\Program Files (x86)\mylar\mylar\PostProcessor.py", line 877, in Process
    dupthis = helpers.duplicate_filecheck(self.nzb_folder, ComicID=comicid, IssueID=issueid)
  File "C:\Program Files (x86)\mylar\mylar\helpers.py", line 1577, in duplicate_filecheck
    filesz = os.path.getsize(filename)
  File "C:\Python27\lib\genericpath.py", line 49, in getsize
    return os.stat(filename).st_size
WindowsError: [Error 2] The system cannot find the file specified: 'D:\\Downloads\\To Sort\\Spawn.252.2015.Digital-Empire'

From the SABnzbd log:

2015-06-09 18:00:08,971::INFO::[__init__:513] Fetching http://127.0.0.1:8090/mylar/api?apikey=53d3c283103b3cca8fef5c06e5b22deb&cmd=downloadNZB&nzbname=Spawn.252.2015.Digital-Empire.nzb
2015-06-09 18:00:08,974::INFO::[nzbqueue:218] Saving queue
2015-06-09 18:00:08,976::INFO::[__init__:919] Saving data for queue9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\queue9.sab
2015-06-09 18:00:08,976::INFO::[urlgrabber:116] Grabbing URL http://127.0.0.1:8090/mylar/api?apikey=53d3c283103b3cca8fef5c06e5b22deb&cmd=downloadNZB&nzbname=Spawn.252.2015.Digital-Empire.nzb
2015-06-09 18:00:08,990::INFO::[misc:811] Creating directories: D:\Downloads\To Sort\incomplete\Spawn.252.2015.Digital-Empire
2015-06-09 18:00:08,993::INFO::[nzbstuff:444] File 0-Day 2015.5.20 - "Spawn 252 (2015) (Digital-Empire).cbr" yEnc (1/59) added to queue
2015-06-09 18:00:08,993::INFO::[__init__:584] Backing up D:\Downloads\To Sort\incomplete\Spawn.252.2015.Digital-Empire\__ADMIN__\Spawn.252.2015.Digital-Empire.nzb.gz
2015-06-09 18:00:16,471::INFO::[nzbqueue:218] Saving queue
2015-06-09 18:00:16,476::INFO::[__init__:919] Saving data for queue9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\queue9.sab
2015-06-09 18:00:16,479::INFO::[__init__:908] C:\Users\Skylar\AppData\Local\sabnzbd\admin\future\SABnzbd_nzo_3nlfzc removed
2015-06-09 18:00:16,480::INFO::[nzbqueue:218] Saving queue
2015-06-09 18:00:16,480::INFO::[__init__:919] Saving data for queue9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\queue9.sab
2015-06-09 18:00:17,480::INFO::[downloader:381] 24@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:18,668::INFO::[downloader:577] Connecting 24@news.newshosting.com:563 finished
2015-06-09 18:00:21,298::INFO::[downloader:381] 1@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,299::INFO::[downloader:381] 18@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,301::INFO::[downloader:381] 8@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,302::INFO::[downloader:381] 2@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,302::INFO::[downloader:381] 20@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,305::INFO::[downloader:381] 13@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,308::INFO::[downloader:381] 6@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,309::INFO::[downloader:381] 5@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,309::INFO::[downloader:381] 10@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,311::INFO::[downloader:381] 12@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,312::INFO::[downloader:381] 7@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,312::INFO::[downloader:381] 4@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,313::INFO::[downloader:381] 21@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,315::INFO::[downloader:381] 11@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,315::INFO::[downloader:381] 9@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,316::INFO::[downloader:381] 22@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,318::INFO::[downloader:381] 25@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,319::INFO::[downloader:381] 3@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,319::INFO::[downloader:381] 16@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,321::INFO::[downloader:381] 15@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,322::INFO::[downloader:381] 17@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,323::INFO::[downloader:381] 14@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,325::INFO::[downloader:381] 23@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:21,325::INFO::[downloader:381] 19@news.newshosting.com:563: Initiating connection
2015-06-09 18:00:22,634::INFO::[downloader:577] Connecting 1@news.newshosting.com:563 finished
2015-06-09 18:00:22,641::INFO::[downloader:577] Connecting 10@news.newshosting.com:563 finished
2015-06-09 18:00:22,641::INFO::[downloader:577] Connecting 22@news.newshosting.com:563 finished
2015-06-09 18:00:22,641::INFO::[downloader:577] Connecting 16@news.newshosting.com:563 finished
2015-06-09 18:00:22,642::INFO::[downloader:577] Connecting 19@news.newshosting.com:563 finished
2015-06-09 18:00:22,644::INFO::[downloader:577] Connecting 5@news.newshosting.com:563 finished
2015-06-09 18:00:22,644::INFO::[downloader:577] Connecting 17@news.newshosting.com:563 finished
2015-06-09 18:00:22,644::INFO::[downloader:577] Connecting 6@news.newshosting.com:563 finished
2015-06-09 18:00:22,644::INFO::[downloader:577] Connecting 25@news.newshosting.com:563 finished
2015-06-09 18:00:22,645::INFO::[downloader:577] Connecting 21@news.newshosting.com:563 finished
2015-06-09 18:00:22,647::INFO::[downloader:577] Connecting 13@news.newshosting.com:563 finished
2015-06-09 18:00:22,647::INFO::[downloader:577] Connecting 9@news.newshosting.com:563 finished
2015-06-09 18:00:22,648::INFO::[downloader:577] Connecting 2@news.newshosting.com:563 finished
2015-06-09 18:00:22,648::INFO::[downloader:577] Connecting 8@news.newshosting.com:563 finished
2015-06-09 18:00:22,648::INFO::[downloader:577] Connecting 23@news.newshosting.com:563 finished
2015-06-09 18:00:22,650::INFO::[downloader:577] Connecting 3@news.newshosting.com:563 finished
2015-06-09 18:00:22,651::INFO::[downloader:577] Connecting 20@news.newshosting.com:563 finished
2015-06-09 18:00:22,651::INFO::[downloader:577] Connecting 4@news.newshosting.com:563 finished
2015-06-09 18:00:22,651::INFO::[downloader:577] Connecting 7@news.newshosting.com:563 finished
2015-06-09 18:00:22,653::INFO::[downloader:577] Connecting 14@news.newshosting.com:563 finished
2015-06-09 18:00:22,653::INFO::[downloader:577] Connecting 12@news.newshosting.com:563 finished
2015-06-09 18:00:22,654::INFO::[downloader:577] Connecting 15@news.newshosting.com:563 finished
2015-06-09 18:00:22,654::INFO::[downloader:577] Connecting 11@news.newshosting.com:563 finished
2015-06-09 18:00:22,654::INFO::[downloader:577] Connecting 18@news.newshosting.com:563 finished
2015-06-09 18:00:30,523::INFO::[__init__:919] Saving data for totals9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\totals9.sab
2015-06-09 18:00:30,525::INFO::[assembler:89] Decoding D:\Downloads\To Sort\incomplete\Spawn.252.2015.Digital-Empire\Spawn 252 (2015) (Digital-Empire).cbr yenc
2015-06-09 18:00:30,647::INFO::[__init__:908] D:\Downloads\To Sort\incomplete\Spawn.252.2015.Digital-Empire\__ADMIN__\SABnzbd_nzo_xgd54p removed
2015-06-09 18:00:30,648::INFO::[nzbqueue:218] Saving queue
2015-06-09 18:00:30,648::INFO::[__init__:919] Saving data for queue9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\queue9.sab
2015-06-09 18:00:30,648::INFO::[postproc:85] Saving postproc queue
2015-06-09 18:00:30,648::INFO::[__init__:919] Saving data for postproc1.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\postproc1.sab
2015-06-09 18:00:30,648::INFO::[postproc:284] Starting PostProcessing on Spawn.252.2015.Digital-Empire => Repair:True, Unpack:True, Delete:True, Script:ComicRN.py, Cat:comics
2015-06-09 18:00:30,648::INFO::[postproc:574] Par2 check starting on Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,651::INFO::[__init__:874] D:\Downloads\To Sort\incomplete\Spawn.252.2015.Digital-Empire\__ADMIN__\__verified__ missing
2015-06-09 18:00:30,651::INFO::[postproc:607] No par2 sets for Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,651::INFO::[postproc:622] Par2 check finished on Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,651::INFO::[misc:811] Creating directories: D:\Downloads\To Sort\Comics\Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,653::INFO::[postproc:351] Running unpack_magic on Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,653::INFO::[postproc:353] unpack_magic finished on Spawn.252.2015.Digital-Empire
2015-06-09 18:00:30,655::INFO::[newsunpack:150] Running external script C:\Program Files (x86)\SABnzbd\Scripts\nzbToMedia\ComicRN.py(D:\Downloads\To Sort\Comics\Spawn.252.2015.Digital-Empire, Spawn.252.2015.Digital-Empire.nzb, Spawn.252.2015.Digital-Empire, , comics, alt.binaries.comics.dcp, 0, )
2015-06-09 18:00:31,517::INFO::[downloader:667] Thread 11@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:31,618::INFO::[downloader:667] Thread 25@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:31,717::INFO::[downloader:667] Thread 10@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:31,818::INFO::[downloader:667] Thread 21@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:31,917::INFO::[downloader:667] Thread 13@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,019::INFO::[downloader:667] Thread 14@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,118::INFO::[downloader:667] Thread 24@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,219::INFO::[downloader:667] Thread 5@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,319::INFO::[downloader:667] Thread 22@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,418::INFO::[downloader:667] Thread 2@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,519::INFO::[downloader:667] Thread 1@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,618::INFO::[downloader:667] Thread 19@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,719::INFO::[downloader:667] Thread 3@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,819::INFO::[downloader:667] Thread 8@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:32,918::INFO::[downloader:667] Thread 7@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,019::INFO::[downloader:667] Thread 12@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,118::INFO::[downloader:667] Thread 6@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,219::INFO::[downloader:667] Thread 16@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,319::INFO::[downloader:667] Thread 4@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,418::INFO::[downloader:667] Thread 18@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,519::INFO::[downloader:667] Thread 23@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,618::INFO::[downloader:667] Thread 20@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,720::INFO::[downloader:667] Thread 15@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,821::INFO::[downloader:667] Thread 17@news.newshosting.com:563: forcing disconnect
2015-06-09 18:00:33,921::INFO::[downloader:667] Thread 9@news.newshosting.com:563: forcing disconnect
2015-06-09 18:05:33,944::INFO::[postproc:543] Cleaning up Spawn.252.2015.Digital-Empire (keep_basic=False)
2015-06-09 18:05:33,946::INFO::[postproc:85] Saving postproc queue
2015-06-09 18:05:33,946::INFO::[__init__:919] Saving data for postproc1.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\postproc1.sab
2015-06-09 18:05:33,947::INFO::[downloader:246] Post-processing finished, resuming download
2015-06-09 18:05:34,947::INFO::[nzbqueue:218] Saving queue
2015-06-09 18:05:34,947::INFO::[__init__:919] Saving data for queue9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\queue9.sab
2015-06-09 18:05:34,948::INFO::[__init__:919] Saving data for totals9.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\totals9.sab
2015-06-09 18:05:34,950::INFO::[__init__:919] Saving data for rss_data.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\rss_data.sab
2015-06-09 18:05:34,951::INFO::[__init__:919] Saving data for bookmarks.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\bookmarks.sab
2015-06-09 18:05:34,953::INFO::[__init__:919] Saving data for watched_data.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\watched_data.sab
2015-06-09 18:05:34,953::INFO::[postproc:85] Saving postproc queue
2015-06-09 18:05:34,954::INFO::[__init__:919] Saving data for postproc1.sab in C:\Users\Skylar\AppData\Local\sabnzbd\admin\postproc1.sab
2015-06-09 18:05:34,956::INFO::[postproc:677] Queue has finished, launching: None (None)

I can run this test again using the default script if you'd prefer.

Any help or thoughts would be super appreciated! :)

I've also opened an issue in Clinton-Halls github page: clinton-hall/nzbToMedia#767

skywayskase commented 9 years ago

It looks like DUPECHECK is looking in the parent directory of where it should be.. and then explodes.

skywayskase commented 9 years ago

I fixed it! After posting the logs you requested and noticing that it seemed to be an issue with DUPECHECK, I searched for other reported issues with DUPECHECK and found #934. While that field (download directory) has been removed from the Mylar config UI in the most recent commit, I found it in the config file and it was pointing to the parent directory for uncategorized downloads instead of the comics folder. I fixed it, restarted Mylar and tested with a new issue and the script ran just fine.