From 2f353ccee3a4d37e64af8437128464acbc058253 Mon Sep 17 00:00:00 2001 From: Clinton Hall Date: Sat, 16 Feb 2013 16:25:03 -0800 Subject: [PATCH] added logging --- TorrentToMedia.py | 124 ++++++++++++++++++++++++++-------------------- 1 file changed, 70 insertions(+), 54 deletions(-) diff --git a/TorrentToMedia.py b/TorrentToMedia.py index b7e7009f..7bc494f4 100755 --- a/TorrentToMedia.py +++ b/TorrentToMedia.py @@ -3,10 +3,19 @@ import autoProcessMovie import autoProcessTV import sys, os, ConfigParser, shutil +import logging, logging.config from subprocess import call from nzbToMediaEnv import * +Logger = logging.getLogger() +logFile = os.path.join(os.path.dirname(sys.argv[0]), "postprocess.log") +logging.config.fileConfig(os.path.join(os.path.dirname(sys.argv[0]), "nzbToMediaEnv.py")) +fileHandler = logging.FileHandler(logFile, encoding='utf-8', delay=True) +fileHandler.formatter = logging.Formatter('%(asctime)s|%(levelname)-7.7s %(message)s', '%H:%M:%S') +fileHandler.level = logging.DEBUG +Logger.addHandler(fileHandler) + def removeEmptyFolders(path): if not os.path.isdir(path): return @@ -22,13 +31,15 @@ def removeEmptyFolders(path): # if folder empty, delete it files = os.listdir(path) if len(files) == 0: - print "INFO: Removing empty folder: %s" % (path) + Logger.info("Removing empty folder: %s", path) os.rmdir(path) -old_stdout = sys.stdout #backup the default stdout -log_file = open(os.path.join(os.path.dirname(sys.argv[0]), "postprocess.log"),"a+") -sys.stdout = log_file #create a local log file, and direct all "print" to the log. -print "INFO: TorrentToMedia %s" % VERSION + + +#old_stdout = sys.stdout #backup the default stdout +#log_file = open(os.path.join(os.path.dirname(sys.argv[0]), "postprocess.log"),"a+") +#sys.stdout = log_file #create a local log file, and direct all "print" to the log. +Logger.info("TorrentToMedia %s", VERSION) if len(sys.argv) == 4: ##You can use the following parameters (UTORRENT): ## @@ -60,13 +71,13 @@ if len(sys.argv) == 4: ##Stopped - 13 ## We will pass in %D, %N, %L from uTorrent - print "INFO: Script called from utorrent" + Logger.info("Script called from utorrent") Directory = sys.argv[1] ## %D -- Example output: F:\path\to\dir\My.Series.S01E01.720p.HDTV.x264-2HD Name = sys.argv[2] ## %N -- Example output: My.Series.S01E01.720p.HDTV.x264-2HD Category = sys.argv[3] ## %L -- Example output: tvseries ## This is the label in uTorrent elif len(sys.argv) > 1: #Doesn't match Transmission (1) or uTorrent (4). - print "Error: The number of arguments passed is %s. Unable to determin the arguments to use; Exiting" % (len(sys.argv)) + Logger.error("The number of arguments passed is %s. Unable to determin the arguments to use; Exiting", len(sys.argv)) sys.exit(-1) else: @@ -80,15 +91,15 @@ else: try: Directory = os.getenv('TR_TORRENT_DIR') Name = os.getenv('TR_TORRENT_NAME') - print "INFO: Script called from Transmission" + Logger.info("Script called from Transmission") except: - print "Error: There was a problem loading variables from Transmission", "Exiting" + Logger.error("There was a problem loading variables from Transmission: Exiting") sys.exit(-1) Category = '' #We dont have a category, so assume the last directory is the category for now. -print "DEBUG: Received Directory: %s" % (Directory) -print "DEBUG: Received Torrent Name: %s" % (Name) -print "DEBUG: Received Category: %s" % (Category) +Logger.debug("Received Directory: %s", Directory) +Logger.debug("Received Torrent Name: %s", Name) +Logger.debug("Received Category: %s", Category) status = 0 packed = 0 @@ -98,10 +109,10 @@ video = 0 config = ConfigParser.ConfigParser() configFilename = os.path.join(os.path.dirname(sys.argv[0]), "autoProcessMedia.cfg") -print "INFO: Loading config from %s" % (configFilename) +Logger.info("Loading config from %s", configFilename) if not os.path.isfile(configFilename): - print "ERROR: You need an autoProcessMedia.cfg file - did you rename and edit the .sample?" + Logger.error("You need an autoProcessMedia.cfg file - did you rename and edit the .sample?") sys.exit(-1) config.read(configFilename) @@ -115,30 +126,30 @@ extractionTool = config.get("Torrent", "extractiontool") DirBase = os.path.split(os.path.normpath(Directory)) #Test for blackhole sub-directory. if DirBase[1] == Name: - print "INFO: Files appear to be in their own directory" + Logger.info("Files appear to be in their own directory") DirBase2 = os.path.split(os.path.normpath(DirBase[0])) if DirBase2[1] == Movie_Cat or DirBase == TV_Cat: if not Category: - print "INFO: Determined Category to be: %s" % (DirBase2[1]) + Logger.info("Determined Category to be: %s", DirBase2[1]) Category = DirBase2[1] elif DirBase[1] == Movie_Cat or DirBase == TV_Cat: if os.path.isdir(os.path.join(Directory, Name)): - print "INFO: Found torrent directory %s in category directory %s" % (os.path.join(Directory, Name), Directory) + Logger.info("Found torrent directory %s in category directory %s", os.path.join(Directory, Name), Directory) Directory = os.path.join(Directory, Name) else: - print "INFO: The directory passed is the root directory for category %s" % (DirBase[1]) - print "WARNING: You should change settings to download torrents to their own directory" - print "INFO: We will try and determine which files to process, individually" + Logger.info("The directory passed is the root directory for category %s", DirBase[1]) + Logger.warn("You should change settings to download torrents to their own directory") + Logger.info("We will try and determine which files to process, individually") root = 1 if not Category: - print "INFO: Determined Category to be: %s" % (DirBase2[1]) + Logger.info("Determined Category to be: %s", DirBase2[1]) Category = DirBase[1] else: # no category found in directory. For Utorrent we can do a recursive scan. - print "INFO: The directory passed does not appear to include a category or the torrent name" - print "WARNING: You should change settings to download torrents to their own directory" - print "INFO: We will try and determine which files to process, individually" + Logger.info("The directory passed does not appear to include a category or the torrent name") + Logger.warn("You should change settings to download torrents to their own directory") + Logger.info("We will try and determine which files to process, individually") root = 1 if Category == Movie_Cat: @@ -146,23 +157,23 @@ if Category == Movie_Cat: elif Category == TV_Cat: destination = os.path.join(TV_dest, Name) else: - print "INFO: Category of %s does not match either %s or %s: Exiting" %(Category, Movie_Cat, TV_Cat) + Logger.info("Category of %s does not match either %s or %s: Exiting", Category, Movie_Cat, TV_Cat) sys.exit(-1) test = ['.zip', '.rar', '.7z', '.gz', '.bz', '.tar', '.arj'] test2 = ['.mkv', '.avi', '.divx', '.xvid', '.mov', '.wmv', '.mp4', '.mpg', '.mpeg'] -print "DEBUG: scanning files in directory: %s" % (Directory) +Logger.debug("scanning files in directory: %s", Directory) f = [filenames for dirpath, dirnames, filenames in os.walk(Directory)] if root == 1: - print "DEBUG: Looking for %s in filenames" % (Name) + Logger.debug("Looking for %s in filenames", Name) for file in f[1]: if (Name in file) or (file in Name): if os.path.splitext(file)[1] in test: - print "INFO: Found a packed file %s" % (file) + Logger.info("Found a packed file %s", file) packed = 1 break elif os.path.splitext(file)[1] in test2: - print "INFO: Found a video file %s" % (file) + Logger.info("Found a video file %s", file) video = 1 break else: @@ -170,24 +181,24 @@ if root == 1: else: ext = [os.path.splitext(file)[1] for file in f[1]] if set(ext).intersection(set(test)): - print "INFO: Found compressed archives, extracting" + Logger.info("Found compressed archives, extracting") packed = 1 ## Check that files actully is .mkv / .avi etc, and not packed files or anything else elif set(ext).intersection(set(test2)): - print "INFO: Found media files, moving" + Logger.info("Found media files, moving") video = 1 else: - print "DEBUG: Found files with extensions %s." % (ext) - print "DEBUG: Looking for extensions %s or %s." % (test, test2) - print "INFO: Didn't find any compressed archives or media files to process, exiting" + Logger.debug("Found files with extensions %s.", ext) + Logger.debug("Looking for extensions %s or %s.", test, test2) + Logger.info("Didn't find any compressed archives or media files to process, exiting") sys.exit(-1) if useLink == 0 and packed == 0 and video == 1: ## copy if root == 0: #move all files in tier own directory - print "INFO: Copying all files from %s to %s." % (Directory, destination) + Logger.info("Copying all files from %s to %s.", Directory, destination) shutil.copytree(Directory, destination) else: #we only want to move files matching the torrent name when root directory is used. - print "INFO: Copying files that match the torrent name %s from %s to %s." % (Name, Directory, destination) + Logger.info("Copying files that match the torrent name %s from %s to %s.", Name, Directory, destination) for dirpath, dirnames, filenames in os.walk(Directory): for file in filenames: if (Name in file) or (file in Name): @@ -199,7 +210,7 @@ if useLink == 0 and packed == 0 and video == 1: ## copy shutil.copy(source, target) elif useLink == 1 and packed == 0 and video == 1: ## hardlink - print "INFO: Creating hard link for files from %s to %s." % (Directory, destination) + Logger.info("Creating hard link for files from %s to %s.", Directory, destination) os.mkdir(destination) for dirpath, dirnames, filenames in os.walk(Directory): for file in filenames: @@ -216,7 +227,7 @@ elif useLink == 1 and packed == 0 and video == 1: ## hardlink elif os.name == 'posix': os.link(source, target) else: - print "ERROR: Hardlink failed, cannot determine OS." + Logger.info("Hardlink failed, cannot determine OS.") elif packed == 1: ## unpack ## Using Windows? @@ -224,7 +235,7 @@ elif packed == 1: ## unpack cmd_7zip = [extractionTool, 'x -y'] ext_7zip = [".rar",".zip",".tar.gz","tgz",".tar.bz2",".tbz",".tar.lzma",".tlz",".7z",".xz"] EXTRACT_COMMANDS = dict.fromkeys(ext_7zip, cmd_7zip) - print "INFO: We are using Windows" + Logger.info("We are using Windows") ## Using linux? elif os.name == 'posix': @@ -241,11 +252,11 @@ elif packed == 1: ## unpack ".txz": ["tar", "--xz xf"], ".7z": ["7zr", "x"], } - print "INFO: We are using *nix" + Logger.info("We are using *nix") ## Need to add a check for which commands that can be utilized in *nix systems.. else: - print "ERROR: Unknown OS, exiting" + Logger.error("Unknown OS, exiting") files = [ f for f in os.listdir(Directory) if os.path.isfile(os.path.join(Directory,f)) ] for f in files: @@ -264,7 +275,7 @@ elif packed == 1: ## unpack if ext[1] in EXTRACT_COMMANDS: cmd = EXTRACT_COMMANDS[ext[1]] else: - print "ERROR: Unknown file type: %s" % (ext[1]) + Logger.debug("Unknown file type: %s", ext[1]) continue ## Create destination folder @@ -272,13 +283,13 @@ elif packed == 1: ## unpack try: os.makedirs(destination) except Exception, e: - print "ERROR: Not possible to create destination folder: %s" % (e) + Logger.error("Not possible to create destination folder: %s", e) continue - print"INFO: Extracting to %s" % (destination) + Logger.info("Extracting to %s", destination) ## Running.. - print "INFO: Extracting %s %s %s %s" % (cmd[0], cmd[1], fp, destination) + Logger.info("Extracting %s %s %s %s", cmd[0], cmd[1], fp, destination) pwd = os.getcwd() # Get our Present Working Directory os.chdir(destination) #not all unpack commands accept full paths, so just extract into this directory. if os.name == 'nt': #Windows needs quotes around directory structure @@ -287,11 +298,11 @@ elif packed == 1: ## unpack res = call(run) if res == 0: status = 0 - print "INFO: Extraction was successful for %s to %s" % (fp, destination) + Logger.info("Extraction was successful for %s to %s", fp, destination) else: - print "ERROR: Extraction failed for %s. 7zip result was %s" % (fp, res) + Logger.info("Extraction failed for %s. 7zip result was %s", fp, res) except: - print "ERROR: Extraction failed for %s. Could not call command %s %s" % (fp, run) + Logger.error("Extraction failed for %s. Could not call command %s %s", fp, run) else: try: if cmd[1] == "": #if calling unzip, we dont want to pass the "" @@ -300,11 +311,11 @@ elif packed == 1: ## unpack res = call([cmd[0], cmd[1], fp]) if res == 0: status = 0 - print "INFO: Extraction was successful for %s to %s" % (fp, destination) + Logger.info("Extraction was successful for %s to %s", fp, destination) else: - print "ERROR: Extraction failed for %s. 7zip result was %s" % (fp, res) + Logger.error("Extraction failed for %s. 7zip result was %s", fp, res) except: - print "ERROR: Extraction failed for %s. Could not call command %s %s %s %s" % (fp, cmd[0], cmd[1], fp) + Logger.error("Extraction failed for %s. Could not call command %s %s %s %s", fp, cmd[0], cmd[1], fp) os.chdir(pwd) # Go back to our Original Working Directory for dirpath, dirnames, filenames in os.walk(destination): #flatten out the directory to make postprocessing easier. @@ -314,15 +325,20 @@ for dirpath, dirnames, filenames in os.walk(destination): #flatten out the direc try: shutil.move(os.path.join(dirpath, filename), destination) except OSError: - print "INFO: Could not flatten %s " % (os.path.join(dirpath, filename)) + Logger.info("Could not flatten %s", os.path.join(dirpath, filename)) removeEmptyFolders(destination) #cleanup empty directories. status = int(status) +if status == 0: + Logger.info("calling autoProcess script for successful download") +else: + Logger.info("calling autoProcess script for failed download") ## Now we pass off to CouchPotato or SickBeard. +old_stdout = sys.stdout #backup the default stdout +sys.stdout = Logger.info #Capture the print from the autoProcess scripts. if Category == Movie_Cat: autoProcessMovie.process(destination, Name, status) elif Category == TV_Cat: autoProcessTV.processEpisode(destination, Name, status) - sys.stdout = old_stdout #reset our stdout -log_file.close() #close the log +#log_file.close() #close the log