clinton-hall / nzbToMedia

Provides NZB and Torrent postprocessing To CouchPotatoServer, SickBeard/SickRage, HeadPhones, Mylar and Gamez
GNU General Public License v3.0
671 stars 176 forks source link

Mylar #410

Closed vergessen closed 10 years ago

vergessen commented 10 years ago

nzbToMylar: [07:44:02] [ERROR]::MYLAR: Could not find a status for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire).nzb, is it in the wanted list ?

This is running on the dev branch with the most current version of NZBGET(build 1032)

clinton-hall commented 10 years ago

And is Dexter.Down.Under.01.(of.5) in the wanted list?

I'll need to do some debugging for this... looks like the history search may be broken.

Can you post the full postprocess log for this please?

vergessen commented 10 years ago

sure please see below. It is in the wanted list. I am also running the most recent dev version of mylar.

INFO Fri May 30 2014 07:54:58 Collection Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) added to history ERROR Fri May 30 2014 07:54:58 Post-process-script media/nzbToMylar.py for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) failed INFO Fri May 30 2014 07:54:58 nzbToMylar: [07:54:58] [ERROR]::MAIN: A problem was reported in the /home/vergessen/.nzbget/ppscripts/media/nzbToMylar.py script. INFO Fri May 30 2014 07:54:58 nzbToMylar: [07:54:58] [ERROR]::MYLAR: Could not find a status for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire).nzb, is it in the wanted list ? INFO Fri May 30 2014 07:54:58 nzbToMylar: [07:54:58] [INFO]::MAIN: Calling Mylar:comics to post-process:Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire).nzb INFO Fri May 30 2014 07:54:58 nzbToMylar: [07:54:58] [INFO]::MAIN: Auto-detected SECTION:Mylar INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: Script triggered from NZBGet Version 13.0-testing-r1032M. INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: ######################################################### INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: ## ..::[nzbToMedia.pyc]::.. ## INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: ######################################################### INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: nzbToMedia Version:b1d7847c205bb8e339edb9e7017bf782cae357d7 Branch:dev (Linux 3.14-1-amd64) INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: No update needed INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: Checking if git needs an update INFO Fri May 30 2014 07:54:57 nzbToMylar: [07:54:57] [INFO]::MAIN: Checking database structure... INFO Fri May 30 2014 07:54:57 Executing post-process-script media/nzbToMylar.py for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:57 Move for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) successful INFO Fri May 30 2014 07:54:57 Moving file Dexter Down Under 01 (of 5) (2014) (Digital) (Zone-Empire).cbr to /home/vergessen/Downloads/dst/comics/Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:57 Moving completed files for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:56 Nothing to unpack for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:56 No renamed files found for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:56 Checking renamed files for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) INFO Fri May 30 2014 07:54:56 Queueing Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) for post-processing INFO Fri May 30 2014 07:54:56 Collection Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire) completely downloaded INFO Fri May 30 2014 07:54:56 Successfully downloaded Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire)/Dexter Down Under 01 (of 5) (2014) (Digital) (Zone-Empire).cbr DETAIL Fri May 30 2014 07:54:56 Checking articles for Dexter.Down.Under.01.(of.5).(2014).(Digital).(Zone-Empire)/Dexter Down Under 01 (of 5) (2014) (Digital) (Zone-Empire).cbr

vergessen commented 10 years ago

Just a little more information, it looks like the API key is always blank even though it is in the config and I dropped print lines to see if I could see what is happening it looks like get_status is never firing on my tests.

clinton-hall commented 10 years ago

in autoProcessMedia.cfg [General] can you enable debug logging? That should provide more information as to what is going on.

vergessen commented 10 years ago

http://pastie.org/private/uhvrjirxld7davc2wwfywq log with apikey missing http://pastie.org/private/opdqou5owvjriftuoug5w log with apikey forced into the .cfg file.

Clinton please see above. I was messing with this on the train, notice that even though in the nzbget settings there is no api key being passed, if I add one to the .cfg file it will pick it up which is fine but I don't think mylar works the way you want it to

{"Status": "Snatched", "ComicName": "Wolverine", "IssueID": "452859", "FolderName": null, "Issue_Number": "6", "ComicID": "71431", "Provider": "experimental", "Size": null, "DateAdded": "2014-05-30 07:48:16"}

is the return from the mylar api, the script checks against foldername, this is always null, every single foldername in the mylar json null

clinton-hall commented 10 years ago

ok... in nightly branch I have fixed the mylay api key so that this can be set from within nzbget.

As for the FolderName... this puzzles me., Why would mylar always return a "null" entry? I suspect you have some configuration with mylar that hadn't been anticipated when using this to match releases/downloads.

I'll need to do some further tests to find a better way to handle this

clinton-hall commented 10 years ago

Any chance you can confirm the full output of the getWanted api command?

I am thinking of doing this the same was as I do HeadPhones. I check the number of wanted releases before and after; if it has changed, then processing is done.

If this is too much to post here, just put it into a text file and email to me.

vergessen commented 10 years ago

Get wanted will probably not be the way in this case. I am using the avengers to test in this case first right after selecting it as wanted:

[{"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "442920", "AltIssueNumber": null, "IssueDate": "2014-03-31", "inCacheDIR": null, "ReleaseDate": "2014-01-22", "ArtworkURL": null, "Issue_Number": "1", "Location": null, "Int_IssueNumber": 1000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "446481", "AltIssueNumber": null, "IssueDate": "2014-04-01", "inCacheDIR": null, "ReleaseDate": "2014-02-26", "ArtworkURL": null, "Issue_Number": "2", "Location": null, "Int_IssueNumber": 2000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "448966", "AltIssueNumber": null, "IssueDate": "2014-05-01", "inCacheDIR": null, "ReleaseDate": "2014-03-26", "ArtworkURL": null, "Issue_Number": "3", "Location": null, "Int_IssueNumber": 3000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "451084", "AltIssueNumber": null, "IssueDate": "2014-06-30", "inCacheDIR": null, "ReleaseDate": "2014-04-23", "ArtworkURL": null, "Issue_Number": "4", "Location": null, "Int_IssueNumber": 4000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "444437", "AltIssueNumber": null, "IssueDate": "2014-04-30", "inCacheDIR": null, "ReleaseDate": "2014-02-05", "ArtworkURL": null, "Issue_Number": "1", "Location": null, "Int_IssueNumber": 1000, "IssueName": "rogue logan part 1 of 4", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "446493", "AltIssueNumber": null, "IssueDate": "2014-04-30", "inCacheDIR": null, "ReleaseDate": "2014-02-26", "ArtworkURL": null, "Issue_Number": "2", "Location": null, "Int_IssueNumber": 2000, "IssueName": "rogue logan part 2 of 4: bad advice", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "447517", "AltIssueNumber": null, "IssueDate": "2014-05-31", "inCacheDIR": null, "ReleaseDate": "2014-03-12", "ArtworkURL": null, "Issue_Number": "3", "Location": null, "Int_IssueNumber": 3000, "IssueName": "rogue logan part 3 of 4", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Avengers", "IssueID": "445176", "AltIssueNumber": null, "IssueDate": "2014-04-01", "inCacheDIR": null, "ReleaseDate": "2014-02-12", "ArtworkURL": null, "Issue_Number": "26", "Location": null, "Int_IssueNumber": 26000, "IssueName": "look around... there's no way out", "ComicID": "54428", "Type": null, "DateAdded": "2014-05-31"}]

Then right after snatch but while the download was paused in nzbget. It is all ready missing, mylar removed it on snatch(i guess it isn't wanted at this point)

[{"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "442920", "AltIssueNumber": null, "IssueDate": "2014-03-31", "inCacheDIR": null, "ReleaseDate": "2014-01-22", "ArtworkURL": null, "Issue_Number": "1", "Location": null, "Int_IssueNumber": 1000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "446481", "AltIssueNumber": null, "IssueDate": "2014-04-01", "inCacheDIR": null, "ReleaseDate": "2014-02-26", "ArtworkURL": null, "Issue_Number": "2", "Location": null, "Int_IssueNumber": 2000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "448966", "AltIssueNumber": null, "IssueDate": "2014-05-01", "inCacheDIR": null, "ReleaseDate": "2014-03-26", "ArtworkURL": null, "Issue_Number": "3", "Location": null, "Int_IssueNumber": 3000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "George Romero's Empire of the Dead: Act One", "IssueID": "451084", "AltIssueNumber": null, "IssueDate": "2014-06-30", "inCacheDIR": null, "ReleaseDate": "2014-04-23", "ArtworkURL": null, "Issue_Number": "4", "Location": null, "Int_IssueNumber": 4000, "IssueName": "none", "ComicID": "71065", "Type": null, "DateAdded": null}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "444437", "AltIssueNumber": null, "IssueDate": "2014-04-30", "inCacheDIR": null, "ReleaseDate": "2014-02-05", "ArtworkURL": null, "Issue_Number": "1", "Location": null, "Int_IssueNumber": 1000, "IssueName": "rogue logan part 1 of 4", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "446493", "AltIssueNumber": null, "IssueDate": "2014-04-30", "inCacheDIR": null, "ReleaseDate": "2014-02-26", "ArtworkURL": null, "Issue_Number": "2", "Location": null, "Int_IssueNumber": 2000, "IssueName": "rogue logan part 2 of 4: bad advice", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}, {"Status": "Wanted", "ComicSize": null, "ComicName": "Wolverine", "IssueID": "447517", "AltIssueNumber": null, "IssueDate": "2014-05-31", "inCacheDIR": null, "ReleaseDate": "2014-03-12", "ArtworkURL": null, "Issue_Number": "3", "Location": null, "Int_IssueNumber": 3000, "IssueName": "rogue logan part 3 of 4", "ComicID": "71431", "Type": null, "DateAdded": "2014-05-30"}]

clinton-hall commented 10 years ago

Yeah, that makes sense...

So, with the get history, does that show currently snatched releases? I.e does the size of this change after a download has been renamed/processed?

Or is it a completed history of everything that has been snatched?

vergessen commented 10 years ago

Beat me to it. So i was testing that

in the gethistory api below is when it is snatched and sent to the downloader

[{"Status": "Snatched", "ComicName": "Avengers", "IssueID": "442913", "FolderName": null, "Issue_Number": "25", "ComicID": "54428", "Provider": "dognzb", "Size": null, "DateAdded": "2014-05-31 16:42:52"}

when it is complete and post processed. You get a new line, stating it is downloaded. You might be able to key of time(more of pain on remote systems and so on) or just counting the results but if it is out there searching and there is a slow machine handling post processing you could end up with races where it snatches a new comic, but fails the post process and it is marked ok by the script because the value matched as expected. He doesn't leave a clean way to check up on it.

[{"Status": "Downloaded", "ComicName": "Avengers", "IssueID": "442913", "FolderName": null, "Issue_Number": "25", "ComicID": "54428", "Provider": null, "Size": null, "DateAdded": "2014-05-31 16:43:05"}, {"Status": "Snatched", "ComicName": "Avengers", "IssueID": "442913", "FolderName": null, "Issue_Number": "25", "ComicID": "54428", "Provider": "dognzb", "Size": null, "DateAdded": "2014-05-31 16:42:52"}

clinton-hall commented 10 years ago

Thanks for that. The documentation suggested history only returned snatched releases and not downloaded....

I can do something with this... Basically cache all snatched releases (eliminate any that also have a downloaded release) and then after processing, do the same.

If a snatched release existed before renaming, and not after, then we know it was marked as downloaded....

I might also limit this to only process the last 20 history items....

vergessen commented 10 years ago

while I can see where you are going wouldn't just be easier to call post_process?nzb_name=name&nzb_folder=folder

read the output for Post Processing SUCCESSFULL!

i was playing with master and I noticed it worked fine(how i got the results to work above) but it relies on a timeout, this would remove that need.

clinton-hall commented 10 years ago

The question here is, does that "Successful" mean the processing was successful, or the process command was received and understood?

Basically, if the command is received and it returns successful, but then there is an error that prevents processing, we run in to trouble when the script tries to cleanup the directories etc...

clinton-hall commented 10 years ago

If Successful means the episode was processed, then indeed this is very easy.

vergessen commented 10 years ago

It means it was processed.on error or fail it looks like you get nothing back from the call. As for clean up it looks like the post process call is trying to do that. see the tail from a successful call

Rename Files isn't enabled...keeping original filename. New Filename: Deadpool 027 (2014) (Digital) (Nahga-Empire) Source:/home/betrayed/Downloads/dst/comics/Deadpool.027.2014.Digital.Nahga-EMPIRE/Deadpool 027 (2014) (Digital) (Nahga-Empire).cbr Destination:/home/betrayed/entertainment/comics/Deadpool (2013)/Deadpool 027 (2014) (Digital) (Nahga-Empire).cbr Removed temporary directory : /home/betrayed/Downloads/dst/comics/Deadpool.027.2014.Digital.Nahga-EMPIRE Post Processing SUCCESSFULL!

clinton-hall commented 10 years ago

Excellent. Thanks for all the investigation....

I'll push an update soon.

clinton-hall commented 10 years ago

are you able to test this on nightly branch?

This should send to Mylar for processing. Hopefully you can confirm that the script correctly interprets successful processing.

vergessen commented 10 years ago

I switched to nightly and got this result. I'm working mobile right now so I couldn't look further

Post-process-script media/nzbToMylar.py for Saga.018.2014.Digital.Zone-EMPIRE failed (terminated with unknown status) INFO Sat May 31 2014 23:18:30 nzbToMylar: ValueError: invalid literal for int() with base 10: '' INFO Sat May 31 2014 23:18:30 nzbToMylar: if int(section[inputCategory]['remote_path']) and not nzbtomedia.REMOTEPATHS: INFO Sat May 31 2014 23:18:30 nzbToMylar: File "/home/betrayed/code/nzbToMedia/nzbToMedia.py", line 398, in process INFO Sat May 31 2014 23:18:30 nzbToMylar: clientAgent=clientAgent, download_id=download_id, inputCategory=os.environ['NZBPP_CATEGORY']) INFO Sat May 31 2014 23:18:30 nzbToMylar: File "/home/betrayed/code/nzbToMedia/nzbToMedia.py", line 502, in main INFO Sat May 31 2014 23:18:30 nzbToMylar: result = nzbToMedia.main(sys.argv, section) INFO Sat May 31 2014 23:18:30 nzbToMylar: File "/home/betrayed/.nzbget/ppscripts/media/nzbToMylar.py", line 99, in INFO Sat May 31 2014 23:18:30 nzbToMylar: Traceback (most recent call last):

clinton-hall commented 10 years ago

Ah, sorry.

I had already started something on nightly branch. Basically, the way remote paths is handled has now changed. So in autoProcessMedia.cfg, for all sections (I.e SickBeard, CouchPotato, Mylar, Gamez, HeadPhones, NZBDrone) the remote_path should be 0 for disabled, and 1 if enabled (this also requires the local and remote paths to be entered in the Network section, Mount_Points).

I thought I had set a migration for this, but something must not have worked.

clinton-hall commented 10 years ago

For nzbget, please make sure you change this value to either 0 or 1, then save changes and restart.... The nzbget migration occurs after the. Settings migration, so if nzbget is passing the old parameter, this will break things.

clinton-hall commented 10 years ago

any luck re-processing this one?

Same code is in nightly, dev, and master now (I have tested that it is stable, even if Mylar status checking hasn't been verified...

note. if you use the auto-update feature, please be sure you set the branch in autoProcessMedia.cfg

[General]
    git_branch = dev
vergessen commented 10 years ago

As written it will not work, the api call force process will only return OK

It will work as url = protocol + host + ":" + port + web_root + "/post_process?" + urllib.urlencode(params)

here is in an example of how old my master is https://github.com/clinton-hall/nzbToMedia/blob/8e7490ff80fd054973eefa921f4bb9d9cf0eb172/nzbtomedia/autoProcess/autoProcessComics.py

clinton-hall commented 10 years ago

I'm lost now... the old way used the post_process web web post, but not the api call. Are you saying the web post provides absolute confirmation of process Success, but the api does not?

If so, this should be an easy enough fix to change back to the older version, but add in the result check...

vergessen commented 10 years ago

That's right the api is useless. It only returns OK so it always fails. The post process web post will return the page you can parse to confirm if it completed correctly

clinton-hall commented 10 years ago

Thanks again, I'll try to post a fix soon.

clinton-hall commented 10 years ago

In theory this should call the postprocess with the download name and directory... it then checks for the "postproces SUCCESSFUL" output.

You will need to re-enter your username and password in NZBGet settings. I believe this still gets applied.

Please let me know if this is working, or otherwise what the mode of failure now is...

This is in all 3 branches (nightly, dev, master)

vergessen commented 10 years ago

It is working on the Dev branch with two changes

        if "Post Processing SUCCESSFUL!" in line: success = True

One L and it seems to want the ! and params['nzb_name'] = inputName[0:-4]

the ext seems to throw it off. I cut it here but I think there is an option from nzbget that supplies it that way.

If you want I can for it and submit changes that way. I'll leave it up to you.

clinton-hall commented 10 years ago

yeah... a PR would be great

Just not sure about dropping the last 4 characters.... is it always going to be 4? what if there was no extension etc? Should we do an os.splitext(inputName)[0]

vergessen commented 10 years ago

No problem I'll do it tonight. I'll probably skip stripping and use NZBPP_NZBNAME instead of NZBPP_NZBFILENAME.

clinton-hall commented 10 years ago

Ah... brilliant...

Really appreciate it... obviously after all my attempts to have this ready to merge to master when CP merged, it turned out I had a few uncaught bugs and now I'm scrambling to get it fixed, when in fact I have very little time to look into it.

Just one thing here... for that environemnt variable will give the clean name from NZBGet, but we also need to look for the clean name from SABnzbd and then there is the torrent stuff...

clinton-hall commented 10 years ago

I just did this... see if that is going to work... It is not actually as neat, but it should catch any 3 character extension and strip it...

clinton-hall commented 10 years ago

I only pushed this to nightly for now...

vergessen commented 10 years ago

I will test on sab and nzbget. I'll look at torrents and see if I can knock something out for that test too

clinton-hall commented 10 years ago

merged your PR... can you please close this if you have confirmed it to be working?

vergessen commented 10 years ago

pulled latest nightly, works as expected, closing