Troplo/PlexKodiConnect
1
0
Fork 0
Code Issues Pull requests Projects Releases Wiki Activity

Code cleanup

Browse source
This commit is contained in:
croneter 2018-04-15 18:33:20 +02:00
parent 83e85a3ea9
commit 3fe5cf571c
1 changed files with 104 additions and 105 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

209
resources/lib/librarysync.py
View file

@ -34,7 +34,7 @@ import state
############################################################################### ###############################################################################
log = getLogger("PLEX."+__name__) LOG = getLogger("PLEX." + __name__)
############################################################################### ###############################################################################
@ -92,7 +92,7 @@ class LibrarySync(Thread):
Any info with a PMS timestamp is in Plex time, naturally Any info with a PMS timestamp is in Plex time, naturally
""" """
log.info('Synching time with PMS server') LOG.info('Synching time with PMS server')
# Find a PMS item where we can toggle the view state to enforce a # Find a PMS item where we can toggle the view state to enforce a
# change in lastViewedAt # change in lastViewedAt
@ -101,7 +101,7 @@ class LibrarySync(Thread):
try: try:
sections.attrib sections.attrib
except AttributeError: except AttributeError:
log.error("Error download PMS views, abort syncPMStime") LOG.error("Error download PMS views, abort syncPMStime")
return False return False
plexId = None plexId = None
@ -118,8 +118,8 @@ class LibrarySync(Thread):
libraryId = view.attrib['key'] libraryId = view.attrib['key']
items = GetAllPlexLeaves(libraryId) items = GetAllPlexLeaves(libraryId)
if items in (None, 401): if items in (None, 401):
log.error("Could not download section %s" LOG.error("Could not download section %s",
% view.attrib['key']) view.attrib['key'])
continue continue
for item in items: for item in items:
if item.attrib.get('viewCount') is not None: if item.attrib.get('viewCount') is not None:
@ -129,30 +129,30 @@ class LibrarySync(Thread):
# Don't mess with items with a resume point # Don't mess with items with a resume point
continue continue
plexId = item.attrib.get('ratingKey') plexId = item.attrib.get('ratingKey')
log.info('Found an item to sync with: %s' % plexId) LOG.info('Found an item to sync with: %s', plexId)
break break
if plexId is None: if plexId is None:
log.error("Could not find an item to sync time with") LOG.error("Could not find an item to sync time with")
log.error("Aborting PMS-Kodi time sync") LOG.error("Aborting PMS-Kodi time sync")
return False return False
# Get the Plex item's metadata # Get the Plex item's metadata
xml = GetPlexMetadata(plexId) xml = GetPlexMetadata(plexId)
if xml in (None, 401): if xml in (None, 401):
log.error("Could not download metadata, aborting time sync") LOG.error("Could not download metadata, aborting time sync")
return False return False
timestamp = xml[0].attrib.get('lastViewedAt') timestamp = xml[0].attrib.get('lastViewedAt')
if timestamp is None: if timestamp is None:
timestamp = xml[0].attrib.get('updatedAt') timestamp = xml[0].attrib.get('updatedAt')
log.debug('Using items updatedAt=%s' % timestamp) LOG.debug('Using items updatedAt=%s', timestamp)
if timestamp is None: if timestamp is None:
timestamp = xml[0].attrib.get('addedAt') timestamp = xml[0].attrib.get('addedAt')
log.debug('Using items addedAt=%s' % timestamp) LOG.debug('Using items addedAt=%s', timestamp)
if timestamp is None: if timestamp is None:
timestamp = 0 timestamp = 0
log.debug('No timestamp; using 0') LOG.debug('No timestamp; using 0')
# Set the timer # Set the timer
koditime = unix_timestamp() koditime = unix_timestamp()
@ -165,7 +165,7 @@ class LibrarySync(Thread):
# Toggle watched state back # Toggle watched state back
scrobble(plexId, 'unwatched') scrobble(plexId, 'unwatched')
if items in (None, 401): if items in (None, 401):
log.error("Could not download metadata, aborting time sync") LOG.error("Could not download metadata, aborting time sync")
return False return False
plextime = None plextime = None
@ -175,14 +175,14 @@ class LibrarySync(Thread):
break break
if plextime is None: if plextime is None:
log.error('Could not get lastViewedAt - aborting') LOG.error('Could not get lastViewedAt - aborting')
return False return False
# Calculate time offset Kodi-PMS # Calculate time offset Kodi-PMS
state.KODI_PLEX_TIME_OFFSET = float(koditime) - float(plextime) state.KODI_PLEX_TIME_OFFSET = float(koditime) - float(plextime)
settings('kodiplextimeoffset', value=str(state.KODI_PLEX_TIME_OFFSET)) settings('kodiplextimeoffset', value=str(state.KODI_PLEX_TIME_OFFSET))
log.info("Time offset Koditime - Plextime in seconds: %s" LOG.info("Time offset Koditime - Plextime in seconds: %s",
% str(state.KODI_PLEX_TIME_OFFSET)) str(state.KODI_PLEX_TIME_OFFSET))
return True return True
def initializeDBs(self): def initializeDBs(self):
@ -231,13 +231,13 @@ class LibrarySync(Thread):
self.new_items_only = True self.new_items_only = True
# This will also update playstates and userratings! # This will also update playstates and userratings!
log.info('Running fullsync for NEW PMS items with repair=%s' % repair) LOG.info('Running fullsync for NEW PMS items with repair=%s', repair)
if self._fullSync() is False: if self._fullSync() is False:
return False return False
self.new_items_only = False self.new_items_only = False
# This will NOT update playstates and userratings! # This will NOT update playstates and userratings!
log.info('Running fullsync for CHANGED PMS items with repair=%s' LOG.info('Running fullsync for CHANGED PMS items with repair=%s',
% repair) repair)
if self._fullSync() is False: if self._fullSync() is False:
return False return False
return True return True
@ -309,7 +309,7 @@ class LibrarySync(Thread):
current_viewtype = view[1] current_viewtype = view[1]
current_tagid = view[2] current_tagid = view[2]
except TypeError: except TypeError:
log.info("Creating viewid: %s in Plex database." % folderid) LOG.info("Creating viewid: %s in Plex database.", folderid)
tagid = kodi_db.createTag(foldername) tagid = kodi_db.createTag(foldername)
# Create playlist for the video library # Create playlist for the video library
if (foldername not in playlists and if (foldername not in playlists and
@ -329,7 +329,7 @@ class LibrarySync(Thread):
# Add view to plex database # Add view to plex database
plex_db.addView(folderid, foldername, viewtype, tagid) plex_db.addView(folderid, foldername, viewtype, tagid)
else: else:
log.info(' '.join(( LOG.info(' '.join((
"Found viewid: %s" % folderid, "Found viewid: %s" % folderid,
"viewname: %s" % current_viewname, "viewname: %s" % current_viewname,
"viewtype: %s" % current_viewtype, "viewtype: %s" % current_viewtype,
@ -344,8 +344,7 @@ class LibrarySync(Thread):
# View was modified, update with latest info # View was modified, update with latest info
if current_viewname != foldername: if current_viewname != foldername:
log.info("viewid: %s new viewname: %s" LOG.info("viewid: %s new viewname: %s", folderid, foldername)
% (folderid, foldername))
tagid = kodi_db.createTag(foldername) tagid = kodi_db.createTag(foldername)
# Update view with new info # Update view with new info
@ -431,7 +430,7 @@ class LibrarySync(Thread):
try: try:
sections.attrib sections.attrib
except AttributeError: except AttributeError:
log.error("Error download PMS views, abort maintainViews") LOG.error("Error download PMS views, abort maintainViews")
return False return False
# For whatever freaking reason, .copy() or dict() does NOT work?!?!?! # For whatever freaking reason, .copy() or dict() does NOT work?!?!?!
@ -454,7 +453,7 @@ class LibrarySync(Thread):
if (itemType in if (itemType in
(v.PLEX_TYPE_MOVIE, v.PLEX_TYPE_SHOW, v.PLEX_TYPE_PHOTO)): (v.PLEX_TYPE_MOVIE, v.PLEX_TYPE_SHOW, v.PLEX_TYPE_PHOTO)):
self.sorted_views.append(view.attrib['title']) self.sorted_views.append(view.attrib['title'])
log.debug('Sorted views: %s' % self.sorted_views) LOG.debug('Sorted views: %s', self.sorted_views)
# total nodes for window properties # total nodes for window properties
vnodes.clearProperties() vnodes.clearProperties()
@ -497,11 +496,11 @@ class LibrarySync(Thread):
# update views for all: # update views for all:
with plexdb.Get_Plex_DB() as plex_db: with plexdb.Get_Plex_DB() as plex_db:
self.views = plex_db.getAllViewInfo() self.views = plex_db.getAllViewInfo()
log.info("Finished processing views. Views saved: %s" % self.views) LOG.info("Finished processing views. Views saved: %s", self.views)
return True return True
def delete_views(self): def delete_views(self):
log.info("Removing views: %s" % self.old_views) LOG.info("Removing views: %s", self.old_views)
delete_items = [] delete_items = []
with plexdb.Get_Plex_DB() as plex_db: with plexdb.Get_Plex_DB() as plex_db:
for view in self.old_views: for view in self.old_views:
@ -642,14 +641,14 @@ class LibrarySync(Thread):
showProgress If False, NEVER shows sync progress showProgress If False, NEVER shows sync progress
""" """
# Some logging, just in case. # Some logging, just in case.
log.debug("self.updatelist: %s" % self.updatelist) LOG.debug("self.updatelist: %s", self.updatelist)
itemNumber = len(self.updatelist) itemNumber = len(self.updatelist)
if itemNumber == 0: if itemNumber == 0:
return return
# Run through self.updatelist, get XML metadata per item # Run through self.updatelist, get XML metadata per item
# Initiate threads # Initiate threads
log.info("Starting sync threads") LOG.info("Starting sync threads")
getMetadataQueue = Queue.Queue() getMetadataQueue = Queue.Queue()
processMetadataQueue = Queue.Queue(maxsize=100) processMetadataQueue = Queue.Queue(maxsize=100)
# To keep track # To keep track
@ -667,7 +666,7 @@ class LibrarySync(Thread):
thread.setDaemon(True) thread.setDaemon(True)
thread.start() thread.start()
threads.append(thread) threads.append(thread)
log.info("%s download threads spawned" % len(threads)) LOG.info("%s download threads spawned", len(threads))
# Spawn one more thread to process Metadata, once downloaded # Spawn one more thread to process Metadata, once downloaded
thread = Threaded_Process_Metadata(processMetadataQueue, thread = Threaded_Process_Metadata(processMetadataQueue,
itemType) itemType)
@ -686,21 +685,21 @@ class LibrarySync(Thread):
getMetadataQueue.join() getMetadataQueue.join()
processMetadataQueue.join() processMetadataQueue.join()
# Kill threads # Kill threads
log.info("Waiting to kill threads") LOG.debug("Waiting to kill threads")
for thread in threads: for thread in threads:
# Threads might already have quit by themselves (e.g. Kodi exit) # Threads might already have quit by themselves (e.g. Kodi exit)
try: try:
thread.stop() thread.stop()
except AttributeError: except AttributeError:
pass pass
log.debug("Stop sent to all threads") LOG.debug("Stop sent to all threads")
# Wait till threads are indeed dead # Wait till threads are indeed dead
for thread in threads: for thread in threads:
try: try:
thread.join(1.0) thread.join(1.0)
except: except:
pass pass
log.info("Sync threads finished") LOG.debug("Sync threads finished")
if (settings('FanartTV') == 'true' and if (settings('FanartTV') == 'true' and
itemType in ('Movies', 'TVShows')): itemType in ('Movies', 'TVShows')):
for item in self.updatelist: for item in self.updatelist:
@ -720,7 +719,7 @@ class LibrarySync(Thread):
itemType = 'Movies' itemType = 'Movies'
views = [x for x in self.views if x['itemtype'] == v.KODI_TYPE_MOVIE] views = [x for x in self.views if x['itemtype'] == v.KODI_TYPE_MOVIE]
log.info("Processing Plex %s. Libraries: %s" % (itemType, views)) LOG.info("Processing Plex %s. Libraries: %s", itemType, views)
self.allKodiElementsId = {} self.allKodiElementsId = {}
if self.compare: if self.compare:
@ -745,7 +744,7 @@ class LibrarySync(Thread):
viewName = view['name'] viewName = view['name']
all_plexmovies = GetPlexSectionResults(viewId, args=None) all_plexmovies = GetPlexSectionResults(viewId, args=None)
if all_plexmovies is None: if all_plexmovies is None:
log.info("Couldnt get section items, aborting for view.") LOG.info("Couldnt get section items, aborting for view.")
continue continue
elif all_plexmovies == 401: elif all_plexmovies == 401:
return False return False
@ -769,7 +768,7 @@ class LibrarySync(Thread):
for kodimovie in self.allKodiElementsId: for kodimovie in self.allKodiElementsId:
if kodimovie not in self.allPlexElementsId: if kodimovie not in self.allPlexElementsId:
Movie.remove(kodimovie) Movie.remove(kodimovie)
log.info("%s sync is finished." % itemType) LOG.info("%s sync is finished.", itemType)
return True return True
def PlexUpdateWatched(self, viewId, itemType, def PlexUpdateWatched(self, viewId, itemType,
@ -790,9 +789,9 @@ class LibrarySync(Thread):
try: try:
xml[0].attrib xml[0].attrib
except (TypeError, AttributeError, IndexError): except (TypeError, AttributeError, IndexError):
log.error('Error updating watch status. Could not get viewId: ' LOG.error('Error updating watch status. Could not get viewId: '
'%s of itemType %s with lastViewedAt: %s, updatedAt: ' '%s of itemType %s with lastViewedAt: %s, updatedAt: '
'%s' % (viewId, itemType, lastViewedAt, updatedAt)) '%s', viewId, itemType, lastViewedAt, updatedAt)
return return
if itemType in ('Movies', 'TVShows'): if itemType in ('Movies', 'TVShows'):
@ -811,7 +810,7 @@ class LibrarySync(Thread):
itemType = 'TVShows' itemType = 'TVShows'
views = [x for x in self.views if x['itemtype'] == 'show'] views = [x for x in self.views if x['itemtype'] == 'show']
log.info("Media folders for %s: %s" % (itemType, views)) LOG.info("Media folders for %s: %s", itemType, views)
self.allKodiElementsId = {} self.allKodiElementsId = {}
if self.compare: if self.compare:
@ -839,7 +838,7 @@ class LibrarySync(Thread):
viewName = view['name'] viewName = view['name']
allPlexTvShows = GetPlexSectionResults(viewId) allPlexTvShows = GetPlexSectionResults(viewId)
if allPlexTvShows is None: if allPlexTvShows is None:
log.error("Error downloading show xml for view %s" % viewId) LOG.error("Error downloading show xml for view %s", viewId)
continue continue
elif allPlexTvShows == 401: elif allPlexTvShows == 401:
return False return False
@ -849,14 +848,14 @@ class LibrarySync(Thread):
'add_update', 'add_update',
viewName, viewName,
viewId) viewId)
log.debug("Analyzed view %s with ID %s" % (viewName, viewId)) LOG.debug("Analyzed view %s with ID %s", viewName, viewId)
# COPY for later use # COPY for later use
allPlexTvShowsId = self.allPlexElementsId.copy() allPlexTvShowsId = self.allPlexElementsId.copy()
# Process self.updatelist # Process self.updatelist
self.GetAndProcessXMLs(itemType) self.GetAndProcessXMLs(itemType)
log.debug("GetAndProcessXMLs completed for tv shows") LOG.debug("GetAndProcessXMLs completed for tv shows")
# PROCESS TV Seasons ##### # PROCESS TV Seasons #####
# Cycle through tv shows # Cycle through tv shows
@ -866,7 +865,7 @@ class LibrarySync(Thread):
# Grab all seasons to tvshow from PMS # Grab all seasons to tvshow from PMS
seasons = GetAllPlexChildren(tvShowId) seasons = GetAllPlexChildren(tvShowId)
if seasons is None: if seasons is None:
log.error("Error download season xml for show %s" % tvShowId) LOG.error("Error download season xml for show %s", tvShowId)
continue continue
elif seasons == 401: elif seasons == 401:
return False return False
@ -876,12 +875,12 @@ class LibrarySync(Thread):
'add_updateSeason', 'add_updateSeason',
viewName, viewName,
viewId) viewId)
log.debug("Analyzed all seasons of TV show with Plex Id %s" LOG.debug("Analyzed all seasons of TV show with Plex Id %s",
% tvShowId) tvShowId)
# Process self.updatelist # Process self.updatelist
self.GetAndProcessXMLs(itemType) self.GetAndProcessXMLs(itemType)
log.debug("GetAndProcessXMLs completed for seasons") LOG.debug("GetAndProcessXMLs completed for seasons")
# PROCESS TV Episodes ##### # PROCESS TV Episodes #####
# Cycle through tv shows # Cycle through tv shows
@ -891,8 +890,8 @@ class LibrarySync(Thread):
# Grab all episodes to tvshow from PMS # Grab all episodes to tvshow from PMS
episodes = GetAllPlexLeaves(view['id']) episodes = GetAllPlexLeaves(view['id'])
if episodes is None: if episodes is None:
log.error("Error downloading episod xml for view %s" LOG.error("Error downloading episod xml for view %s",
% view.get('name')) view.get('name'))
continue continue
elif episodes == 401: elif episodes == 401:
return False return False
@ -902,22 +901,22 @@ class LibrarySync(Thread):
'add_updateEpisode', 'add_updateEpisode',
viewName, viewName,
viewId) viewId)
log.debug("Analyzed all episodes of TV show with Plex Id %s" LOG.debug("Analyzed all episodes of TV show with Plex Id %s",
% view['id']) view['id'])
# Process self.updatelist # Process self.updatelist
self.GetAndProcessXMLs(itemType) self.GetAndProcessXMLs(itemType)
log.debug("GetAndProcessXMLs completed for episodes") LOG.debug("GetAndProcessXMLs completed for episodes")
# Refresh season info # Refresh season info
# Cycle through tv shows # Cycle through tv shows
with itemtypes.TVShows() as TVshow: with itemtypes.TVShows() as TVshow:
for tvShowId in allPlexTvShowsId: for tvShowId in allPlexTvShowsId:
XMLtvshow = GetPlexMetadata(tvShowId) XMLtvshow = GetPlexMetadata(tvShowId)
if XMLtvshow is None or XMLtvshow == 401: if XMLtvshow is None or XMLtvshow == 401:
log.error('Could not download XMLtvshow') LOG.error('Could not download XMLtvshow')
continue continue
TVshow.refreshSeasonEntry(XMLtvshow, tvShowId) TVshow.refreshSeasonEntry(XMLtvshow, tvShowId)
log.debug("Season info refreshed") LOG.debug("Season info refreshed")
# Update viewstate: # Update viewstate:
for view in views: for view in views:
@ -931,7 +930,7 @@ class LibrarySync(Thread):
for kodiTvElement in self.allKodiElementsId: for kodiTvElement in self.allKodiElementsId:
if kodiTvElement not in self.allPlexElementsId: if kodiTvElement not in self.allPlexElementsId:
TVShow.remove(kodiTvElement) TVShow.remove(kodiTvElement)
log.info("%s sync is finished." % itemType) LOG.info("%s sync is finished.", itemType)
return True return True
@log_time @log_time
@ -939,7 +938,7 @@ class LibrarySync(Thread):
itemType = 'Music' itemType = 'Music'
views = [x for x in self.views if x['itemtype'] == v.PLEX_TYPE_ARTIST] views = [x for x in self.views if x['itemtype'] == v.PLEX_TYPE_ARTIST]
log.info("Media folders for %s: %s" % (itemType, views)) LOG.info("Media folders for %s: %s", itemType, views)
methods = { methods = {
v.PLEX_TYPE_ARTIST: 'add_updateArtist', v.PLEX_TYPE_ARTIST: 'add_updateArtist',
@ -960,7 +959,7 @@ class LibrarySync(Thread):
v.PLEX_TYPE_SONG): v.PLEX_TYPE_SONG):
if self.stopped() or self.suspended(): if self.stopped() or self.suspended():
return False return False
log.debug("Start processing music %s" % kind) LOG.debug("Start processing music %s", kind)
self.allKodiElementsId = {} self.allKodiElementsId = {}
self.allPlexElementsId = {} self.allPlexElementsId = {}
self.updatelist = [] self.updatelist = []
@ -969,9 +968,9 @@ class LibrarySync(Thread):
urlArgs[kind], urlArgs[kind],
methods[kind]) is False: methods[kind]) is False:
return False return False
log.debug("Processing of music %s done" % kind) LOG.debug("Processing of music %s done", kind)
self.GetAndProcessXMLs(itemType) self.GetAndProcessXMLs(itemType)
log.debug("GetAndProcessXMLs for music %s completed" % kind) LOG.debug("GetAndProcessXMLs for music %s completed", kind)
# Update viewstate for EVERY item # Update viewstate for EVERY item
for view in views: for view in views:
@ -983,7 +982,7 @@ class LibrarySync(Thread):
self.allKodiElementsId = {} self.allKodiElementsId = {}
self.allPlexElementsId = {} self.allPlexElementsId = {}
self.updatelist = [] self.updatelist = []
log.info("%s sync is finished." % itemType) LOG.info("%s sync is finished.", itemType)
return True return True
def ProcessMusic(self, views, kind, urlArgs, method): def ProcessMusic(self, views, kind, urlArgs, method):
@ -1007,7 +1006,7 @@ class LibrarySync(Thread):
# Get items per view # Get items per view
itemsXML = GetPlexSectionResults(view['id'], args=urlArgs) itemsXML = GetPlexSectionResults(view['id'], args=urlArgs)
if itemsXML is None: if itemsXML is None:
log.error("Error downloading xml for view %s" % view['id']) LOG.error("Error downloading xml for view %s", view['id'])
continue continue
elif itemsXML == 401: elif itemsXML == 401:
return False return False
@ -1034,20 +1033,20 @@ class LibrarySync(Thread):
try: try:
self.process_playing(message['PlaySessionStateNotification']) self.process_playing(message['PlaySessionStateNotification'])
except KeyError: except KeyError:
log.error('Received invalid PMS message for playstate: %s' LOG.error('Received invalid PMS message for playstate: %s',
% message) message)
elif message['type'] == 'timeline': elif message['type'] == 'timeline':
try: try:
self.process_timeline(message['TimelineEntry']) self.process_timeline(message['TimelineEntry'])
except (KeyError, ValueError): except (KeyError, ValueError):
log.error('Received invalid PMS message for timeline: %s' LOG.error('Received invalid PMS message for timeline: %s',
% message) message)
elif message['type'] == 'activity': elif message['type'] == 'activity':
try: try:
self.process_activity(message['ActivityNotification']) self.process_activity(message['ActivityNotification'])
except KeyError: except KeyError:
log.error('Received invalid PMS message for activity: %s' LOG.error('Received invalid PMS message for activity: %s',
% message) message)
def multi_delete(self, liste, deleteListe): def multi_delete(self, liste, deleteListe):
""" """
@ -1114,8 +1113,8 @@ class LibrarySync(Thread):
# Safety net if we can't process an item # Safety net if we can't process an item
item['attempt'] += 1 item['attempt'] += 1
if item['attempt'] > 3: if item['attempt'] > 3:
log.error('Repeatedly could not process item %s, abort' LOG.error('Repeatedly could not process item %s, abort',
% item) item)
deleteListe.append(i) deleteListe.append(i)
# Get rid of the items we just processed # Get rid of the items we just processed
@ -1124,10 +1123,10 @@ class LibrarySync(Thread):
self.itemsToProcess, deleteListe) self.itemsToProcess, deleteListe)
# Let Kodi know of the change # Let Kodi know of the change
if self.videoLibUpdate is True: if self.videoLibUpdate is True:
log.info("Doing Kodi Video Lib update") LOG.info("Doing Kodi Video Lib update")
xbmc.executebuiltin('UpdateLibrary(video)') xbmc.executebuiltin('UpdateLibrary(video)')
if self.musicLibUpdate is True: if self.musicLibUpdate is True:
log.info("Doing Kodi Music Lib update") LOG.info("Doing Kodi Music Lib update")
xbmc.executebuiltin('UpdateLibrary(music)') xbmc.executebuiltin('UpdateLibrary(music)')
def process_newitems(self, item): def process_newitems(self, item):
@ -1135,9 +1134,9 @@ class LibrarySync(Thread):
try: try:
mediatype = xml[0].attrib['type'] mediatype = xml[0].attrib['type']
except (IndexError, KeyError, TypeError): except (IndexError, KeyError, TypeError):
log.error('Could not download metadata for %s' % item['ratingKey']) LOG.error('Could not download metadata for %s', item['ratingKey'])
return False return False
log.debug("Processing new/updated PMS item: %s" % item['ratingKey']) LOG.debug("Processing new/updated PMS item: %s", item['ratingKey'])
viewtag = xml.attrib.get('librarySectionTitle') viewtag = xml.attrib.get('librarySectionTitle')
viewid = xml.attrib.get('librarySectionID') viewid = xml.attrib.get('librarySectionID')
if mediatype == v.PLEX_TYPE_MOVIE: if mediatype == v.PLEX_TYPE_MOVIE:
@ -1162,14 +1161,14 @@ class LibrarySync(Thread):
def process_deleteditems(self, item): def process_deleteditems(self, item):
if item['type'] == v.PLEX_TYPE_MOVIE: if item['type'] == v.PLEX_TYPE_MOVIE:
log.debug("Removing movie %s" % item['ratingKey']) LOG.debug("Removing movie %s", item['ratingKey'])
self.videoLibUpdate = True self.videoLibUpdate = True
with itemtypes.Movies() as movie: with itemtypes.Movies() as movie:
movie.remove(item['ratingKey']) movie.remove(item['ratingKey'])
elif item['type'] in (v.PLEX_TYPE_SHOW, elif item['type'] in (v.PLEX_TYPE_SHOW,
v.PLEX_TYPE_SEASON, v.PLEX_TYPE_SEASON,
v.PLEX_TYPE_EPISODE): v.PLEX_TYPE_EPISODE):
log.debug("Removing episode/season/show with plex id %s", LOG.debug("Removing episode/season/show with plex id %s",
item['ratingKey']) item['ratingKey'])
self.videoLibUpdate = True self.videoLibUpdate = True
with itemtypes.TVShows() as show: with itemtypes.TVShows() as show:
@ -1177,7 +1176,7 @@ class LibrarySync(Thread):
elif item['type'] in (v.PLEX_TYPE_ARTIST, elif item['type'] in (v.PLEX_TYPE_ARTIST,
v.PLEX_TYPE_ALBUM, v.PLEX_TYPE_ALBUM,
v.PLEX_TYPE_SONG): v.PLEX_TYPE_SONG):
log.debug("Removing song/album/artist %s" % item['ratingKey']) LOG.debug("Removing song/album/artist %s", item['ratingKey'])
self.musicLibUpdate = True self.musicLibUpdate = True
with itemtypes.Music() as music: with itemtypes.Music() as music:
music.remove(item['ratingKey']) music.remove(item['ratingKey'])
@ -1250,7 +1249,7 @@ class LibrarySync(Thread):
with plexdb.Get_Plex_DB() as plex_db: with plexdb.Get_Plex_DB() as plex_db:
kodi_info = plex_db.getItem_byId(plex_id) kodi_info = plex_db.getItem_byId(plex_id)
if kodi_info is None: if kodi_info is None:
log.debug('Plex id %s not synced yet - skipping' % plex_id) LOG.debug('Plex id %s not synced yet - skipping', plex_id)
continue continue
# Have we already added this element? # Have we already added this element?
for existingItem in self.itemsToProcess: for existingItem in self.itemsToProcess:
@ -1299,10 +1298,10 @@ class LibrarySync(Thread):
else: else:
# PMS is ours - get all current sessions # PMS is ours - get all current sessions
self.sessionKeys.update(GetPMSStatus(state.PLEX_TOKEN)) self.sessionKeys.update(GetPMSStatus(state.PLEX_TOKEN))
log.debug('Updated current sessions. They are: %s', LOG.debug('Updated current sessions. They are: %s',
self.sessionKeys) self.sessionKeys)
if sessionKey not in self.sessionKeys: if sessionKey not in self.sessionKeys:
log.info('Session key %s still unknown! Skip ' LOG.info('Session key %s still unknown! Skip '
'playstate update', sessionKey) 'playstate update', sessionKey)
continue continue
# Attach Kodi info to the session # Attach Kodi info to the session
@ -1322,7 +1321,7 @@ class LibrarySync(Thread):
pass pass
elif not (session['userId'] == state.PLEX_USER_ID or elif not (session['userId'] == state.PLEX_USER_ID or
session['username'] == state.PLEX_USERNAME): session['username'] == state.PLEX_USERNAME):
log.debug('Our username %s, userid %s did not match ' LOG.debug('Our username %s, userid %s did not match '
'the session username %s with userid %s', 'the session username %s with userid %s',
state.PLEX_USERNAME, state.PLEX_USERNAME,
state.PLEX_USER_ID, state.PLEX_USER_ID,
@ -1334,7 +1333,7 @@ class LibrarySync(Thread):
if session.get('duration') is None: if session.get('duration') is None:
xml = GetPlexMetadata(plex_id) xml = GetPlexMetadata(plex_id)
if xml in (None, 401): if xml in (None, 401):
log.error('Could not get up-to-date xml for item %s', LOG.error('Could not get up-to-date xml for item %s',
plex_id) plex_id)
continue continue
api = PlexAPI.API(xml[0]) api = PlexAPI.API(xml[0])
@ -1352,7 +1351,7 @@ class LibrarySync(Thread):
try: try:
completed = float(resume) / float(session['duration']) completed = float(resume) / float(session['duration'])
except (ZeroDivisionError, TypeError): except (ZeroDivisionError, TypeError):
log.error('Could not mark playstate for %s and session %s', LOG.error('Could not mark playstate for %s and session %s',
data, session) data, session)
continue continue
if completed >= v.MARK_PLAYED_AT: if completed >= v.MARK_PLAYED_AT:
@ -1365,7 +1364,7 @@ class LibrarySync(Thread):
continue continue
else: else:
mark_played = False mark_played = False
log.debug('Update playstate for user %s with id %s for plex id %s', LOG.debug('Update playstate for user %s with id %s for plex id %s',
state.PLEX_USERNAME, state.PLEX_USER_ID, plex_id) state.PLEX_USERNAME, state.PLEX_USER_ID, plex_id)
item_fkt = getattr(itemtypes, item_fkt = getattr(itemtypes,
v.ITEMTYPE_FROM_KODITYPE[session['kodi_type']]) v.ITEMTYPE_FROM_KODITYPE[session['kodi_type']])
@ -1402,7 +1401,7 @@ class LibrarySync(Thread):
triggered full or repair syncs triggered full or repair syncs
""" """
if state.RUN_LIB_SCAN in ("full", "repair"): if state.RUN_LIB_SCAN in ("full", "repair"):
log.info('Full library scan requested, starting') LOG.info('Full library scan requested, starting')
window('plex_dbScan', value="true") window('plex_dbScan', value="true")
state.DB_SCAN = True state.DB_SCAN = True
if state.RUN_LIB_SCAN == "full": if state.RUN_LIB_SCAN == "full":
@ -1415,7 +1414,7 @@ class LibrarySync(Thread):
self.showKodiNote(lang(39407)) self.showKodiNote(lang(39407))
# Reset views was requested from somewhere else # Reset views was requested from somewhere else
elif state.RUN_LIB_SCAN == "views": elif state.RUN_LIB_SCAN == "views":
log.info('Refresh playlist and nodes requested, starting') LOG.info('Refresh playlist and nodes requested, starting')
window('plex_dbScan', value="true") window('plex_dbScan', value="true")
state.DB_SCAN = True state.DB_SCAN = True
# First remove playlists # First remove playlists
@ -1425,12 +1424,12 @@ class LibrarySync(Thread):
# Kick off refresh # Kick off refresh
if self.maintainViews() is True: if self.maintainViews() is True:
# Ran successfully # Ran successfully
log.info("Refresh playlists/nodes completed") LOG.info("Refresh playlists/nodes completed")
# "Plex playlists/nodes refreshed" # "Plex playlists/nodes refreshed"
self.showKodiNote(lang(39405)) self.showKodiNote(lang(39405))
else: else:
# Failed # Failed
log.error("Refresh playlists/nodes failed") LOG.error("Refresh playlists/nodes failed")
# "Plex playlists/nodes refresh failed" # "Plex playlists/nodes refresh failed"
self.showKodiNote(lang(39406), self.showKodiNote(lang(39406),
icon="error") icon="error")
@ -1464,9 +1463,9 @@ class LibrarySync(Thread):
except Exception as e: except Exception as e:
state.DB_SCAN = False state.DB_SCAN = False
window('plex_dbScan', clear=True) window('plex_dbScan', clear=True)
log.error('LibrarySync thread crashed. Error message: %s' % e) LOG.error('LibrarySync thread crashed. Error message: %s', e)
import traceback import traceback
log.error("Traceback:\n%s" % traceback.format_exc()) LOG.error("Traceback:\n%s", traceback.format_exc())
# Library sync thread has crashed # Library sync thread has crashed
dialog('ok', heading='{plex}', line1=lang(39400)) dialog('ok', heading='{plex}', line1=lang(39400))
raise raise
@ -1490,7 +1489,7 @@ class LibrarySync(Thread):
startupComplete = False startupComplete = False
self.views = [] self.views = []
log.info("---===### Starting LibrarySync ###===---") LOG.info("---===### Starting LibrarySync ###===---")
# Ensure that DBs exist if called for very first time # Ensure that DBs exist if called for very first time
self.initializeDBs() self.initializeDBs()
@ -1505,7 +1504,7 @@ class LibrarySync(Thread):
# Set in service.py # Set in service.py
if stopped(): if stopped():
# Abort was requested while waiting. We should exit # Abort was requested while waiting. We should exit
log.info("###===--- LibrarySync Stopped ---===###") LOG.info("###===--- LibrarySync Stopped ---===###")
return return
xbmc.sleep(1000) xbmc.sleep(1000)
@ -1515,14 +1514,14 @@ class LibrarySync(Thread):
# Verify the validity of the database # Verify the validity of the database
currentVersion = settings('dbCreatedWithVersion') currentVersion = settings('dbCreatedWithVersion')
if not compare_version(currentVersion, v.MIN_DB_VERSION): if not compare_version(currentVersion, v.MIN_DB_VERSION):
log.warn("Db version out of date: %s minimum version " LOG.warn("Db version out of date: %s minimum version "
"required: %s", currentVersion, v.MIN_DB_VERSION) "required: %s", currentVersion, v.MIN_DB_VERSION)
# DB out of date. Proceed to recreate? # DB out of date. Proceed to recreate?
resp = dialog('yesno', resp = dialog('yesno',
heading=lang(29999), heading=lang(29999),
line1=lang(39401)) line1=lang(39401))
if not resp: if not resp:
log.warn("Db version out of date! USER IGNORED!") LOG.warn("Db version out of date! USER IGNORED!")
# PKC may not work correctly until reset # PKC may not work correctly until reset
dialog('ok', dialog('ok',
heading='{plex}', heading='{plex}',
@ -1538,9 +1537,9 @@ class LibrarySync(Thread):
videoDb = v.DB_VIDEO_PATH videoDb = v.DB_VIDEO_PATH
if not exists(try_encode(videoDb)): if not exists(try_encode(videoDb)):
# Database does not exists # Database does not exists
log.error("The current Kodi version is incompatible " LOG.error("The current Kodi version is incompatible "
"to know which Kodi versions are supported.") "to know which Kodi versions are supported.")
log.error('Current Kodi version: %s' % try_decode( LOG.error('Current Kodi version: %s', try_decode(
xbmc.getInfoLabel('System.BuildVersion'))) xbmc.getInfoLabel('System.BuildVersion')))
# "Current Kodi version is unsupported, cancel lib sync" # "Current Kodi version is unsupported, cancel lib sync"
dialog('ok', heading='{plex}', line1=lang(39403)) dialog('ok', heading='{plex}', line1=lang(39403))
@ -1548,7 +1547,7 @@ class LibrarySync(Thread):
# Run start up sync # Run start up sync
state.DB_SCAN = True state.DB_SCAN = True
window('plex_dbScan', value="true") window('plex_dbScan', value="true")
log.info("Db version: %s" % settings('dbCreatedWithVersion')) LOG.info("Db version: %s", settings('dbCreatedWithVersion'))
lastTimeSync = unix_timestamp() lastTimeSync = unix_timestamp()
# Initialize time offset Kodi - PMS # Initialize time offset Kodi - PMS
self.syncPMStime() self.syncPMStime()
@ -1557,32 +1556,32 @@ class LibrarySync(Thread):
# Start getting additional missing artwork # Start getting additional missing artwork
with plexdb.Get_Plex_DB() as plex_db: with plexdb.Get_Plex_DB() as plex_db:
missing_fanart = plex_db.get_missing_fanart() missing_fanart = plex_db.get_missing_fanart()
log.info('Trying to get %s additional fanart' LOG.info('Trying to get %s additional fanart',
% len(missing_fanart)) len(missing_fanart))
for item in missing_fanart: for item in missing_fanart:
self.fanartqueue.put({ self.fanartqueue.put({
'plex_id': item['plex_id'], 'plex_id': item['plex_id'],
'plex_type': item['plex_type'], 'plex_type': item['plex_type'],
'refresh': True 'refresh': True
}) })
log.info('Refreshing video nodes and playlists now') LOG.info('Refreshing video nodes and playlists now')
delete_playlists() delete_playlists()
delete_nodes() delete_nodes()
log.info("Initial start-up full sync starting") LOG.info("Initial start-up full sync starting")
xbmc.executebuiltin('InhibitIdleShutdown(true)') xbmc.executebuiltin('InhibitIdleShutdown(true)')
librarySync = fullSync() librarySync = fullSync()
xbmc.executebuiltin('InhibitIdleShutdown(false)') xbmc.executebuiltin('InhibitIdleShutdown(false)')
window('plex_dbScan', clear=True) window('plex_dbScan', clear=True)
state.DB_SCAN = False state.DB_SCAN = False
if librarySync: if librarySync:
log.info("Initial start-up full sync successful") LOG.info("Initial start-up full sync successful")
startupComplete = True startupComplete = True
settings('SyncInstallRunDone', value="true") settings('SyncInstallRunDone', value="true")
settings("dbCreatedWithVersion", v.ADDON_VERSION) settings("dbCreatedWithVersion", v.ADDON_VERSION)
installSyncDone = True installSyncDone = True
self.force_dialog = False self.force_dialog = False
else: else:
log.error("Initial start-up full sync unsuccessful") LOG.error("Initial start-up full sync unsuccessful")
# Currently no db scan, so we can start a new scan # Currently no db scan, so we can start a new scan
elif state.DB_SCAN is False: elif state.DB_SCAN is False:
@ -1599,11 +1598,11 @@ class LibrarySync(Thread):
if (now - lastSync > state.FULL_SYNC_INTERVALL and if (now - lastSync > state.FULL_SYNC_INTERVALL and
not self.xbmcplayer.isPlaying()): not self.xbmcplayer.isPlaying()):
lastSync = now lastSync = now
log.info('Doing scheduled full library scan') LOG.info('Doing scheduled full library scan')
state.DB_SCAN = True state.DB_SCAN = True
window('plex_dbScan', value="true") window('plex_dbScan', value="true")
if fullSync() is False and not stopped(): if fullSync() is False and not stopped():
log.error('Could not finish scheduled full sync') LOG.error('Could not finish scheduled full sync')
self.force_dialog = True self.force_dialog = True
self.showKodiNote(lang(39410), self.showKodiNote(lang(39410),
icon='error') icon='error')
@ -1614,7 +1613,7 @@ class LibrarySync(Thread):
self.showKodiNote(lang(39407)) self.showKodiNote(lang(39407))
elif now - lastTimeSync > oneDay: elif now - lastTimeSync > oneDay:
lastTimeSync = now lastTimeSync = now
log.info('Starting daily time sync') LOG.info('Starting daily time sync')
state.DB_SCAN = True state.DB_SCAN = True
window('plex_dbScan', value="true") window('plex_dbScan', value="true")
self.syncPMStime() self.syncPMStime()
@ -1650,4 +1649,4 @@ class LibrarySync(Thread):
downloadutils.DownloadUtils().stopSession() downloadutils.DownloadUtils().stopSession()
except: except:
pass pass
log.info("###===--- LibrarySync Stopped ---===###") LOG.info("###===--- LibrarySync Stopped ---===###")