PlexKodiConnect/resources/lib/kodimonitor.py

568 lines
23 KiB
Python
Raw Normal View History

#!/usr/bin/env python
# -*- coding: utf-8 -*-
2017-12-15 03:39:50 +11:00
"""
PKC Kodi Monitoring implementation
"""
from __future__ import absolute_import, division, unicode_literals
2017-09-03 20:46:41 +10:00
from logging import getLogger
2017-01-09 01:03:41 +11:00
from json import loads
import copy
import xbmc
import xbmcgui
2015-12-25 07:07:00 +11:00
2018-10-25 02:17:02 +11:00
from .plex_db import PlexDB
2018-11-09 07:22:16 +11:00
from . import kodi_db
2018-06-22 03:24:37 +10:00
from .downloadutils import DownloadUtils as DU
from . import utils, timing, plex_functions as PF, playback
2018-11-19 00:59:17 +11:00
from . import json_rpc as js, playqueue as PQ, playlist_func as PL
from . import backgroundthread, app, variables as v
2016-01-13 00:14:49 +11:00
2018-06-22 03:24:37 +10:00
LOG = getLogger('PLEX.kodimonitor')
2016-08-31 00:57:47 +10:00
# "Start from beginning", "Play from beginning"
STRINGS = (utils.try_encode(utils.lang(12021)),
utils.try_encode(utils.lang(12023)))
2016-08-31 00:57:47 +10:00
2015-12-25 07:07:00 +11:00
class KodiMonitor(xbmc.Monitor):
2017-12-15 03:39:50 +11:00
"""
PKC implementation of the Kodi Monitor class. Invoke only once.
"""
def __init__(self):
self._already_slept = False
2018-06-22 03:24:37 +10:00
self.hack_replay = None
xbmc.Monitor.__init__(self)
2018-11-19 00:59:17 +11:00
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)
2017-12-15 03:39:50 +11:00
LOG.info("Kodi monitor started.")
2015-12-25 07:07:00 +11:00
def onScanStarted(self, library):
2017-12-15 03:39:50 +11:00
"""
Will be called when Kodi starts scanning the library
"""
LOG.debug("Kodi library scan %s running.", library)
2016-02-20 06:03:06 +11:00
2015-12-25 07:07:00 +11:00
def onScanFinished(self, library):
2017-12-15 03:39:50 +11:00
"""
Will be called when Kodi finished scanning the library
"""
LOG.debug("Kodi library scan %s finished.", library)
2015-12-25 07:07:00 +11:00
def onSettingsChanged(self):
2016-10-23 02:15:10 +11:00
"""
Monitor the PKC settings for changes made by the user
"""
2017-12-15 03:39:50 +11:00
LOG.debug('PKC settings change detected')
# Assume that the user changed something so we can try to reconnect
# app.APP.suspend = False
# app.APP.resume_threads(block=False)
2015-12-25 07:07:00 +11:00
def onNotification(self, sender, method, data):
2017-12-15 03:39:50 +11:00
"""
Called when a bunch of different stuff happens on the Kodi side
"""
2015-12-25 07:07:00 +11:00
if data:
2017-01-09 01:03:41 +11:00
data = loads(data, 'utf-8')
2017-12-15 03:39:50 +11:00
LOG.debug("Method: %s Data: %s", method, data)
2015-12-25 07:07:00 +11:00
2018-06-22 03:24:37 +10:00
# Hack
if not method == 'Player.OnStop':
self.hack_replay = None
2015-12-25 07:07:00 +11:00
if method == "Player.OnPlay":
2018-11-19 00:59:17 +11:00
with app.APP.lock_playqueues:
self.PlayBackStart(data)
2016-04-08 21:51:29 +10:00
elif method == "Player.OnStop":
# Should refresh our video nodes, e.g. on deck
# xbmc.executebuiltin('ReloadSkin()')
2018-06-22 03:24:37 +10:00
if (self.hack_replay and not data.get('end') and
self.hack_replay == data['item']):
# Hack for add-on paths
self.hack_replay = None
2018-11-19 00:59:17 +11:00
with app.APP.lock_playqueues:
self._hack_addon_paths_replay_video()
2018-06-22 03:24:37 +10:00
elif data.get('end'):
with app.APP.lock_playqueues:
_playback_cleanup(ended=True)
else:
2018-11-19 00:59:17 +11:00
with app.APP.lock_playqueues:
_playback_cleanup()
2017-12-21 19:28:06 +11:00
elif method == 'Playlist.OnAdd':
if 'item' in data and data['item'].get('type') == v.KODI_TYPE_SHOW:
# Hitting the "browse" button on tv show info dialog
# Hence show the tv show directly
xbmc.executebuiltin("Dialog.Close(all, true)")
js.activate_window('videos',
'videodb://tvshows/titles/%s/' % data['item']['id'])
2018-11-19 00:59:17 +11:00
with app.APP.lock_playqueues:
self._playlist_onadd(data)
2017-12-21 19:28:06 +11:00
elif method == 'Playlist.OnRemove':
self._playlist_onremove(data)
elif method == 'Playlist.OnClear':
2018-11-19 00:59:17 +11:00
with app.APP.lock_playqueues:
self._playlist_onclear(data)
2015-12-25 07:07:00 +11:00
elif method == "VideoLibrary.OnUpdate":
# Manually marking as watched/unwatched
playcount = data.get('playcount')
item = data.get('item')
2018-01-26 03:15:38 +11:00
if playcount is None or item is None:
return
2015-12-25 07:07:00 +11:00
try:
2018-10-25 02:17:02 +11:00
kodi_id = item['id']
kodi_type = item['type']
2015-12-25 07:07:00 +11:00
except (KeyError, TypeError):
2017-12-15 03:39:50 +11:00
LOG.info("Item is invalid for playstate update.")
2018-01-26 03:15:38 +11:00
return
# Send notification to the server.
2018-10-25 02:17:02 +11:00
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 "
2018-01-26 03:15:38 +11:00
"video library update")
2015-12-25 07:07:00 +11:00
else:
2018-04-09 15:21:47 +10:00
# notify the server
if playcount > 0:
2018-10-25 02:17:02 +11:00
PF.scrobble(db_item['plex_id'], 'watched')
2015-12-25 07:07:00 +11:00
else:
2018-10-25 02:17:02 +11:00
PF.scrobble(db_item['plex_id'], 'unwatched')
2015-12-25 07:07:00 +11:00
elif method == "VideoLibrary.OnRemove":
pass
2016-08-31 00:57:47 +10:00
elif method == "System.OnSleep":
# Connection is going to sleep
2017-12-15 03:39:50 +11:00
LOG.info("Marking the server as offline. SystemOnSleep activated.")
2015-12-25 07:07:00 +11:00
elif method == "System.OnWake":
# Allow network to wake up
self.waitForAbort(10)
app.CONN.online = False
elif method == "GUI.OnScreensaverDeactivated":
2018-06-22 03:24:37 +10:00
if utils.settings('dbSyncScreensaver') == "true":
self.waitForAbort(5)
app.SYNC.run_lib_scan = 'full'
elif method == "System.OnQuit":
2017-12-15 03:39:50 +11:00
LOG.info('Kodi OnQuit detected - shutting down')
2018-11-19 00:59:17 +11:00
app.APP.stop_pkc = True
2018-06-22 03:24:37 +10:00
@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')
2018-11-19 00:59:17 +11:00
old = app.PLAYSTATE.old_player_states[1]
2018-06-22 03:24:37 +10:00
kwargs = {
'plex_id': old['plex_id'],
'plex_type': old['plex_type'],
'path': old['file'],
'resolve': False
}
2018-11-26 17:54:32 +11:00
task = backgroundthread.FunctionAsTask(playback.playback_triage,
2018-11-26 17:56:27 +11:00
None,
2018-11-26 17:54:32 +11:00
**kwargs)
backgroundthread.BGThreader.addTasksToFront([task])
2018-06-22 03:24:37 +10:00
2017-12-21 19:28:06 +11:00
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
2018-11-19 00:59:17 +11:00
old = app.PLAYSTATE.old_player_states[data['playlistid']]
if (not app.SYNC.direct_paths and
2018-06-22 03:24:37 +10:00
data['position'] == 0 and data['playlistid'] == 1 and
2018-03-07 04:23:56 +11:00
not PQ.PLAYQUEUES[data['playlistid']].items and
data['item']['type'] == old['kodi_type'] and
data['item']['id'] == old['kodi_id']):
2018-06-22 03:24:37 +10:00
self.hack_replay = data['item']
2017-12-21 19:28:06 +11:00
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
2017-12-21 19:28:06 +11:00
2019-02-08 23:52:33 +11:00
@staticmethod
def _playlist_onclear(data):
2017-12-21 19:28:06 +11:00
"""
Called if a Kodi playlist is cleared. Example data dict:
{
u'playlistid': 1,
}
"""
2018-03-07 04:23:56 +11:00
playqueue = PQ.PLAYQUEUES[data['playlistid']]
if not playqueue.is_pkc_clear():
playqueue.pkc_edit = True
2018-03-07 04:23:56 +11:00
playqueue.clear(kodi=False)
else:
LOG.debug('Detected PKC clear - ignoring')
2017-12-21 19:28:06 +11:00
2019-02-08 23:52:33 +11:00
@staticmethod
def _get_ids(kodi_id, kodi_type, path):
"""
Returns the tuple (plex_id, plex_type) or (None, None)
"""
2017-12-14 06:14:27 +11:00
# No Kodi id returned by Kodi, even if there is one. Ex: Widgets
plex_id = None
plex_type = None
2017-12-14 06:14:27 +11:00
# If using direct paths and starting playback from a widget
if not kodi_id and kodi_type and path:
2018-11-09 07:22:16 +11:00
kodi_id, _ = kodi_db.kodiid_from_filename(path, kodi_type)
if kodi_id:
2018-10-25 02:17:02 +11:00
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
2018-01-11 06:14:05 +11:00
2018-02-04 02:40:24 +11:00
@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):
2018-05-02 23:34:21 +10:00
PL.add_item_to_plex_playqueue(playqueue, i + 1, kodi_item=item)
2018-02-04 02:40:24 +11:00
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'))
2018-01-11 06:14:05 +11:00
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
2018-01-11 06:14:05 +11:00
# 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
2018-01-23 17:59:53 +11:00
if playerid == -1:
# Kodi might return -1 for "last player"
# Getting the playerid is really a PITA
2018-01-23 17:59:53 +11:00
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:
2019-02-08 23:52:33 +11:00
LOG.error('Coud not get playerid for data %s', data)
return
playqueue = PQ.PLAYQUEUES[playerid]
2018-01-11 06:14:05 +11:00
info = js.get_player_props(playerid)
2018-06-15 00:27:13 +10:00
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)
2018-11-19 00:59:17 +11:00
status = app.PLAYSTATE.player_states[playerid]
2017-12-21 19:28:06 +11:00
try:
2018-01-11 06:14:05 +11:00
item = playqueue.items[pos]
LOG.debug('PKC playqueue item is: %s', item)
2017-12-21 19:28:06 +11:00
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
2018-02-04 00:59:43 +11:00
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')
2018-11-19 00:59:17 +11:00
app.PLAYSTATE.player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
return
2018-05-02 02:08:31 +10:00
item = PL.init_plex_playqueue(playqueue, plex_id=plex_id)
item.file = path
2018-01-11 06:14:05 +11:00
# 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
2018-11-19 00:59:17 +11:00
app.PLAYSTATE.active_players.add(playerid)
2018-01-22 04:31:49 +11:00
status.update(info)
LOG.debug('Set the Plex container_key to: %s', container_key)
2018-02-04 02:16:53 +11:00
status['container_key'] = container_key
2018-01-22 04:31:49 +11:00
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
2018-02-04 02:20:10 +11:00
LOG.debug('Set the player state: %s', status)
2018-01-22 21:20:37 +11:00
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',
2018-11-19 00:59:17 +11:00
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)
2018-11-19 00:59:17 +11:00
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
2018-11-19 00:59:17 +11:00
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
2018-11-19 00:59:17 +11:00
app.PLAYSTATE.player_states[playerid] = copy.deepcopy(app.PLAYSTATE.template)
# As all playback has halted, reset the players that have been active
2018-11-19 00:59:17 +11:00
app.PLAYSTATE.active_players = set()
2018-10-05 03:45:44 +10:00
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
2018-10-25 02:17:02 +11:00
with PlexDB() as plexdb:
2018-11-06 23:50:46 +11:00
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
2018-11-19 00:59:17 +11:00
totaltime = float(timing.kodi_time_to_millis(status['totaltime'])) / 1000
if ended:
progress = 0.99
time = v.IGNORE_SECONDS_AT_START + 1
else:
2018-11-19 00:59:17 +11:00
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']
2018-11-26 17:50:38 +11:00
last_played = timing.kodi_now()
if playcount is None:
LOG.debug('playcount not found, looking it up in the Kodi DB')
2018-11-09 07:22:16 +11:00
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
2018-11-09 07:22:16 +11:00
with kodi_db.KodiVideoDB() as kodidb:
kodidb.set_resume(db_item['kodi_fileid'],
time,
totaltime,
playcount,
last_played)
if 'kodi_fileid_2' in db_item and db_item['kodi_fileid_2']:
# Dirty hack for our episodes
kodidb.set_resume(db_item['kodi_fileid_2'],
time,
totaltime,
playcount,
last_played)
# Hack to force "in progress" widget to appear if it wasn't visible before
2018-11-19 00:59:17 +11:00
if (app.APP.force_reload_skin and
xbmc.getCondVisibility('Window.IsVisible(Home.xml)')):
LOG.debug('Refreshing skin to update widgets')
xbmc.executebuiltin('ReloadSkin()')
2018-11-26 17:56:27 +11:00
task = backgroundthread.FunctionAsTask(_clean_file_table, None)
2018-11-26 17:58:12 +11:00
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(lock=False) 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')
class ContextMonitor(backgroundthread.KillableThread):
"""
Detect the resume dialog for widgets. Could also be used to detect
external players (see Emby implementation)
Let's not register this thread because it won't quit due to
xbmc.getCondVisibility
It should still exit at some point due to xbmc.abortRequested
"""
def run(self):
LOG.info("----===## Starting ContextMonitor ##===----")
# app.APP.register_thread(self)
try:
self._run()
finally:
# app.APP.deregister_thread(self)
LOG.info("##===---- ContextMonitor Stopped ----===##")
def _run(self):
while not self.isCanceled():
# The following function will block if called while PKC should
# exit!
if xbmc.getCondVisibility('Window.IsVisible(DialogContextMenu.xml)'):
if xbmc.getInfoLabel('Control.GetLabel(1002)') in STRINGS:
# Remember that the item IS indeed resumable
control = int(xbmcgui.Window(10106).getFocusId())
app.PLAYSTATE.resume_playback = True if control == 1001 else False
else:
# Different context menu is displayed
app.PLAYSTATE.resume_playback = False
app.APP.monitor.waitForAbort(0.1)