PlexKodiConnect/resources/lib/kodimonitor.py

#!/usr/bin/env python
# -*- coding: utf-8 -*-
"""
PKC Kodi Monitoring implementation
"""
from __future__ import absolute_import, division, unicode_literals
from logging import getLogger
from json import loads
import copy
import xbmc

from .plex_db import PlexDB
from . import kodi_db
from .downloadutils import DownloadUtils as DU
from . import utils, timing, plex_functions as PF, playback
from . import json_rpc as js, playqueue as PQ, playlist_func as PL
from . import backgroundthread, app, variables as v

###############################################################################

LOG = getLogger('PLEX.kodimonitor')

###############################################################################


class KodiMonitor(xbmc.Monitor):
    """
    PKC implementation of the Kodi Monitor class. Invoke only once.
    """
    def __init__(self):
        self._already_slept = False
        self.hack_replay = None
        xbmc.Monitor.__init__(self)
        for playerid in app.PLAYSTATE.player_states:
            app.PLAYSTATE.player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
            app.PLAYSTATE.old_player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
        LOG.info("Kodi monitor started.")

    def onScanStarted(self, library):
        """
        Will be called when Kodi starts scanning the library
        """
        LOG.debug("Kodi library scan %s running.", library)

    def onScanFinished(self, library):
        """
        Will be called when Kodi finished scanning the library
        """
        LOG.debug("Kodi library scan %s finished.", library)

    def onSettingsChanged(self):
        """
        Monitor the PKC settings for changes made by the user
        """
        LOG.debug('PKC settings change detected')
        # Assume that the user changed something so we can try to reconnect
        app.APP.suspend = False

    def onNotification(self, sender, method, data):
        """
        Called when a bunch of different stuff happens on the Kodi side
        """
        if data:
            data = loads(data, 'utf-8')
            LOG.debug("Method: %s Data: %s", method, data)

        # Hack
        if not method == 'Player.OnStop':
            self.hack_replay = None

        if method == "Player.OnPlay":
            app.SYNC.suspend_sync = True
            with app.APP.lock_playqueues:
                self.PlayBackStart(data)
        elif method == "Player.OnStop":
            # Should refresh our video nodes, e.g. on deck
            # xbmc.executebuiltin('ReloadSkin()')
            if (self.hack_replay and not data.get('end') and
                    self.hack_replay == data['item']):
                # Hack for add-on paths
                self.hack_replay = None
                with app.APP.lock_playqueues:
                    self._hack_addon_paths_replay_video()
            elif data.get('end'):
                with app.APP.lock_playqueues:
                    _playback_cleanup(ended=True)
            else:
                with app.APP.lock_playqueues:
                    _playback_cleanup()
            app.SYNC.suspend_sync = False
        elif method == 'Playlist.OnAdd':
            with app.APP.lock_playqueues:
                self._playlist_onadd(data)
        elif method == 'Playlist.OnRemove':
            self._playlist_onremove(data)
        elif method == 'Playlist.OnClear':
            with app.APP.lock_playqueues:
                self._playlist_onclear(data)
        elif method == "VideoLibrary.OnUpdate":
            # Manually marking as watched/unwatched
            playcount = data.get('playcount')
            item = data.get('item')
            if playcount is None or item is None:
                return
            try:
                kodi_id = item['id']
                kodi_type = item['type']
            except (KeyError, TypeError):
                LOG.info("Item is invalid for playstate update.")
                return
            # Send notification to the server.
            with PlexDB() as plexdb:
                db_item = plexdb.item_by_kodi_id(kodi_id, kodi_type)
            if not db_item:
                LOG.error("Could not find plex_id in plex database for a "
                          "video library update")
            else:
                # notify the server
                if playcount > 0:
                    PF.scrobble(db_item['plex_id'], 'watched')
                else:
                    PF.scrobble(db_item['plex_id'], 'unwatched')
        elif method == "VideoLibrary.OnRemove":
            pass
        elif method == "System.OnSleep":
            # Connection is going to sleep
            LOG.info("Marking the server as offline. SystemOnSleep activated.")
        elif method == "System.OnWake":
            # Allow network to wake up
            self.waitForAbort(10)
            app.CONN.online = False
        elif method == "GUI.OnScreensaverDeactivated":
            if utils.settings('dbSyncScreensaver') == "true":
                self.waitForAbort(5)
                app.SYNC.run_lib_scan = 'full'
        elif method == "System.OnQuit":
            LOG.info('Kodi OnQuit detected - shutting down')
            app.APP.stop_pkc = True

    @staticmethod
    def _hack_addon_paths_replay_video():
        """
        Hack we need for RESUMABLE items because Kodi lost the path of the
        last played item that is now being replayed (see playback.py's
        Player().play()) Also see playqueue.py _compare_playqueues()

        Needed if user re-starts the same video from the library using addon
        paths. (Video is only added to playqueue, then immediately stoppen.
        There is no playback initialized by Kodi.) Log excerpts:
          Method: Playlist.OnAdd Data:
              {u'item': {u'type': u'movie', u'id': 4},
               u'playlistid': 1,
               u'position': 0}
          Now we would hack!
          Method: Player.OnStop Data:
              {u'item': {u'type': u'movie', u'id': 4},
               u'end': False}
        (within the same micro-second!)
        """
        LOG.info('Detected re-start of playback of last item')
        old = app.PLAYSTATE.old_player_states[1]
        kwargs = {
            'plex_id': old['plex_id'],
            'plex_type': old['plex_type'],
            'path': old['file'],
            'resolve': False
        }
        task = backgroundthread.FunctionAsTask(playback.playback_triage,
                                               None,
                                               **kwargs)
        backgroundthread.BGThreader.addTasksToFront([task])

    def _playlist_onadd(self, data):
        """
        Called if an item is added to a Kodi playlist. Example data dict:
        {
            u'item': {
                u'type': u'movie',
                u'id': 2},
            u'playlistid': 1,
            u'position': 0
        }
        Will NOT be called if playback initiated by Kodi widgets
        """
        if 'id' not in data['item']:
            return
        old = app.PLAYSTATE.old_player_states[data['playlistid']]
        if (not app.SYNC.direct_paths and
                data['position'] == 0 and data['playlistid'] == 1 and
                not PQ.PLAYQUEUES[data['playlistid']].items and
                data['item']['type'] == old['kodi_type'] and
                data['item']['id'] == old['kodi_id']):
            self.hack_replay = data['item']

    def _playlist_onremove(self, data):
        """
        Called if an item is removed from a Kodi playlist. Example data dict:
        {
            u'playlistid': 1,
            u'position': 0
        }
        """
        pass

    def _playlist_onclear(self, data):
        """
        Called if a Kodi playlist is cleared. Example data dict:
        {
            u'playlistid': 1,
        }
        """
        playqueue = PQ.PLAYQUEUES[data['playlistid']]
        if not playqueue.is_pkc_clear():
            playqueue.pkc_edit = True
            playqueue.clear(kodi=False)
        else:
            LOG.debug('Detected PKC clear - ignoring')

    def _get_ids(self, kodi_id, kodi_type, path):
        """
        Returns the tuple (plex_id, plex_type) or (None, None)
        """
        # No Kodi id returned by Kodi, even if there is one. Ex: Widgets
        plex_id = None
        plex_type = None
        # If using direct paths and starting playback from a widget
        if not kodi_id and kodi_type and path:
            kodi_id, _ = kodi_db.kodiid_from_filename(path, kodi_type)
        if kodi_id:
            with PlexDB() as plexdb:
                db_item = plexdb.item_by_kodi_id(kodi_id, kodi_type)
            if db_item:
                plex_id = db_item['plex_id']
                plex_type = db_item['plex_type']
        return plex_id, plex_type

    @staticmethod
    def _add_remaining_items_to_playlist(playqueue):
        """
        Adds all but the very first item of the Kodi playlist to the Plex
        playqueue
        """
        items = js.playlist_get_items(playqueue.playlistid)
        if not items:
            LOG.error('Could not retrieve Kodi playlist items')
            return
        # Remove first item
        items.pop(0)
        try:
            for i, item in enumerate(items):
                PL.add_item_to_plex_playqueue(playqueue, i + 1, kodi_item=item)
        except PL.PlaylistError:
            LOG.info('Could not build Plex playlist for: %s', items)

    def _json_item(self, playerid):
        """
        Uses JSON RPC to get the playing item's info and returns the tuple
            kodi_id, kodi_type, path
        or None each time if not found.
        """
        if not self._already_slept:
            # SLEEP before calling this for the first time just after playback
            # start as Kodi updates this info very late!! Might get previous
            # element otherwise
            self._already_slept = True
            self.waitForAbort(1)
        try:
            json_item = js.get_item(playerid)
        except KeyError:
            LOG.debug('No playing item returned by Kodi')
            return None, None, None
        LOG.debug('Kodi playing item properties: %s', json_item)
        return (json_item.get('id'),
                json_item.get('type'),
                json_item.get('file'))

    def PlayBackStart(self, data):
        """
        Called whenever playback is started. Example data:
        {
            u'item': {u'type': u'movie', u'title': u''},
            u'player': {u'playerid': 1, u'speed': 1}
        }
        Unfortunately when using Widgets, Kodi doesn't tell us shit
        """
        self._already_slept = False
        # Get the type of media we're playing
        try:
            playerid = data['player']['playerid']
        except (TypeError, KeyError):
            LOG.info('Aborting playback report - item invalid for updates %s',
                     data)
            return
        kodi_id = data['item'].get('id') if 'item' in data else None
        kodi_type = data['item'].get('type') if 'item' in data else None
        path = data['item'].get('file') if 'item' in data else None
        if playerid == -1:
            # Kodi might return -1 for "last player"
            # Getting the playerid is really a PITA
            try:
                playerid = js.get_player_ids()[0]
            except IndexError:
                # E.g. Kodi 18 doesn't tell us anything useful
                if kodi_type in v.KODI_VIDEOTYPES:
                    playlist_type = v.KODI_TYPE_VIDEO_PLAYLIST
                elif kodi_type in v.KODI_AUDIOTYPES:
                    playlist_type = v.KODI_TYPE_AUDIO_PLAYLIST
                else:
                    LOG.error('Unexpected type %s, data %s', kodi_type, data)
                    return
                playerid = js.get_playlist_id(playlist_type)
                if not playerid:
                    LOG.error('Coud not get playerid for data', data)
                    return
        playqueue = PQ.PLAYQUEUES[playerid]
        info = js.get_player_props(playerid)
        if playqueue.kodi_playlist_playback:
            # Kodi will tell us the wrong position - of the playlist, not the
            # playqueue, when user starts playing from a playlist :-(
            pos = 0
            LOG.debug('Detected playback from a Kodi playlist')
        else:
            pos = info['position'] if info['position'] != -1 else 0
            LOG.debug('Detected position %s for %s', pos, playqueue)
        status = app.PLAYSTATE.player_states[playerid]
        try:
            item = playqueue.items[pos]
            LOG.debug('PKC playqueue item is: %s', item)
        except IndexError:
            # PKC playqueue not yet initialized
            LOG.debug('Position %s not in PKC playqueue yet', pos)
            initialize = True
        else:
            if not kodi_id:
                kodi_id, kodi_type, path = self._json_item(playerid)
            if kodi_id and item.kodi_id:
                if item.kodi_id != kodi_id or item.kodi_type != kodi_type:
                    LOG.debug('Detected different Kodi id')
                    initialize = True
                else:
                    initialize = False
            else:
                # E.g. clips set-up previously with no Kodi DB entry
                if not path:
                    kodi_id, kodi_type, path = self._json_item(playerid)
                if path == '':
                    LOG.debug('Detected empty path: aborting playback report')
                    return
                if item.file != path:
                    # Clips will get a new path
                    LOG.debug('Detected different path')
                    try:
                        tmp_plex_id = int(utils.REGEX_PLEX_ID.findall(path)[0])
                    except IndexError:
                        LOG.debug('No Plex id in path, need to init playqueue')
                        initialize = True
                    else:
                        if tmp_plex_id == item.plex_id:
                            LOG.debug('Detected different path for the same id')
                            initialize = False
                        else:
                            LOG.debug('Different Plex id, need to init playqueue')
                            initialize = True
                else:
                    initialize = False
        if initialize:
            LOG.debug('Need to initialize Plex and PKC playqueue')
            if not kodi_id or not kodi_type:
                kodi_id, kodi_type, path = self._json_item(playerid)
            plex_id, plex_type = self._get_ids(kodi_id, kodi_type, path)
            if not plex_id:
                LOG.debug('No Plex id obtained - aborting playback report')
                app.PLAYSTATE.player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
                return
            item = PL.init_plex_playqueue(playqueue, plex_id=plex_id)
            item.file = path
            # Set the Plex container key (e.g. using the Plex playqueue)
            container_key = None
            if info['playlistid'] != -1:
                # -1 is Kodi's answer if there is no playlist
                container_key = PQ.PLAYQUEUES[playerid].id
            if container_key is not None:
                container_key = '/playQueues/%s' % container_key
            elif plex_id is not None:
                container_key = '/library/metadata/%s' % plex_id
        else:
            LOG.debug('No need to initialize playqueues')
            kodi_id = item.kodi_id
            kodi_type = item.kodi_type
            plex_id = item.plex_id
            plex_type = item.plex_type
            if playqueue.id:
                container_key = '/playQueues/%s' % playqueue.id
            else:
                container_key = '/library/metadata/%s' % plex_id
        # Remember that this player has been active
        app.PLAYSTATE.active_players.add(playerid)
        status.update(info)
        LOG.debug('Set the Plex container_key to: %s', container_key)
        status['container_key'] = container_key
        status['file'] = path
        status['kodi_id'] = kodi_id
        status['kodi_type'] = kodi_type
        status['plex_id'] = plex_id
        status['plex_type'] = plex_type
        status['playmethod'] = item.playmethod
        status['playcount'] = item.playcount
        LOG.debug('Set the player state: %s', status)


def _playback_cleanup(ended=False):
    """
    PKC cleanup after playback ends/is stopped. Pass ended=True if Kodi
    completely finished playing an item (because we will get and use wrong
    timing data otherwise)
    """
    LOG.debug('playback_cleanup called. Active players: %s',
              app.PLAYSTATE.active_players)
    # We might have saved a transient token from a user flinging media via
    # Companion (if we could not use the playqueue to store the token)
    app.CONN.plex_transient_token = None
    for playerid in app.PLAYSTATE.active_players:
        status = app.PLAYSTATE.player_states[playerid]
        # Remember the last played item later
        app.PLAYSTATE.old_player_states[playerid] = copy.deepcopy(status)
        # Stop transcoding
        if status['playmethod'] == 'Transcode':
            LOG.debug('Tell the PMS to stop transcoding')
            DU().downloadUrl(
                '{server}/video/:/transcode/universal/stop',
                parameters={'session': v.PKC_MACHINE_IDENTIFIER})
        if playerid == 1:
            # Bookmarks might not be pickup up correctly, so let's do them
            # manually. Applies to addon paths, but direct paths might have
            # started playback via PMS
            _record_playstate(status, ended)
        # Reset the player's status
        app.PLAYSTATE.player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
    # As all playback has halted, reset the players that have been active
    app.PLAYSTATE.active_players = set()
    LOG.info('Finished PKC playback cleanup')


def _record_playstate(status, ended):
    if not status['plex_id']:
        LOG.debug('No Plex id found to record playstate for status %s', status)
        return
    with PlexDB() as plexdb:
        db_item = plexdb.item_by_id(status['plex_id'], status['plex_type'])
    if not db_item:
        # Item not (yet) in Kodi library
        LOG.debug('No playstate update due to Plex id not found: %s', status)
        return
    totaltime = float(timing.kodi_time_to_millis(status['totaltime'])) / 1000
    if ended:
        progress = 0.99
        time = v.IGNORE_SECONDS_AT_START + 1
    else:
        time = float(timing.kodi_time_to_millis(status['time'])) / 1000
        try:
            progress = time / totaltime
        except ZeroDivisionError:
            progress = 0.0
        LOG.debug('Playback progress %s (%s of %s seconds)',
                  progress, time, totaltime)
    playcount = status['playcount']
    last_played = timing.kodi_now()
    if playcount is None:
        LOG.debug('playcount not found, looking it up in the Kodi DB')
        with kodi_db.KodiVideoDB() as kodidb:
            playcount = kodidb.get_playcount(db_item['kodi_fileid'])
        playcount = 0 if playcount is None else playcount
    if time < v.IGNORE_SECONDS_AT_START:
        LOG.debug('Ignoring playback less than %s seconds',
                  v.IGNORE_SECONDS_AT_START)
        # Annoying Plex bug - it'll reset an already watched video to unwatched
        playcount = None
        last_played = None
        time = 0
    elif progress >= v.MARK_PLAYED_AT:
        LOG.debug('Recording entirely played video since progress > %s',
                  v.MARK_PLAYED_AT)
        playcount += 1
        time = 0
    with kodi_db.KodiVideoDB() as kodidb:
        kodidb.set_resume(db_item['kodi_fileid'],
                          time,
                          totaltime,
                          playcount,
                          last_played,
                          status['plex_type'])
    # Hack to force "in progress" widget to appear if it wasn't visible before
    if (app.APP.force_reload_skin and
            xbmc.getCondVisibility('Window.IsVisible(Home.xml)')):
        LOG.debug('Refreshing skin to update widgets')
        xbmc.executebuiltin('ReloadSkin()')
    task = backgroundthread.FunctionAsTask(_clean_file_table, None)
    backgroundthread.BGThreader.addTasksToFront([task])


def _clean_file_table():
    """
    If we associate a playing video e.g. pointing to plugin://... to an existing
    Kodi library item, Kodi will add an additional entry for this (additional)
    path plugin:// in the file table. This leads to all sorts of wierd behavior.
    This function tries for at most 5 seconds to clean the file table.
    """
    LOG.debug('Start cleaning Kodi files table')
    app.APP.monitor.waitForAbort(2)
    try:
        with kodi_db.KodiVideoDB() as kodidb_1:
            with kodi_db.KodiVideoDB() as kodidb_2:
                for file_id in kodidb_1.obsolete_file_ids():
                    LOG.debug('Removing obsolete Kodi file_id %s', file_id)
                    kodidb_2.remove_file(file_id, remove_orphans=False)
    except utils.OperationalError:
        LOG.debug('Database was locked, unable to clean file table')
    else:
        LOG.debug('Done cleaning up Kodi file table')