Ausgabe von tivodecode einsammeln und loggen (statt stdout/stderr direkt)

src/tivomirror/tivomirror

@@ -1,6 +1,6 @@
 #!/usr/local/bin/python
 
-# $Schlepperbande: src/tivomirror/tivomirror,v 1.58 2014/07/01 16:57:33 stb Exp $
+# $Schlepperbande: src/tivomirror/tivomirror,v 1.59 2014/07/01 17:04:17 stb Exp $
 #
 # Stefans Script, um die Sendungen vom Tivo runterzuladen und in MPEG4
 # zu transkodieren.
@@ -26,6 +26,7 @@ import signal
 import shutil
 import subprocess
 import sys
+import threading
 import time
 import urllib2
 import xml.dom.minidom
@@ -230,6 +231,25 @@ def quit_process(pid):
 		pass
 
 
+class FdLogger(threading.Thread):
+	def __init__(self, logger, lvl, fd):
+		self.logger = logger
+		self.lvl = lvl
+		self.fd = fd
+		threading.Thread.__init__(self)
+		self.daemon = True
+		self.start()
+
+	def run(self):
+		try:
+			# for line in fd buffers, so use this instead
+			for line in iter(self.fd.readline, b''):
+				self.logger.log(self.lvl, ":   %s", line.strip('\n'))
+			self.fd.close()
+		except Exception:
+			self.logger.exception("")
+
+
 @timeout(7200)
 def download(url, mak, target):
 	global session
@@ -245,8 +265,12 @@ def download(url, mak, target):
 
 	try:
 		p_decode = subprocess.Popen(["tivodecode", "--mak", mak, \
-			"--no-verify", "--out", target, "-"], stdin=subprocess.PIPE)
+			"--no-verify", "--out", target, "-"], stdin=subprocess.PIPE,
+			stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+		FdLogger(logger, logging.INFO, p_decode.stdout)
+		FdLogger(logger, logging.ERROR, p_decode.stderr)
 		while True:
+			time.sleep(0) # yield to logger threads
 			chunk = r.raw.read(65536)
 			if chunk:
 				p_decode.stdin.write(chunk)
@@ -268,12 +292,12 @@ def download(url, mak, target):
 			count/1e9, int(elapsed/3600), int(elapsed / 60) % 60, throughput/1e6))
 		try:
 			p_decode.stdin.close()
-			#quit_process(p_decode.pid)
 			p_decode.poll()
 			if p_decode.returncode == None:
 				time.sleep(1)
 				p_decode.poll()
 				if p_decode.returncode == None:
+					logger.debug("terminating tivodecode")
 					p_decode.terminate()
 		except Exception, e:
 			pass
@@ -363,8 +387,6 @@ def mirror(dom, downloaddb):
 		except TivoException, e:
 			logger.info("Error processing \"%s\": %s" % (item.name, e))
 
-	logger.info("*** Completed %s" % datetime.datetime.now().strftime("%Y-%m-%d %H:%M"))
-
 
 def printtoc(dom, downloaddb):
 	items = dom.getElementsByTagName("Item")
@@ -383,7 +405,7 @@ def main():
 	curdir = os.getcwd()
 	os.chdir(os.path.expanduser("~") + "/.tivo")
 	handler = logging.handlers.RotatingFileHandler("tivomirror.log", maxBytes=2*1024*1024, backupCount=5)
-	handler.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s'))
+	handler.setFormatter(logging.Formatter('%(asctime)s %(levelname)6.6s %(message)s'))
 	logger.addHandler(handler)
 
 	try: