diff --git a/resources/lib/PlexCompanion.py b/resources/lib/PlexCompanion.py index c6e92edb..ff13eb9b 100644 --- a/resources/lib/PlexCompanion.py +++ b/resources/lib/PlexCompanion.py @@ -1,4 +1,5 @@ # -*- coding: utf-8 -*- +import logging import threading import traceback import socket @@ -6,35 +7,37 @@ import Queue import xbmc -import utils +from utils import settings, ThreadMethodsAdditionalSuspend, ThreadMethods from plexbmchelper import listener, plexgdm, subscribers, functions, \ - httppersist, settings + httppersist, plexsettings from PlexFunctions import ParseContainerKey, GetPlayQueue, \ ConvertPlexToKodiTime import playlist import player +############################################################################### -@utils.logging -@utils.ThreadMethodsAdditionalSuspend('plex_serverStatus') -@utils.ThreadMethods +log = logging.getLogger("PLEX."+__name__) + +############################################################################### + + +@ThreadMethodsAdditionalSuspend('plex_serverStatus') +@ThreadMethods class PlexCompanion(threading.Thread): """ Initialize with a Queue for callbacks """ def __init__(self): - self.logMsg("----===## Starting PlexCompanion ##===----", 1) - self.settings = settings.getSettings() - + log.info("----===## Starting PlexCompanion ##===----") + self.settings = plexsettings.getSettings() # Start GDM for server/client discovery self.client = plexgdm.plexgdm() self.client.clientDetails(self.settings) - self.logMsg("Registration string is: %s " - % self.client.getClientDetails(), 2) - + log.debug("Registration string is: %s " + % self.client.getClientDetails()) # Initialize playlist/queue stuff self.playlist = playlist.Playlist('video') - # kodi player instance self.player = player.Player() @@ -54,7 +57,7 @@ class PlexCompanion(threading.Thread): except IndexError: string = '' else: - self.logMsg('Unknown string! %s' % string, -1) + log.error('Unknown string! %s' % string) return typus, string def processTasks(self, task): @@ -66,37 +69,32 @@ class PlexCompanion(threading.Thread): 'data': as received from Plex companion } """ - self.logMsg('Processing: %s' % task, 2) + log.debug('Processing: %s' % task) data = task['data'] if task['action'] == 'playlist': try: _, queueId, query = ParseContainerKey(data['containerKey']) except Exception as e: - self.logMsg('Exception while processing: %s' % e, -1) + log.error('Exception while processing: %s' % e) import traceback - self.logMsg("Traceback:\n%s" % traceback.format_exc(), -1) + log.error("Traceback:\n%s" % traceback.format_exc()) return if self.playlist is not None: if self.playlist.Typus() != data.get('type'): - self.logMsg('Switching to Kodi playlist of type %s' - % data.get('type'), 1) + log.debug('Switching to Kodi playlist of type %s' + % data.get('type')) self.playlist = None if self.playlist is None: if data.get('type') == 'music': self.playlist = playlist.Playlist('music') - elif data.get('type') == 'video': - self.playlist = playlist.Playlist('video') else: - self.playlist = playlist.Playlist() - if self.playlist is None: - self.logMsg('Could not initialize playlist', -1) - return + self.playlist = playlist.Playlist('video') if queueId != self.playlist.QueueId(): - self.logMsg('New playlist received, updating!', 1) + log.info('New playlist received, updating!') xml = GetPlayQueue(queueId) if xml in (None, 401): - self.logMsg('Could not download Plex playlist.', -1) + log.error('Could not download Plex playlist.') return # Clear existing playlist on the Kodi side self.playlist.clear() @@ -115,16 +113,15 @@ class PlexCompanion(threading.Thread): items, startitem=self._getStartItem(data.get('key', '')), offset=ConvertPlexToKodiTime(data.get('offset', 0))) - self.logMsg('Initiated playlist no %s with version %s' - % (self.playlist.QueueId(), - self.playlist.PlayQueueVersion())) + log.info('Initiated playlist no %s with version %s' + % (self.playlist.QueueId(), + self.playlist.PlayQueueVersion())) else: - self.logMsg('This has never happened before!', -1) + log.error('This has never happened before!') def run(self): httpd = False # Cache for quicker while loops - log = self.logMsg client = self.client threadStopped = self.threadStopped threadSuspended = self.threadSuspended @@ -137,8 +134,7 @@ class PlexCompanion(threading.Thread): queue = Queue.Queue(maxsize=100) - if utils.settings('plexCompanion') == 'true': - self.logMsg('User activated Plex Companion', 0) + if settings('plexCompanion') == 'true': # Start up httpd start_count = 0 while True: @@ -154,19 +150,19 @@ class PlexCompanion(threading.Thread): httpd.timeout = 0.95 break except: - log("Unable to start PlexCompanion. Traceback:", -1) - log(traceback.print_exc(), -1) + log.error("Unable to start PlexCompanion. Traceback:") + log.error(traceback.print_exc()) xbmc.sleep(3000) if start_count == 3: - log("Error: Unable to start web helper.", -1) + log.error("Error: Unable to start web helper.") httpd = False break start_count += 1 else: - self.logMsg('User deactivated Plex Companion', 0) + log.info('User deactivated Plex Companion') client.start_all() @@ -193,12 +189,11 @@ class PlexCompanion(threading.Thread): if message_count == 3000: message_count = 0 if client.check_client_registration(): - log("Client is still registered", 1) + log.debug("Client is still registered") else: - log("Client is no longer registered", 1) - log("Plex Companion still running on port %s" - % self.settings['myport'], 1) - + log.info("Client is no longer registered" + "Plex Companion still running on port %s" + % self.settings['myport']) # Get and set servers if message_count % 30 == 0: subscriptionManager.serverlist = client.getServerList() @@ -206,8 +201,8 @@ class PlexCompanion(threading.Thread): if not httpd: message_count = 0 except: - log("Error in loop, continuing anyway. Traceback:", 1) - log(traceback.format_exc(), 1) + log.warn("Error in loop, continuing anyway. Traceback:") + log.warn(traceback.format_exc()) # See if there's anything we need to process try: task = queue.get(block=False) @@ -229,4 +224,4 @@ class PlexCompanion(threading.Thread): pass finally: httpd.socket.close() - log("----===## Plex Companion stopped ##===----", 0) + log.info("----===## Plex Companion stopped ##===----") diff --git a/resources/lib/plexbmchelper/functions.py b/resources/lib/plexbmchelper/functions.py index 9fbb617d..443b1c8f 100644 --- a/resources/lib/plexbmchelper/functions.py +++ b/resources/lib/plexbmchelper/functions.py @@ -1,12 +1,18 @@ +import logging import base64 import json import string import xbmc -from utils import logging import embydb_functions as embydb +############################################################################### + +log = logging.getLogger("PLEX."+__name__) + +############################################################################### + def xbmc_photo(): return "photo" @@ -82,7 +88,6 @@ def textFromXml(element): return element.firstChild.data -@logging class jsonClass(): def __init__(self, requestMgr, settings): @@ -139,7 +144,6 @@ class jsonClass(): return result def skipTo(self, plexId, typus): - self.logMsg('players: %s' % self.getPlayers()) # playlistId = self.getPlaylistId(tryDecode(xbmc_type(typus))) # playerId = self. with embydb.GetEmbyDB() as emby_db: @@ -148,10 +152,10 @@ class jsonClass(): dbid = embydb_item[0] mediatype = embydb_item[4] except TypeError: - self.logMsg('Couldnt find item %s in Kodi db' % plexId, 1) + log.info('Couldnt find item %s in Kodi db' % plexId) return - self.logMsg('plexid: %s, kodi id: %s, type: %s' - % (plexId, dbid, mediatype)) + log.debug('plexid: %s, kodi id: %s, type: %s' + % (plexId, dbid, mediatype)) def getPlexHeaders(self): h = { @@ -172,12 +176,12 @@ class jsonClass(): def parseJSONRPC(self, jsonraw): if not jsonraw: - self.logMsg("Empty response from XBMC", 1) + log.debug("Empty response from Kodi") return {} else: parsed = json.loads(jsonraw) if parsed.get('error', False): - self.logMsg("XBMC returned an error: %s" % parsed.get('error'), -1) + log.error("Kodi returned an error: %s" % parsed.get('error')) return parsed.get('result', {}) def getPlayers(self): diff --git a/resources/lib/plexbmchelper/httppersist.py b/resources/lib/plexbmchelper/httppersist.py index 8f9a9fe4..0fdf61bb 100644 --- a/resources/lib/plexbmchelper/httppersist.py +++ b/resources/lib/plexbmchelper/httppersist.py @@ -1,13 +1,17 @@ +import logging import httplib import traceback import string import errno from socket import error as socket_error -from utils import logging +############################################################################### + +log = logging.getLogger("PLEX."+__name__) + +############################################################################### -@logging class RequestMgr: def __init__(self): self.conns = {} @@ -41,7 +45,7 @@ class RequestMgr: conn.request("POST", path, body, header) data = conn.getresponse() if int(data.status) >= 400: - self.logMsg("HTTP response error: %s" % str(data.status), -1) + log.error("HTTP response error: %s" % str(data.status)) # this should return false, but I'm hacking it since iOS # returns 404 no matter what return data.read() or True @@ -52,8 +56,8 @@ class RequestMgr: if serr.errno in (errno.WSAECONNABORTED, errno.WSAECONNREFUSED): pass else: - self.logMsg("Unable to connect to %s\nReason:" % host, -1) - self.logMsg(traceback.print_exc(), -1) + log.error("Unable to connect to %s\nReason:" % host) + log.error(traceback.print_exc()) self.conns.pop(protocol+host+str(port), None) if conn: conn.close() @@ -75,7 +79,7 @@ class RequestMgr: conn.request("GET", path, headers=header) data = conn.getresponse() if int(data.status) >= 400: - self.logMsg("HTTP response error: %s" % str(data.status), -1) + log.error("HTTP response error: %s" % str(data.status)) return False else: return data.read() or True @@ -84,8 +88,8 @@ class RequestMgr: if serr.errno in (errno.WSAECONNABORTED, errno.WSAECONNREFUSED): pass else: - self.logMsg("Unable to connect to %s\nReason:" % host, -1) - self.logMsg(traceback.print_exc(), -1) + log.error("Unable to connect to %s\nReason:" % host) + log.error(traceback.print_exc()) self.conns.pop(protocol+host+str(port), None) conn.close() return False diff --git a/resources/lib/plexbmchelper/listener.py b/resources/lib/plexbmchelper/listener.py index db18a58b..422a9232 100644 --- a/resources/lib/plexbmchelper/listener.py +++ b/resources/lib/plexbmchelper/listener.py @@ -1,3 +1,5 @@ +# -*- coding: utf-8 -*- +import logging import re from SocketServer import ThreadingMixIn from BaseHTTPServer import HTTPServer, BaseHTTPRequestHandler @@ -6,10 +8,15 @@ from urlparse import urlparse, parse_qs from xbmc import sleep from functions import * -from utils import logging -@logging +############################################################################### + +log = logging.getLogger("PLEX."+__name__) + +############################################################################### + + class MyHandler(BaseHTTPRequestHandler): protocol_version = 'HTTP/1.1' regex = re.compile(r'''/playQueues/(\d+)$''') @@ -28,11 +35,11 @@ class MyHandler(BaseHTTPRequestHandler): return {} def do_HEAD(self): - self.logMsg("Serving HEAD request...", 2) + log.debug("Serving HEAD request...") self.answer_request(0) def do_GET(self): - self.logMsg("Serving GET request...", 2) + log.debug("Serving GET request...") self.answer_request(1) def do_OPTIONS(self): @@ -86,8 +93,8 @@ class MyHandler(BaseHTTPRequestHandler): params = {} for key in paramarrays: params[key] = paramarrays[key][0] - self.logMsg("remote request_path: %s" % request_path, 2) - self.logMsg("params received from remote: %s" % params, 2) + log.debug("remote request_path: %s" % request_path) + log.debug("params received from remote: %s" % params) subMgr.updateCommandID(self.headers.get( 'X-Plex-Client-Identifier', self.client_address[0]), @@ -119,7 +126,7 @@ class MyHandler(BaseHTTPRequestHandler): settings['uuid'], settings['platform'], settings['plexbmc_version'])) - self.logMsg("crafted resources response: %s" % resp, 2) + log.debug("crafted resources response: %s" % resp) self.response(resp, js.getPlexHeaders()) elif "/subscribe" in request_path: self.response(getOKMsg(), js.getPlexHeaders()) @@ -157,7 +164,7 @@ class MyHandler(BaseHTTPRequestHandler): self.response(getOKMsg(), js.getPlexHeaders()) if 'volume' in params: volume = int(params['volume']) - self.logMsg("adjusting the volume to %s%%" % volume, 2) + log.debug("adjusting the volume to %s%%" % volume) js.jsonrpc("Application.SetVolume", {"volume": volume}) elif "/playMedia" in request_path: @@ -266,31 +273,12 @@ class MyHandler(BaseHTTPRequestHandler): self.response(getOKMsg(), js.getPlexHeaders()) js.jsonrpc("Input.Back") else: - self.logMsg('Unknown request path: %s' % request_path, -1) - # elif 'player/mirror/details' in request_path: - # # Detailed e.g. Movie information page was opened - # # CURRENTLY NOT POSSIBLE DUE TO KODI RESTRICTIONS - # plexId = params.get('key', params.get('ratingKey')) - # if plexId is None: - # self.logMsg('Could not get plex id from params: %s' - # % params, -1) - # return - # if 'library/metadata' in plexId: - # plexId = plexId.rsplit('/', 1)[1] - # with embydb.GetEmbyDB() as emby_db: - # emby_dbitem = emby_db.getItem_byId(plexId) - # try: - # kodiid = emby_dbitem[0] - # mediatype = emby_dbitem[4] - # except TypeError: - # self.log("No Plex id returned for plexId %s" % plexId, 0) - # return - # getDBfromPlexType(mediatype) + log.error('Unknown request path: %s' % request_path) except: - self.logMsg('Error encountered. Traceback:', -1) + log.error('Error encountered. Traceback:') import traceback - self.logMsg(traceback.print_exc(), -1) + log.error(traceback.print_exc()) class ThreadedHTTPServer(ThreadingMixIn, HTTPServer): diff --git a/resources/lib/plexbmchelper/plexgdm.py b/resources/lib/plexbmchelper/plexgdm.py index 8ea8692d..71d17558 100644 --- a/resources/lib/plexbmchelper/plexgdm.py +++ b/resources/lib/plexbmchelper/plexgdm.py @@ -21,8 +21,7 @@ along with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. """ - - +import logging import socket import threading import time @@ -30,10 +29,15 @@ import time from xbmc import sleep import downloadutils -from utils import window, logging, settings +from utils import window, settings + +############################################################################### + +log = logging.getLogger("PLEX."+__name__) + +############################################################################### -@logging class plexgdm: def __init__(self): @@ -80,10 +84,6 @@ class plexgdm: self.client_id = options['uuid'] def getClientDetails(self): - if not self.client_data: - self.logMsg("Client data has not been initialised. Please use " - "PlexGDM.clientDetails()", -1) - return self.client_data def client_update(self): @@ -104,8 +104,8 @@ class plexgdm: try: update_sock.bind(('0.0.0.0', self.client_update_port)) except: - self.logMsg("Unable to bind to port [%s] - client will not be " - "registered" % self.client_update_port, -1) + log.error("Unable to bind to port [%s] - client will not be " + "registered" % self.client_update_port) return update_sock.setsockopt(socket.IPPROTO_IP, @@ -117,8 +117,8 @@ class plexgdm: self._multicast_address) + socket.inet_aton('0.0.0.0')) update_sock.setblocking(0) - self.logMsg("Sending registration data: HELLO %s\r\n%s" - % (self.client_header, self.client_data), 2) + log.debug("Sending registration data: HELLO %s\r\n%s" + % (self.client_header, self.client_data)) # Send initial client registration try: @@ -126,54 +126,49 @@ class plexgdm: % (self.client_header, self.client_data), self.client_register_group) except: - self.logMsg("Unable to send registration message", -1) + log.error("Unable to send registration message") - # Now, listen for client discovery reguests and respond. + # Now, listen format client discovery reguests and respond. while self._registration_is_running: try: data, addr = update_sock.recvfrom(1024) - self.logMsg("Recieved UDP packet from [%s] containing [%s]" - % (addr, data.strip()), 2) + log.debug("Recieved UDP packet from [%s] containing [%s]" + % (addr, data.strip())) except socket.error: pass else: if "M-SEARCH * HTTP/1." in data: - self.logMsg("Detected client discovery request from %s. " - " Replying" % str(addr), 2) + log.debug("Detected client discovery request from %s. " + " Replying" % str(addr)) try: update_sock.sendto("HTTP/1.0 200 OK\r\n%s" % self.client_data, addr) except: - self.logMsg("Unable to send client update message", -1) + log.error("Unable to send client update message") - self.logMsg("Sending registration data HTTP/1.0 200 OK", 2) + log.debug("Sending registration data HTTP/1.0 200 OK") self.client_registered = True sleep(500) - - self.logMsg("Client Update loop stopped", 1) - + log.info("Client Update loop stopped") # When we are finished, then send a final goodbye message to # deregister cleanly. - self.logMsg("Sending registration data: BYE %s\r\n%s" - % (self.client_header, self.client_data), 2) + log.debug("Sending registration data: BYE %s\r\n%s" + % (self.client_header, self.client_data)) try: update_sock.sendto("BYE %s\r\n%s" % (self.client_header, self.client_data), self.client_register_group) except: - self.logMsg("Unable to send client update message", -1) - + log.error("Unable to send client update message") self.client_registered = False def check_client_registration(self): if self.client_registered and self.discovery_complete: - if not self.server_list: - self.logMsg("Server list is empty. Unable to check", 1) + log.info("Server list is empty. Unable to check") return False - try: for server in self.server_list: if server['uuid'] == window('plex_machineIdentifier'): @@ -182,11 +177,11 @@ class plexgdm: scheme = server['protocol'] break else: - self.logMsg("Did not find our server!", 0) + log.info("Did not find our server!") return False - self.logMsg("Checking server [%s] on port [%s]" - % (media_server, media_port), 2) + log.debug("Checking server [%s] on port [%s]" + % (media_server, media_port)) client_result = self.download( '%s://%s:%s/clients' % (scheme, media_server, media_port)) registered = False @@ -195,17 +190,15 @@ class plexgdm: self.client_id): registered = True if registered: - self.logMsg("Client registration successful", 1) - self.logMsg("Client data is: %s" % client_result, 2) + log.debug("Client registration successful. " + "Client data is: %s" % client_result) return True else: - self.logMsg("Client registration not found", 1) - self.logMsg("Client data is: %s" % client_result, 1) - + log.info("Client registration not found. " + "Client data is: %s" % client_result) except: - self.logMsg("Unable to check status", 0) + log.error("Unable to check status") pass - return False def getServerList(self): @@ -244,21 +237,21 @@ class plexgdm: def stop_discovery(self): if self._discovery_is_running: - self.logMsg("Discovery shutting down", 0) + log.info("Discovery shutting down") self._discovery_is_running = False self.discover_t.join() del self.discover_t else: - self.logMsg("Discovery not running", 0) + log.info("Discovery not running") def stop_registration(self): if self._registration_is_running: - self.logMsg("Registration shutting down", 0) + log.info("Registration shutting down") self._registration_is_running = False self.register_t.join() del self.register_t else: - self.logMsg("Registration not running", 0) + log.info("Registration not running") def run_discovery_loop(self): # Run initial discovery @@ -274,23 +267,23 @@ class plexgdm: def start_discovery(self, daemon=False): if not self._discovery_is_running: - self.logMsg("Discovery starting up", 0) + log.info("Discovery starting up") self._discovery_is_running = True self.discover_t = threading.Thread(target=self.run_discovery_loop) self.discover_t.setDaemon(daemon) self.discover_t.start() else: - self.logMsg("Discovery already running", 0) + log.info("Discovery already running") def start_registration(self, daemon=False): if not self._registration_is_running: - self.logMsg("Registration starting up", 0) + log.info("Registration starting up") self._registration_is_running = True self.register_t = threading.Thread(target=self.client_update) self.register_t.setDaemon(daemon) self.register_t.start() else: - self.logMsg("Registration already running", 0) + log.info("Registration already running") def start_all(self, daemon=False): self.start_discovery(daemon) diff --git a/resources/lib/plexbmchelper/settings.py b/resources/lib/plexbmchelper/plexsettings.py similarity index 100% rename from resources/lib/plexbmchelper/settings.py rename to resources/lib/plexbmchelper/plexsettings.py diff --git a/resources/lib/plexbmchelper/subscribers.py b/resources/lib/plexbmchelper/subscribers.py index 93f4c3ff..66fc8eb1 100644 --- a/resources/lib/plexbmchelper/subscribers.py +++ b/resources/lib/plexbmchelper/subscribers.py @@ -1,13 +1,19 @@ +import logging import re import threading import downloadutils -from utils import window, logging +from utils import window import PlexFunctions as pf from functions import * +############################################################################### + +log = logging.getLogger("PLEX."+__name__) + +############################################################################### + -@logging class SubscriptionManager: def __init__(self, jsonClass, RequestMgr, player, playlist): self.serverlist = [] @@ -191,8 +197,8 @@ class SubscriptionManager: serv.get('server', 'localhost'), serv.get('port', '32400')) self.doUtils(url, parameters=params) - self.logMsg("Sent server notification with parameters: %s to %s" - % (params, url), 2) + log.debug("Sent server notification with parameters: %s to %s" + % (params, url)) def controllable(self): return "volume,shuffle,repeat,audioStream,videoStream,subtitleStream,skipPrevious,skipNext,seekTo,stepBack,stepForward,stop,playPause" @@ -256,8 +262,7 @@ class SubscriptionManager: self.playlist.getQueueIdFromPosition(pos['position']) except: import traceback - self.logMsg("Traceback:\n%s" - % traceback.format_exc(), -1) + log.error("Traceback:\n%s" % traceback.format_exc()) info = { 'time': 0, 'duration': 0, @@ -273,7 +278,6 @@ class SubscriptionManager: return info -@logging class Subscriber: def __init__(self, protocol, host, port, uuid, commandID, subMgr, RequestMgr): @@ -306,8 +310,7 @@ class Subscriber: else: self.navlocationsent = True msg = re.sub(r"INSERTCOMMANDID", str(self.commandID), msg) - self.logMsg("sending xml to subscriber %s: %s" - % (self.tostr(), msg), 2) + log.debug("sending xml to subscriber %s: %s" % (self.tostr(), msg)) url = self.protocol + '://' + self.host + ':' + self.port \ + "/:/timeline" t = threading.Thread(target=self.threadedSend, args=(url, msg))