Update logging

Use the logging module. Moved logging to it's own file.
This commit is contained in:
angelblue05 2016-07-24 03:59:48 -05:00
parent 380fcdfc35
commit 76dfa1286c
26 changed files with 689 additions and 646 deletions

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import os
import sys
import urlparse
@ -21,8 +22,14 @@ sys.path.append(_base_resource)
import entrypoint
import utils
from utils import Logging, window, language as lang
log = Logging('Default').log
from utils import window, language as lang
#################################################################################################
import loghandler
loghandler.config()
log = logging.getLogger("EMBY.default")
#################################################################################################
@ -37,7 +44,7 @@ class Main():
# Parse parameters
base_url = sys.argv[0]
params = urlparse.parse_qs(sys.argv[2][1:])
log("Parameter string: %s" % sys.argv[2], 0)
log.warn("Parameter string: %s" % sys.argv[2])
try:
mode = params['mode'][0]
itemid = params.get('id')
@ -113,7 +120,7 @@ class Main():
# Server is not online, do not run the sync
xbmcgui.Dialog().ok(heading=lang(29999),
line1=lang(33034))
log("Not connected to the emby server.", 1)
log.warn("Not connected to the emby server.")
return
if window('emby_dbScan') != "true":
@ -126,7 +133,7 @@ class Main():
else:
lib.fullSync(repair=True)
else:
log("Database scan is already running.", 1)
log.warn("Database scan is already running.")
elif mode == "texturecache":
import artwork
@ -137,6 +144,6 @@ class Main():
if __name__ == "__main__":
log('plugin.video.emby started', 1)
log.info('plugin.video.emby started')
Main()
log('plugin.video.emby stopped', 1)
log.info('plugin.video.emby stopped')

View file

@ -4,8 +4,12 @@
##################################################################################################
import clientinfo
from utils import Logging, settings
import logging
from utils import settings
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
@ -13,17 +17,10 @@ from utils import Logging, settings
class API():
def __init__(self, item):
global log
log = Logging(self.__class__.__name__).log
# item is the api response
self.item = item
self.clientinfo = clientinfo.ClientInfo()
self.addonName = self.clientinfo.getAddonName()
def getUserData(self):
# Default
favorite = False

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import requests
import os
import urllib
@ -12,11 +13,14 @@ import xbmc
import xbmcgui
import xbmcvfs
import clientinfo
import image_cache_thread
from utils import Logging, window, settings, language as lang, kodiSQL
from utils import window, settings, language as lang, kodiSQL
#################################################################################################
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
class Artwork():
@ -32,16 +36,10 @@ class Artwork():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.clientinfo = clientinfo.ClientInfo()
self.addonName = self.clientinfo.getAddonName()
self.enableTextureCache = settings('enableTextureCache') == "true"
self.imageCacheLimitThreads = int(settings('imageCacheLimit'))
self.imageCacheLimitThreads = int(self.imageCacheLimitThreads * 5)
log("Using Image Cache Thread Count: %s" % self.imageCacheLimitThreads, 1)
log.info("Using Image Cache Thread Count: %s" % self.imageCacheLimitThreads)
if not self.xbmc_port and self.enableTextureCache:
self.setKodiWebServerDetails()
@ -175,14 +173,14 @@ class Artwork():
line1=lang(33042)):
return
log("Doing Image Cache Sync", 1)
log.info("Doing Image Cache Sync")
pdialog = xbmcgui.DialogProgress()
pdialog.create(lang(29999), lang(33043))
# ask to rest all existing or not
if dialog.yesno(lang(29999), lang(33044)):
log("Resetting all cache data first.", 1)
log.info("Resetting all cache data first.")
# Remove all existing textures first
path = xbmc.translatePath('special://thumbnails/').decode('utf-8')
@ -215,7 +213,7 @@ class Artwork():
cursor.execute("SELECT url FROM art WHERE media_type != 'actor'") # dont include actors
result = cursor.fetchall()
total = len(result)
log("Image cache sync about to process %s images" % total, 1)
log.info("Image cache sync about to process %s images" % total)
cursor.close()
count = 0
@ -236,7 +234,7 @@ class Artwork():
cursor.execute("SELECT url FROM art")
result = cursor.fetchall()
total = len(result)
log("Image cache sync about to process %s images" % total, 1)
log.info("Image cache sync about to process %s images" % total)
cursor.close()
count = 0
@ -252,14 +250,14 @@ class Artwork():
count += 1
pdialog.update(100, "%s %s" % (lang(33046), len(self.imageCacheThreads)))
log("Waiting for all threads to exit", 1)
log.info("Waiting for all threads to exit")
while len(self.imageCacheThreads):
for thread in self.imageCacheThreads:
if thread.isFinished:
self.imageCacheThreads.remove(thread)
pdialog.update(100, "%s %s" % (lang(33046), len(self.imageCacheThreads)))
log("Waiting for all threads to exit: %s" % len(self.imageCacheThreads), 1)
log.info("Waiting for all threads to exit: %s" % len(self.imageCacheThreads))
xbmc.sleep(500)
pdialog.close()
@ -282,13 +280,13 @@ class Artwork():
self.imageCacheThreads.append(newThread)
return
else:
log("Waiting for empty queue spot: %s" % len(self.imageCacheThreads), 2)
log.info("Waiting for empty queue spot: %s" % len(self.imageCacheThreads))
xbmc.sleep(50)
def cacheTexture(self, url):
# Cache a single image url to the texture cache
if url and self.enableTextureCache:
log("Processing: %s" % url, 2)
log.debug("Processing: %s" % url)
if not self.imageCacheLimitThreads:
# Add image to texture cache by simply calling it at the http endpoint
@ -406,7 +404,7 @@ class Artwork():
except TypeError: # Add the artwork
cacheimage = True
log("Adding Art Link for kodiId: %s (%s)" % (kodiId, imageUrl), 2)
log.debug("Adding Art Link for kodiId: %s (%s)" % (kodiId, imageUrl))
query = (
'''
@ -427,8 +425,8 @@ class Artwork():
# Delete current entry before updating with the new one
self.deleteCachedArtwork(url)
log("Updating Art url for %s kodiId: %s (%s) -> (%s)"
% (imageType, kodiId, url, imageUrl), 1)
log.info("Updating Art url for %s kodiId: %s (%s) -> (%s)"
% (imageType, kodiId, url, imageUrl))
query = ' '.join((
@ -472,21 +470,21 @@ class Artwork():
cachedurl = cursor.fetchone()[0]
except TypeError:
log("Could not find cached url.", 1)
log.info("Could not find cached url.")
except OperationalError:
log("Database is locked. Skip deletion process.", 1)
log.info("Database is locked. Skip deletion process.")
else: # Delete thumbnail as well as the entry
thumbnails = xbmc.translatePath("special://thumbnails/%s" % cachedurl).decode('utf-8')
log("Deleting cached thumbnail: %s" % thumbnails, 1)
log.info("Deleting cached thumbnail: %s" % thumbnails)
xbmcvfs.delete(thumbnails)
try:
cursor.execute("DELETE FROM texture WHERE url = ?", (url,))
connection.commit()
except OperationalError:
log("Issue deleting url from cache. Skipping.", 2)
log.debug("Issue deleting url from cache. Skipping.")
finally:
cursor.close()

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import os
from uuid import uuid4
@ -9,9 +10,13 @@ import xbmc
import xbmcaddon
import xbmcvfs
from utils import Logging, window, settings
from utils import window, settings
#################################################################################################
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
class ClientInfo():
@ -19,9 +24,6 @@ class ClientInfo():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.addon = xbmcaddon.Addon()
self.addonName = self.getAddonName()
@ -88,14 +90,14 @@ class ClientInfo():
GUID = xbmcvfs.File(GUID_file)
clientId = GUID.read()
if not clientId:
log("Generating a new deviceid...", 1)
log.info("Generating a new deviceid...")
clientId = str("%012X" % uuid4())
GUID = xbmcvfs.File(GUID_file, 'w')
GUID.write(clientId)
GUID.close()
log("DeviceId loaded: %s" % clientId, 1)
log.info("DeviceId loaded: %s" % clientId)
window('emby_deviceId', value=clientId)
return clientId

View file

@ -7,7 +7,7 @@ import requests
import logging
import clientinfo
from utils import Logging, window
from utils import window
##################################################################################################
@ -15,7 +15,8 @@ from utils import Logging, window
from requests.packages.urllib3.exceptions import InsecureRequestWarning, InsecurePlatformWarning
requests.packages.urllib3.disable_warnings(InsecureRequestWarning)
requests.packages.urllib3.disable_warnings(InsecurePlatformWarning)
#logging.getLogger('requests').setLevel(logging.WARNING)
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
@ -25,7 +26,6 @@ class ConnectUtils():
# Borg - multiple instances, shared state
_shared_state = {}
clientInfo = clientinfo.ClientInfo()
addonName = clientInfo.getAddonName()
# Requests session
c = None
@ -34,26 +34,23 @@ class ConnectUtils():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
def setUserId(self, userId):
# Reserved for userclient only
self.userId = userId
log("Set connect userId: %s" % userId, 2)
log.debug("Set connect userId: %s" % userId)
def setServer(self, server):
# Reserved for userclient only
self.server = server
log("Set connect server: %s" % server, 2)
log.debug("Set connect server: %s" % server)
def setToken(self, token):
# Reserved for userclient only
self.token = token
log("Set connect token: %s" % token, 2)
log.debug("Set connect token: %s" % token)
def startSession(self):
@ -71,7 +68,7 @@ class ConnectUtils():
if self.sslclient is not None:
verify = self.sslclient
except:
log("Could not load SSL settings.", 1)
log.info("Could not load SSL settings.")
# Start session
self.c = requests.Session()
@ -81,13 +78,13 @@ class ConnectUtils():
self.c.mount("http://", requests.adapters.HTTPAdapter(max_retries=1))
self.c.mount("https://", requests.adapters.HTTPAdapter(max_retries=1))
log("Requests session started on: %s" % self.server, 1)
log.info("Requests session started on: %s" % self.server)
def stopSession(self):
try:
self.c.close()
except Exception as e:
log("Requests session could not be terminated: %s" % e, 1)
except Exception:
log.warn("Requests session could not be terminated")
def getHeader(self, authenticate=True):
@ -101,7 +98,7 @@ class ConnectUtils():
'Content-type': 'application/x-www-form-urlencoded; charset=UTF-8',
'Accept': "application/json"
}
log("Header: %s" % header, 1)
log.info("Header: %s" % header)
else:
token = self.token
@ -113,14 +110,14 @@ class ConnectUtils():
'X-Application': "Kodi/%s" % version,
'X-Connect-UserToken': token
}
log("Header: %s" % header, 1)
log.info("Header: %s" % header)
return header
def doUrl(self, url, data=None, postBody=None, rtype="GET",
parameters=None, authenticate=True, timeout=None):
log("=== ENTER connectUrl ===", 2)
log.debug("=== ENTER connectUrl ===")
default_link = ""
@ -207,25 +204,25 @@ class ConnectUtils():
verify=verifyssl)
##### THE RESPONSE #####
log(r.url, 1)
log(r, 1)
log.info(r.url)
log.info(r)
if r.status_code == 204:
# No body in the response
log("====== 204 Success ======", 1)
log.info("====== 204 Success ======")
elif r.status_code == requests.codes.ok:
try:
# UNICODE - JSON object
r = r.json()
log("====== 200 Success ======", 1)
log("Response: %s" % r, 1)
log.info("====== 200 Success ======")
log.info("Response: %s" % r)
return r
except:
if r.headers.get('content-type') != "text/html":
log("Unable to convert the response for: %s" % url, 1)
log.info("Unable to convert the response for: %s" % url)
else:
r.raise_for_status()
@ -236,8 +233,7 @@ class ConnectUtils():
pass
except requests.exceptions.ConnectTimeout as e:
log("Server timeout at: %s" % url, 0)
log(e, 1)
log.warn("Server timeout at: %s" % url)
except requests.exceptions.HTTPError as e:
@ -253,11 +249,9 @@ class ConnectUtils():
pass
except requests.exceptions.SSLError as e:
log("Invalid SSL certificate for: %s" % url, 0)
log(e, 1)
log.warn("Invalid SSL certificate for: %s" % url)
except requests.exceptions.RequestException as e:
log("Unknown error connecting to: %s" % url, 0)
log(e, 1)
log.warn("Unknown error connecting to: %s" % url)
return default_link

View file

@ -10,7 +10,7 @@ import xbmc
import xbmcgui
import clientinfo
from utils import Logging, window, settings
from utils import window, settings
##################################################################################################
@ -18,7 +18,8 @@ from utils import Logging, window, settings
from requests.packages.urllib3.exceptions import InsecureRequestWarning, InsecurePlatformWarning
requests.packages.urllib3.disable_warnings(InsecureRequestWarning)
requests.packages.urllib3.disable_warnings(InsecurePlatformWarning)
#logging.getLogger('requests').setLevel(logging.WARNING)
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
@ -36,38 +37,35 @@ class DownloadUtils():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
def setUsername(self, username):
# Reserved for userclient only
self.username = username
log("Set username: %s" % username, 2)
log.debug("Set username: %s" % username)
def setUserId(self, userId):
# Reserved for userclient only
self.userId = userId
log("Set userId: %s" % userId, 2)
log.debug("Set userId: %s" % userId)
def setServer(self, server):
# Reserved for userclient only
self.server = server
log("Set server: %s" % server, 2)
log.debug("Set server: %s" % server)
def setToken(self, token):
# Reserved for userclient only
self.token = token
log("Set token: %s" % token, 2)
log.debug("Set token: %s" % token)
def setSSL(self, ssl, sslclient):
# Reserved for userclient only
self.sslverify = ssl
self.sslclient = sslclient
log("Verify SSL host certificate: %s" % ssl, 2)
log("SSL client side certificate: %s" % sslclient, 2)
log.debug("Verify SSL host certificate: %s" % ssl)
log.debug("SSL client side certificate: %s" % sslclient)
def postCapabilities(self, deviceId):
@ -92,11 +90,11 @@ class DownloadUtils():
)
}
log("Capabilities URL: %s" % url, 2)
log("Postdata: %s" % data, 2)
log.debug("Capabilities URL: %s" % url)
log.debug("Postdata: %s" % data)
self.downloadUrl(url, postBody=data, action_type="POST")
log("Posted capabilities to %s" % self.server, 2)
log.debug("Posted capabilities to %s" % self.server)
# Attempt at getting sessionId
url = "{server}/emby/Sessions?DeviceId=%s&format=json" % deviceId
@ -105,11 +103,11 @@ class DownloadUtils():
sessionId = result[0]['Id']
except (KeyError, TypeError):
log("Failed to retrieve sessionId.", 1)
log.info("Failed to retrieve sessionId.")
else:
log("Session: %s" % result, 2)
log("SessionId: %s" % sessionId, 1)
log.debug("Session: %s" % result)
log.info("SessionId: %s" % sessionId)
window('emby_sessionId', value=sessionId)
# Post any permanent additional users
@ -117,8 +115,7 @@ class DownloadUtils():
if additionalUsers:
additionalUsers = additionalUsers.split(',')
log("List of permanent users added to the session: %s"
% additionalUsers, 1)
log.info("List of permanent users added to the session: %s" % additionalUsers)
# Get the user list from server to get the userId
url = "{server}/emby/Users?format=json"
@ -155,7 +152,7 @@ class DownloadUtils():
if self.sslclient is not None:
verify = self.sslclient
except:
log("Could not load SSL settings.", 1)
log.info("Could not load SSL settings.")
# Start session
self.s = requests.Session()
@ -165,13 +162,13 @@ class DownloadUtils():
self.s.mount("http://", requests.adapters.HTTPAdapter(max_retries=1))
self.s.mount("https://", requests.adapters.HTTPAdapter(max_retries=1))
log("Requests session started on: %s" % self.server, 1)
log.info("Requests session started on: %s" % self.server)
def stopSession(self):
try:
self.s.close()
except:
log("Requests session could not be terminated.", 1)
except Exception:
log.warn("Requests session could not be terminated.")
def getHeader(self, authenticate=True):
@ -210,7 +207,7 @@ class DownloadUtils():
def downloadUrl(self, url, postBody=None, action_type="GET", parameters=None,
authenticate=True):
log("===== ENTER downloadUrl =====", 2)
log.debug("===== ENTER downloadUrl =====")
session = requests
kwargs = {}
@ -267,12 +264,12 @@ class DownloadUtils():
})
##### THE RESPONSE #####
log(kwargs, 2)
log.debug(kwargs)
r = self._requests(action_type, session, **kwargs)
if r.status_code == 204:
# No body in the response
log("====== 204 Success ======", 2)
log.debug("====== 204 Success ======")
# Read response to release connection
r.content
@ -280,16 +277,16 @@ class DownloadUtils():
try:
# UNICODE - JSON object
r = r.json()
log("====== 200 Success ======", 2)
log("Response: %s" % r, 2)
log.debug("====== 200 Success ======")
log.debug("Response: %s" % r)
return r
except:
if r.headers.get('content-type') != "text/html":
log("Unable to convert the response for: %s" % url, 1)
log.info("Unable to convert the response for: %s" % url)
else: # Bad status code
log("=== Bad status response: %s ===" % r.status_code, -1)
log.error("=== Bad status response: %s ===" % r.status_code)
r.raise_for_status()
##### EXCEPTIONS #####
@ -297,13 +294,11 @@ class DownloadUtils():
except requests.exceptions.ConnectionError as e:
# Make the addon aware of status
if window('emby_online') != "false":
log("Server unreachable at: %s" % url, 0)
log(e, 2)
log.warn("Server unreachable at: %s" % url)
window('emby_online', value="false")
except requests.exceptions.ConnectTimeout as e:
log("Server timeout at: %s" % url, 0)
log(e, 1)
log.warn("Server timeout at: %s" % url)
except requests.exceptions.HTTPError as e:
@ -330,7 +325,7 @@ class DownloadUtils():
elif status not in ("401", "Auth"):
# Tell userclient token has been revoked.
window('emby_serverStatus', value="401")
log("HTTP Error: %s" % e, 0)
log.warn("HTTP Error: %s" % e)
xbmcgui.Dialog().notification(
heading="Error connecting",
message="Unauthorized.",
@ -345,12 +340,10 @@ class DownloadUtils():
pass
except requests.exceptions.SSLError as e:
log("Invalid SSL certificate for: %s" % url, 0)
log(e, 1)
log.warn("Invalid SSL certificate for: %s" % url)
except requests.exceptions.RequestException as e:
log("Unknown error connecting to: %s" % url, 0)
log(e, 1)
log.warn("Unknown error connecting to: %s" % url)
return default_link

View file

@ -2,12 +2,14 @@
#################################################################################################
import logging
from sqlite3 import OperationalError
import clientinfo
from utils import Logging
##################################################################################################
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
class Embydb_Functions():
@ -15,14 +17,8 @@ class Embydb_Functions():
def __init__(self, embycursor):
global log
log = Logging(self.__class__.__name__).log
self.embycursor = embycursor
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
def getViews(self):

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import os
import sys
import urlparse
@ -24,8 +25,11 @@ import playlist
import playbackutils as pbutils
import playutils
import api
from utils import Logging, window, settings, language as lang
log = Logging('Entrypoint').log
from utils import window, settings, language as lang
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -43,7 +47,7 @@ def resetAuth():
heading=lang(30132),
line1=lang(33050))
if resp:
log("Reset login attempts.", 1)
log.info("Reset login attempts.")
window('emby_serverStatus', value="Auth")
else:
xbmc.executebuiltin('Addon.OpenSettings(plugin.video.emby)')
@ -121,12 +125,12 @@ def resetDeviceId():
window('emby_deviceId', clear=True)
deviceId = clientinfo.ClientInfo().getDeviceId(reset=True)
except Exception as e:
log("Failed to generate a new device Id: %s" % e, 1)
log.error("Failed to generate a new device Id: %s" % e)
dialog.ok(
heading=lang(29999),
line1=lang(33032))
else:
log("Successfully removed old deviceId: %s New deviceId: %s" % (deviceId_old, deviceId), 1)
log.info("Successfully removed old deviceId: %s New deviceId: %s" % (deviceId_old, deviceId))
dialog.ok(
heading=lang(29999),
line1=lang(33033))
@ -153,7 +157,7 @@ def deleteItem():
elif xbmc.getCondVisibility('Container.Content(pictures)'):
itemType = "picture"
else:
log("Unknown type, unable to proceed.", 1)
log.info("Unknown type, unable to proceed.")
return
embyconn = utils.kodiSQL('emby')
@ -165,7 +169,7 @@ def deleteItem():
try:
itemId = item[0]
except TypeError:
log("Unknown itemId, unable to proceed.", 1)
log.error("Unknown itemId, unable to proceed.")
return
if settings('skipContextMenu') != "true":
@ -173,7 +177,7 @@ def deleteItem():
heading=lang(29999),
line1=lang(33041))
if not resp:
log("User skipped deletion for: %s." % itemId, 1)
log.info("User skipped deletion for: %s." % itemId)
return
embyserver.Read_EmbyServer().deleteItem(itemId)
@ -257,7 +261,7 @@ def addUser():
return
# Subtract any additional users
log("Displaying list of users: %s" % users)
log.info("Displaying list of users: %s" % users)
resp = dialog.select("Add user to the session", users)
# post additional user
if resp > -1:
@ -272,7 +276,7 @@ def addUser():
time=1000)
except:
log("Failed to add user to session.")
log.error("Failed to add user to session.")
dialog.notification(
heading=lang(29999),
message=lang(33068),
@ -328,7 +332,7 @@ def getThemeMedia():
tvtunes = xbmcaddon.Addon(id="script.tvtunes")
tvtunes.setSetting('custom_path_enable', "true")
tvtunes.setSetting('custom_path', library)
log("TV Tunes custom path is enabled and set.", 1)
log.info("TV Tunes custom path is enabled and set.")
else:
# if it does not exist this will not work so warn user
# often they need to edit the settings first for it to be created.
@ -474,7 +478,7 @@ def refreshPlaylist():
sound=False)
except Exception as e:
log("Refresh playlists/nodes failed: %s" % e, 1)
log.error("Refresh playlists/nodes failed: %s" % e)
dialog.notification(
heading=lang(29999),
message=lang(33070),
@ -516,7 +520,7 @@ def BrowseContent(viewname, browse_type="", folderid=""):
break
if viewname is not None:
log("viewname: %s - type: %s - folderid: %s - filter: %s" %(viewname.decode('utf-8'), browse_type.decode('utf-8'), folderid.decode('utf-8'), filter_type.decode('utf-8')))
log.info("viewname: %s - type: %s - folderid: %s - filter: %s" %(viewname.decode('utf-8'), browse_type.decode('utf-8'), folderid.decode('utf-8'), filter_type.decode('utf-8')))
#set the correct params for the content type
#only proceed if we have a folderid
if folderid:
@ -1049,7 +1053,7 @@ def getExtraFanArt(embyId,embyPath):
if embyId:
#only proceed if we actually have a emby id
log("Requesting extrafanart for Id: %s" % embyId, 0)
log.info("Requesting extrafanart for Id: %s" % embyId)
# We need to store the images locally for this to work
# because of the caching system in xbmc
@ -1078,7 +1082,7 @@ def getExtraFanArt(embyId,embyPath):
xbmcvfs.copy(backdrop, fanartFile)
count += 1
else:
log("Found cached backdrop.", 2)
log.debug("Found cached backdrop.")
# Use existing cached images
dirs, files = xbmcvfs.listdir(fanartDir)
for file in files:
@ -1089,7 +1093,7 @@ def getExtraFanArt(embyId,embyPath):
url=fanartFile,
listitem=li)
except Exception as e:
log("Error getting extrafanart: %s" % e, 0)
log.error("Error getting extrafanart: %s" % e)
# Always do endofdirectory to prevent errors in the logs
xbmcplugin.endOfDirectory(int(sys.argv[1]))

View file

@ -2,10 +2,13 @@
#################################################################################################
import threading
import logging
import requests
import threading
from utils import Logging
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -22,9 +25,6 @@ class image_cache_thread(threading.Thread):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
threading.Thread.__init__(self)
@ -44,7 +44,7 @@ class image_cache_thread(threading.Thread):
def run(self):
log("Image Caching Thread Processing: %s" % self.urlToProcess, 2)
log.debug("Image Caching Thread Processing: %s" % self.urlToProcess)
try:
response = requests.head(
@ -56,5 +56,5 @@ class image_cache_thread(threading.Thread):
# We don't need the result
except: pass
log("Image Caching Thread Exited", 2)
log.debug("Image Caching Thread Exited")
self.isFinished = True

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import socket
import xbmc
@ -12,7 +13,11 @@ import xbmcaddon
import clientinfo
import downloadutils
import userclient
from utils import Logging, settings, language as lang, passwordsXML
from utils import settings, language as lang, passwordsXML
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -22,9 +27,6 @@ class InitialSetup():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.addonId = clientinfo.ClientInfo().getAddonId()
self.doUtils = downloadutils.DownloadUtils().downloadUrl
self.userClient = userclient.UserClient()
@ -37,20 +39,20 @@ class InitialSetup():
##### SERVER INFO #####
log("Initial setup called.", 2)
log.debug("Initial setup called.")
server = self.userClient.getServer()
if server:
log("Server is already set.", 2)
log.debug("Server is already set.")
return
log("Looking for server...", 2)
log.debug("Looking for server...")
server = self.getServerDetails()
log("Found: %s" % server, 2)
log.debug("Found: %s" % server)
try:
prefix, ip, port = server.replace("/", "").split(":")
except: # Failed to retrieve server information
log("getServerDetails failed.", 1)
except Exception: # Failed to retrieve server information
log.error("getServerDetails failed.")
xbmc.executebuiltin('Addon.OpenSettings(%s)' % addonId)
return
else:
@ -60,7 +62,7 @@ class InitialSetup():
line2="%s %s" % (lang(30169), server))
if server_confirm:
# Correct server found
log("Server is selected. Saving the information.", 1)
log.info("Server is selected. Saving the information.")
settings('ipaddress', value=ip)
settings('port', value=port)
@ -68,20 +70,20 @@ class InitialSetup():
settings('https', value="true")
else:
# User selected no or cancelled the dialog
log("No server selected.", 1)
log.info("No server selected.")
xbmc.executebuiltin('Addon.OpenSettings(%s)' % addonId)
return
##### USER INFO #####
log("Getting user list.", 1)
log.info("Getting user list.")
result = self.doUtils("%s/emby/Users/Public?format=json" % server, authenticate=False)
if result == "":
log("Unable to connect to %s" % server, 1)
log.info("Unable to connect to %s" % server)
return
log("Response: %s" % result, 2)
log.debug("Response: %s" % result)
# Process the list of users
usernames = []
users_hasPassword = []
@ -95,14 +97,14 @@ class InitialSetup():
name = "%s (secure)" % name
users_hasPassword.append(name)
log("Presenting user list: %s" % users_hasPassword, 1)
log.info("Presenting user list: %s" % users_hasPassword)
user_select = dialog.select(lang(30200), users_hasPassword)
if user_select > -1:
selected_user = usernames[user_select]
log("Selected user: %s" % selected_user, 1)
log.info("Selected user: %s" % selected_user)
settings('username', value=selected_user)
else:
log("No user selected.", 1)
log.info("No user selected.")
xbmc.executebuiltin('Addon.OpenSettings(%s)' % addonId)
return
@ -114,7 +116,7 @@ class InitialSetup():
nolabel=lang(33036),
yeslabel=lang(33037))
if directPaths:
log("User opted to use direct paths.", 1)
log.info("User opted to use direct paths.")
settings('useDirectPaths', value="1")
# ask for credentials
@ -122,14 +124,14 @@ class InitialSetup():
heading=lang(30517),
line1= lang(33038))
if credentials:
log("Presenting network credentials dialog.", 1)
log.info("Presenting network credentials dialog.")
passwordsXML()
musicDisabled = dialog.yesno(
heading=lang(29999),
line1=lang(33039))
if musicDisabled:
log("User opted to disable Emby music library.", 1)
log.info("User opted to disable Emby music library.")
settings('enableMusic', value="false")
else:
# Only prompt if the user didn't select direct paths for videos
@ -138,12 +140,12 @@ class InitialSetup():
heading=lang(29999),
line1=lang(33040))
if musicAccess:
log("User opted to direct stream music.", 1)
log.info("User opted to direct stream music.")
settings('streamMusic', value="true")
def getServerDetails(self):
log("Getting Server Details from Network", 1)
log.info("Getting Server Details from Network")
MULTI_GROUP = ("<broadcast>", 7359)
MESSAGE = "who is EmbyServer?"
@ -157,15 +159,15 @@ class InitialSetup():
sock.setsockopt(socket.SOL_IP, socket.IP_MULTICAST_LOOP, 1)
sock.setsockopt(socket.IPPROTO_IP, socket.SO_REUSEADDR, 1)
log("MultiGroup : %s" % str(MULTI_GROUP), 2)
log("Sending UDP Data: %s" % MESSAGE, 2)
log.debug("MultiGroup : %s" % str(MULTI_GROUP))
log.debug("Sending UDP Data: %s" % MESSAGE)
sock.sendto(MESSAGE, MULTI_GROUP)
try:
data, addr = sock.recvfrom(1024) # buffer size is 1024 bytes
log("Received Response: %s" % data)
except:
log("No UDP Response")
log.info("Received Response: %s" % data)
except Exception:
log.error("No UDP Response")
return None
else:
# Get the address

View file

@ -2,6 +2,7 @@
##################################################################################################
import logging
import urllib
from ntpath import dirname
from datetime import datetime
@ -18,9 +19,13 @@ import embydb_functions as embydb
import kodidb_functions as kodidb
import read_embyserver as embyserver
import musicutils
from utils import Logging, window, settings, language as lang, kodiSQL
from utils import window, settings, language as lang, kodiSQL
##################################################################################################
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
class Items(object):
@ -28,9 +33,6 @@ class Items(object):
def __init__(self, embycursor, kodicursor):
global log
log = Logging(self.__class__.__name__).log
self.embycursor = embycursor
self.kodicursor = kodicursor
@ -79,7 +81,7 @@ class Items(object):
if total == 0:
return False
log("Processing %s: %s" % (process, items), 1)
log.info("Processing %s: %s" % (process, items))
if pdialog:
pdialog.update(heading="Processing %s: %s items" % (process, total))
@ -171,7 +173,7 @@ class Items(object):
'remove': items_process.remove
}
else:
log("Unsupported itemtype: %s." % itemtype, 1)
log.info("Unsupported itemtype: %s." % itemtype)
actions = {}
if actions.get(process):
@ -202,7 +204,7 @@ class Items(object):
if musicconn is not None:
# close connection for special types
log("Updating music database.", 1)
log.info("Updating music database.")
musicconn.commit()
musiccursor.close()
@ -282,11 +284,11 @@ class Movies(Items):
movieid = emby_dbitem[0]
fileid = emby_dbitem[1]
pathid = emby_dbitem[2]
log("movieid: %s fileid: %s pathid: %s" % (movieid, fileid, pathid), 1)
log.info("movieid: %s fileid: %s pathid: %s" % (movieid, fileid, pathid))
except TypeError:
update_item = False
log("movieid: %s not found." % itemid, 2)
log.info("movieid: %s not found." % itemid)
# movieid
kodicursor.execute("select coalesce(max(idMovie),0) from movie")
movieid = kodicursor.fetchone()[0] + 1
@ -300,12 +302,12 @@ class Movies(Items):
except TypeError:
# item is not found, let's recreate it.
update_item = False
log("movieid: %s missing from Kodi, repairing the entry." % movieid, 1)
log.info("movieid: %s missing from Kodi, repairing the entry." % movieid)
if not viewtag or not viewid:
# Get view tag from emby
viewtag, viewid, mediatype = self.emby.getView_embyId(itemid)
log("View tag found: %s" % viewtag, 2)
log.debug("View tag found: %s" % viewtag)
# fileId information
checksum = API.getChecksum()
@ -348,7 +350,7 @@ class Movies(Items):
try:
trailer = "plugin://plugin.video.emby/trailer/?id=%s&mode=play" % result[0]['Id']
except IndexError:
log("Failed to process local trailer.", 1)
log.info("Failed to process local trailer.")
trailer = None
else:
# Try to get the youtube trailer
@ -360,7 +362,7 @@ class Movies(Items):
try:
trailerId = trailer.rsplit('=', 1)[1]
except IndexError:
log("Failed to process trailer: %s" % trailer, 1)
log.info("Failed to process trailer: %s" % trailer)
trailer = None
else:
trailer = "plugin://plugin.video.youtube/play/?video_id=%s" % trailerId
@ -397,7 +399,7 @@ class Movies(Items):
##### UPDATE THE MOVIE #####
if update_item:
log("UPDATE movie itemid: %s - Title: %s" % (itemid, title), 1)
log.info("UPDATE movie itemid: %s - Title: %s" % (itemid, title))
# Update the movie entry
query = ' '.join((
@ -417,7 +419,7 @@ class Movies(Items):
##### OR ADD THE MOVIE #####
else:
log("ADD movie itemid: %s - Title: %s" % (itemid, title), 1)
log.info("ADD movie itemid: %s - Title: %s" % (itemid, title))
# Add path
pathid = self.kodi_db.addPath(path)
@ -527,10 +529,10 @@ class Movies(Items):
try:
movieid = emby_dbitem[0]
except TypeError:
log("Failed to add: %s to boxset." % movie['Name'], 1)
log.info("Failed to add: %s to boxset." % movie['Name'])
continue
log("New addition to boxset %s: %s" % (title, movie['Name']), 1)
log.info("New addition to boxset %s: %s" % (title, movie['Name']))
self.kodi_db.assignBoxset(setid, movieid)
# Update emby reference
emby_db.updateParentId(itemid, setid)
@ -541,7 +543,7 @@ class Movies(Items):
# Process removals from boxset
for movie in process:
movieid = current[movie]
log("Remove from boxset %s: %s" % (title, movieid))
log.info("Remove from boxset %s: %s" % (title, movieid))
self.kodi_db.removefromBoxset(movieid)
# Update emby reference
emby_db.updateParentId(movie, None)
@ -566,7 +568,7 @@ class Movies(Items):
try:
movieid = emby_dbitem[0]
fileid = emby_dbitem[1]
log("Update playstate for movie: %s fileid: %s" % (item['Name'], fileid), 1)
log.info("Update playstate for movie: %s fileid: %s" % (item['Name'], fileid))
except TypeError:
return
@ -582,7 +584,7 @@ class Movies(Items):
resume = API.adjustResume(userdata['Resume'])
total = round(float(runtime), 6)
log("%s New resume point: %s" % (itemid, resume))
log.debug("%s New resume point: %s" % (itemid, resume))
self.kodi_db.addPlaystate(fileid, resume, total, playcount, dateplayed)
emby_db.updateReference(itemid, checksum)
@ -598,7 +600,7 @@ class Movies(Items):
kodiid = emby_dbitem[0]
fileid = emby_dbitem[1]
mediatype = emby_dbitem[4]
log("Removing %sid: %s fileid: %s" % (mediatype, kodiid, fileid), 1)
log.info("Removing %sid: %s fileid: %s" % (mediatype, kodiid, fileid))
except TypeError:
return
@ -624,7 +626,7 @@ class Movies(Items):
kodicursor.execute("DELETE FROM sets WHERE idSet = ?", (kodiid,))
log("Deleted %s %s from kodi database" % (mediatype, itemid), 1)
log.info("Deleted %s %s from kodi database" % (mediatype, itemid))
class MusicVideos(Items):
@ -664,11 +666,11 @@ class MusicVideos(Items):
mvideoid = emby_dbitem[0]
fileid = emby_dbitem[1]
pathid = emby_dbitem[2]
log("mvideoid: %s fileid: %s pathid: %s" % (mvideoid, fileid, pathid), 1)
log.info("mvideoid: %s fileid: %s pathid: %s" % (mvideoid, fileid, pathid))
except TypeError:
update_item = False
log("mvideoid: %s not found." % itemid, 2)
log.info("mvideoid: %s not found." % itemid)
# mvideoid
kodicursor.execute("select coalesce(max(idMVideo),0) from musicvideo")
mvideoid = kodicursor.fetchone()[0] + 1
@ -682,12 +684,12 @@ class MusicVideos(Items):
except TypeError:
# item is not found, let's recreate it.
update_item = False
log("mvideoid: %s missing from Kodi, repairing the entry." % mvideoid, 1)
log.info("mvideoid: %s missing from Kodi, repairing the entry." % mvideoid)
if not viewtag or not viewid:
# Get view tag from emby
viewtag, viewid, mediatype = self.emby.getView_embyId(itemid)
log("View tag found: %s" % viewtag, 2)
log.debug("View tag found: %s" % viewtag)
# fileId information
checksum = API.getChecksum()
@ -743,7 +745,7 @@ class MusicVideos(Items):
##### UPDATE THE MUSIC VIDEO #####
if update_item:
log("UPDATE mvideo itemid: %s - Title: %s" % (itemid, title), 1)
log.info("UPDATE mvideo itemid: %s - Title: %s" % (itemid, title))
# Update path
query = "UPDATE path SET strPath = ? WHERE idPath = ?"
@ -769,7 +771,7 @@ class MusicVideos(Items):
##### OR ADD THE MUSIC VIDEO #####
else:
log("ADD mvideo itemid: %s - Title: %s" % (itemid, title), 1)
log.info("ADD mvideo itemid: %s - Title: %s" % (itemid, title))
# Add path
query = ' '.join((
@ -869,9 +871,9 @@ class MusicVideos(Items):
try:
mvideoid = emby_dbitem[0]
fileid = emby_dbitem[1]
log(
log.info(
"Update playstate for musicvideo: %s fileid: %s"
% (item['Name'], fileid), 1)
% (item['Name'], fileid))
except TypeError:
return
@ -901,7 +903,7 @@ class MusicVideos(Items):
mvideoid = emby_dbitem[0]
fileid = emby_dbitem[1]
pathid = emby_dbitem[2]
log("Removing mvideoid: %s fileid: %s" % (mvideoid, fileid, pathid), 1)
log.info("Removing mvideoid: %s fileid: %s" % (mvideoid, fileid, pathid))
except TypeError:
return
@ -927,7 +929,7 @@ class MusicVideos(Items):
kodicursor.execute("DELETE FROM path WHERE idPath = ?", (pathid,))
self.embycursor.execute("DELETE FROM emby WHERE emby_id = ?", (itemid,))
log("Deleted musicvideo %s from kodi database" % itemid, 1)
log.info("Deleted musicvideo %s from kodi database" % itemid)
class TVShows(Items):
@ -991,7 +993,7 @@ class TVShows(Items):
API = api.API(item)
if settings('syncEmptyShows') == "false" and not item.get('RecursiveItemCount'):
log("Skipping empty show: %s" % item['Name'], 1)
log.info("Skipping empty show: %s" % item['Name'])
return
# If the item already exist in the local Kodi DB we'll perform a full item update
# If the item doesn't exist, we'll add it to the database
@ -1002,11 +1004,11 @@ class TVShows(Items):
try:
showid = emby_dbitem[0]
pathid = emby_dbitem[2]
log("showid: %s pathid: %s" % (showid, pathid), 1)
log.info("showid: %s pathid: %s" % (showid, pathid))
except TypeError:
update_item = False
log("showid: %s not found." % itemid, 2)
log.info("showid: %s not found." % itemid)
kodicursor.execute("select coalesce(max(idShow),0) from tvshow")
showid = kodicursor.fetchone()[0] + 1
@ -1019,7 +1021,7 @@ class TVShows(Items):
except TypeError:
# item is not found, let's recreate it.
update_item = False
log("showid: %s missing from Kodi, repairing the entry." % showid, 1)
log.info("showid: %s missing from Kodi, repairing the entry." % showid)
# Force re-add episodes after the show is re-created.
force_episodes = True
@ -1027,7 +1029,7 @@ class TVShows(Items):
if viewtag is None or viewid is None:
# Get view tag from emby
viewtag, viewid, mediatype = emby.getView_embyId(itemid)
log("View tag found: %s" % viewtag, 2)
log.debug("View tag found: %s" % viewtag)
# fileId information
checksum = API.getChecksum()
@ -1076,7 +1078,7 @@ class TVShows(Items):
##### UPDATE THE TVSHOW #####
if update_item:
log("UPDATE tvshow itemid: %s - Title: %s" % (itemid, title), 1)
log.info("UPDATE tvshow itemid: %s - Title: %s" % (itemid, title))
# Update the tvshow entry
query = ' '.join((
@ -1094,7 +1096,7 @@ class TVShows(Items):
##### OR ADD THE TVSHOW #####
else:
log("ADD tvshow itemid: %s - Title: %s" % (itemid, title), 1)
log.info("ADD tvshow itemid: %s - Title: %s" % (itemid, title))
# Add top path
toppathid = self.kodi_db.addPath(toplevelpath)
@ -1165,7 +1167,7 @@ class TVShows(Items):
if force_episodes:
# We needed to recreate the show entry. Re-add episodes now.
log("Repairing episodes for showid: %s %s" % (showid, title), 1)
log.info("Repairing episodes for showid: %s %s" % (showid, title))
all_episodes = emby.getEpisodesbyShow(itemid)
self.added_episode(all_episodes['Items'], None)
@ -1214,11 +1216,11 @@ class TVShows(Items):
episodeid = emby_dbitem[0]
fileid = emby_dbitem[1]
pathid = emby_dbitem[2]
log("episodeid: %s fileid: %s pathid: %s" % (episodeid, fileid, pathid), 1)
log.info("episodeid: %s fileid: %s pathid: %s" % (episodeid, fileid, pathid))
except TypeError:
update_item = False
log("episodeid: %s not found." % itemid, 2)
log.info("episodeid: %s not found." % itemid)
# episodeid
kodicursor.execute("select coalesce(max(idEpisode),0) from episode")
episodeid = kodicursor.fetchone()[0] + 1
@ -1232,7 +1234,7 @@ class TVShows(Items):
except TypeError:
# item is not found, let's recreate it.
update_item = False
log("episodeid: %s missing from Kodi, repairing the entry." % episodeid, 1)
log.info("episodeid: %s missing from Kodi, repairing the entry." % episodeid)
# fileId information
checksum = API.getChecksum()
@ -1256,7 +1258,7 @@ class TVShows(Items):
seriesId = item['SeriesId']
except KeyError:
# Missing seriesId, skip
log("Skipping: %s. SeriesId is missing." % itemid, 1)
log.error("Skipping: %s. SeriesId is missing." % itemid)
return False
season = item.get('ParentIndexNumber')
@ -1294,7 +1296,7 @@ class TVShows(Items):
try:
showid = show[0]
except TypeError:
log("Skipping: %s. Unable to add series: %s." % (itemid, seriesId))
log.error("Skipping: %s. Unable to add series: %s." % (itemid, seriesId))
return False
seasonid = self.kodi_db.addSeason(showid, season)
@ -1331,7 +1333,7 @@ class TVShows(Items):
##### UPDATE THE EPISODE #####
if update_item:
log("UPDATE episode itemid: %s - Title: %s" % (itemid, title), 1)
log.info("UPDATE episode itemid: %s - Title: %s" % (itemid, title))
# Update the movie entry
if self.kodiversion in (16, 17):
@ -1365,7 +1367,7 @@ class TVShows(Items):
##### OR ADD THE EPISODE #####
else:
log("ADD episode itemid: %s - Title: %s" % (itemid, title), 1)
log.info("ADD episode itemid: %s - Title: %s" % (itemid, title))
# Add path
pathid = self.kodi_db.addPath(path)
@ -1468,9 +1470,9 @@ class TVShows(Items):
kodiid = emby_dbitem[0]
fileid = emby_dbitem[1]
mediatype = emby_dbitem[4]
log(
log.info(
"Update playstate for %s: %s fileid: %s"
% (mediatype, item['Name'], fileid), 1)
% (mediatype, item['Name'], fileid))
except TypeError:
return
@ -1487,7 +1489,7 @@ class TVShows(Items):
resume = API.adjustResume(userdata['Resume'])
total = round(float(runtime), 6)
log("%s New resume point: %s" % (itemid, resume))
log.debug("%s New resume point: %s" % (itemid, resume))
self.kodi_db.addPlaystate(fileid, resume, total, playcount, dateplayed)
if not self.directpath and not resume:
@ -1525,7 +1527,7 @@ class TVShows(Items):
pathid = emby_dbitem[2]
parentid = emby_dbitem[3]
mediatype = emby_dbitem[4]
log("Removing %s kodiid: %s fileid: %s" % (mediatype, kodiid, fileid), 1)
log.info("Removing %s kodiid: %s fileid: %s" % (mediatype, kodiid, fileid))
except TypeError:
return
@ -1615,14 +1617,14 @@ class TVShows(Items):
self.removeShow(parentid)
emby_db.removeItem_byKodiId(parentid, "tvshow")
log("Deleted %s: %s from kodi database" % (mediatype, itemid), 1)
log.info("Deleted %s: %s from kodi database" % (mediatype, itemid))
def removeShow(self, kodiid):
kodicursor = self.kodicursor
self.artwork.deleteArtwork(kodiid, "tvshow", kodicursor)
kodicursor.execute("DELETE FROM tvshow WHERE idShow = ?", (kodiid,))
log("Removed tvshow: %s." % kodiid, 2)
log.debug("Removed tvshow: %s." % kodiid)
def removeSeason(self, kodiid):
@ -1630,7 +1632,7 @@ class TVShows(Items):
self.artwork.deleteArtwork(kodiid, "season", kodicursor)
kodicursor.execute("DELETE FROM seasons WHERE idSeason = ?", (kodiid,))
log("Removed season: %s." % kodiid, 2)
log.debug("Removed season: %s." % kodiid)
def removeEpisode(self, kodiid, fileid):
@ -1639,7 +1641,7 @@ class TVShows(Items):
self.artwork.deleteArtwork(kodiid, "episode", kodicursor)
kodicursor.execute("DELETE FROM episode WHERE idEpisode = ?", (kodiid,))
kodicursor.execute("DELETE FROM files WHERE idFile = ?", (fileid,))
log("Removed episode: %s." % kodiid, 2)
log.debug("Removed episode: %s." % kodiid)
class Music(Items):
@ -1713,7 +1715,7 @@ class Music(Items):
artistid = emby_dbitem[0]
except TypeError:
update_item = False
log("artistid: %s not found." % itemid, 2)
log.debug("artistid: %s not found." % itemid)
##### The artist details #####
lastScraped = datetime.now().strftime('%Y-%m-%d %H:%M:%S')
@ -1740,13 +1742,13 @@ class Music(Items):
##### UPDATE THE ARTIST #####
if update_item:
log("UPDATE artist itemid: %s - Name: %s" % (itemid, name), 1)
log.info("UPDATE artist itemid: %s - Name: %s" % (itemid, name))
# Update the checksum in emby table
emby_db.updateReference(itemid, checksum)
##### OR ADD THE ARTIST #####
else:
log("ADD artist itemid: %s - Name: %s" % (itemid, name), 1)
log.info("ADD artist itemid: %s - Name: %s" % (itemid, name))
# safety checks: It looks like Emby supports the same artist multiple times.
# Kodi doesn't allow that. In case that happens we just merge the artist entries.
artistid = self.kodi_db.addArtist(name, musicBrainzId)
@ -1794,7 +1796,7 @@ class Music(Items):
albumid = emby_dbitem[0]
except TypeError:
update_item = False
log("albumid: %s not found." % itemid, 2)
log.debug("albumid: %s not found." % itemid)
##### The album details #####
lastScraped = datetime.now().strftime('%Y-%m-%d %H:%M:%S')
@ -1825,13 +1827,13 @@ class Music(Items):
##### UPDATE THE ALBUM #####
if update_item:
log("UPDATE album itemid: %s - Name: %s" % (itemid, name), 1)
log.info("UPDATE album itemid: %s - Name: %s" % (itemid, name))
# Update the checksum in emby table
emby_db.updateReference(itemid, checksum)
##### OR ADD THE ALBUM #####
else:
log("ADD album itemid: %s - Name: %s" % (itemid, name), 1)
log.info("ADD album itemid: %s - Name: %s" % (itemid, name))
# safety checks: It looks like Emby supports the same artist multiple times.
# Kodi doesn't allow that. In case that happens we just merge the artist entries.
albumid = self.kodi_db.addAlbum(name, musicBrainzId)
@ -1964,7 +1966,7 @@ class Music(Items):
albumid = emby_dbitem[3]
except TypeError:
update_item = False
log("songid: %s not found." % itemid, 2)
log.debug("songid: %s not found." % itemid)
##### The song details #####
checksum = API.getChecksum()
@ -2019,7 +2021,7 @@ class Music(Items):
##### UPDATE THE SONG #####
if update_item:
log("UPDATE song itemid: %s - Title: %s" % (itemid, title), 1)
log.info("UPDATE song itemid: %s - Title: %s" % (itemid, title))
# Update path
query = "UPDATE path SET strPath = ? WHERE idPath = ?"
@ -2042,7 +2044,7 @@ class Music(Items):
##### OR ADD THE SONG #####
else:
log("ADD song itemid: %s - Title: %s" % (itemid, title), 1)
log.info("ADD song itemid: %s - Title: %s" % (itemid, title))
# Add path
pathid = self.kodi_db.addPath(path)
@ -2055,27 +2057,27 @@ class Music(Items):
# Verify if there's an album associated.
album_name = item.get('Album')
if album_name:
log("Creating virtual music album for song: %s." % itemid, 1)
log.info("Creating virtual music album for song: %s." % itemid)
albumid = self.kodi_db.addAlbum(album_name, API.getProvider('MusicBrainzAlbum'))
emby_db.addReference("%salbum%s" % (itemid, albumid), albumid, "MusicAlbum_", "album")
else:
# No album Id associated to the song.
log("Song itemid: %s has no albumId associated." % itemid, 1)
log.error("Song itemid: %s has no albumId associated." % itemid)
return False
except TypeError:
# No album found. Let's create it
log("Album database entry missing.", 1)
log.info("Album database entry missing.")
emby_albumId = item['AlbumId']
album = emby.getItem(emby_albumId)
self.add_updateAlbum(album)
emby_dbalbum = emby_db.getItem_byId(emby_albumId)
try:
albumid = emby_dbalbum[0]
log("Found albumid: %s" % albumid, 1)
log.info("Found albumid: %s" % albumid)
except TypeError:
# No album found, create a single's album
log("Failed to add album. Creating singles.", 1)
log.info("Failed to add album. Creating singles.")
kodicursor.execute("select coalesce(max(idAlbum),0) from album")
albumid = kodicursor.fetchone()[0] + 1
if self.kodiversion == 16:
@ -2257,7 +2259,7 @@ class Music(Items):
try:
kodiid = emby_dbitem[0]
mediatype = emby_dbitem[4]
log("Update playstate for %s: %s" % (mediatype, item['Name']), 1)
log.info("Update playstate for %s: %s" % (mediatype, item['Name']))
except TypeError:
return
@ -2296,7 +2298,7 @@ class Music(Items):
try:
kodiid = emby_dbitem[0]
mediatype = emby_dbitem[4]
log("Removing %s kodiid: %s" % (mediatype, kodiid), 1)
log.info("Removing %s kodiid: %s" % (mediatype, kodiid))
except TypeError:
return
@ -2364,7 +2366,7 @@ class Music(Items):
# Remove artist
self.removeArtist(kodiid)
log("Deleted %s: %s from kodi database" % (mediatype, itemid), 1)
log.info("Deleted %s: %s from kodi database" % (mediatype, itemid))
def removeSong(self, kodiId):

View file

@ -2,15 +2,19 @@
##################################################################################################
import logging
import xbmc
import api
import artwork
import clientinfo
from utils import Logging
##################################################################################################
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
class Kodidb_Functions():
@ -18,9 +22,6 @@ class Kodidb_Functions():
def __init__(self, cursor):
global log
log = Logging(self.__class__.__name__).log
self.cursor = cursor
@ -151,7 +152,7 @@ class Kodidb_Functions():
query = "INSERT INTO country(country_id, name) values(?, ?)"
self.cursor.execute(query, (country_id, country))
log("Add country to media, processing: %s" % country, 2)
log.debug("Add country to media, processing: %s" % country)
finally: # Assign country to content
query = (
@ -185,7 +186,7 @@ class Kodidb_Functions():
query = "INSERT INTO country(idCountry, strCountry) values(?, ?)"
self.cursor.execute(query, (idCountry, country))
log("Add country to media, processing: %s" % country, 2)
log.debug("Add country to media, processing: %s" % country)
finally:
# Only movies have a country field
@ -230,7 +231,7 @@ class Kodidb_Functions():
query = "INSERT INTO actor(actor_id, name) values(?, ?)"
self.cursor.execute(query, (actorid, name))
log("Add people to media, processing: %s" % name, 2)
log.debug("Add people to media, processing: %s" % name)
finally:
# Link person to content
@ -300,7 +301,7 @@ class Kodidb_Functions():
query = "INSERT INTO actors(idActor, strActor) values(?, ?)"
self.cursor.execute(query, (actorid, name))
log("Add people to media, processing: %s" % name, 2)
log.debug("Add people to media, processing: %s" % name)
finally:
# Link person to content
@ -460,7 +461,7 @@ class Kodidb_Functions():
query = "INSERT INTO genre(genre_id, name) values(?, ?)"
self.cursor.execute(query, (genre_id, genre))
log("Add Genres to media, processing: %s" % genre, 2)
log.debug("Add Genres to media, processing: %s" % genre)
finally:
# Assign genre to item
@ -505,7 +506,7 @@ class Kodidb_Functions():
query = "INSERT INTO genre(idGenre, strGenre) values(?, ?)"
self.cursor.execute(query, (idGenre, genre))
log("Add Genres to media, processing: %s" % genre, 2)
log.debug("Add Genres to media, processing: %s" % genre)
finally:
# Assign genre to item
@ -564,7 +565,7 @@ class Kodidb_Functions():
query = "INSERT INTO studio(studio_id, name) values(?, ?)"
self.cursor.execute(query, (studioid, studio))
log("Add Studios to media, processing: %s" % studio, 2)
log.debug("Add Studios to media, processing: %s" % studio)
finally: # Assign studio to item
query = (
@ -595,7 +596,7 @@ class Kodidb_Functions():
query = "INSERT INTO studio(idstudio, strstudio) values(?, ?)"
self.cursor.execute(query, (studioid, studio))
log("Add Studios to media, processing: %s" % studio, 2)
log.debug("Add Studios to media, processing: %s" % studio)
finally: # Assign studio to item
if "movie" in mediatype:
@ -726,7 +727,7 @@ class Kodidb_Functions():
self.cursor.execute(query, (kodiid, mediatype))
# Add tags
log("Adding Tags: %s" % tags, 2)
log.debug("Adding Tags: %s" % tags)
for tag in tags:
self.addTag(kodiid, tag, mediatype)
@ -748,7 +749,7 @@ class Kodidb_Functions():
except TypeError:
# Create the tag, because it does not exist
tag_id = self.createTag(tag)
log("Adding tag: %s" % tag, 2)
log.debug("Adding tag: %s" % tag)
finally:
# Assign tag to item
@ -777,7 +778,7 @@ class Kodidb_Functions():
except TypeError:
# Create the tag
tag_id = self.createTag(tag)
log("Adding tag: %s" % tag, 2)
log.debug("Adding tag: %s" % tag)
finally:
# Assign tag to item
@ -813,7 +814,7 @@ class Kodidb_Functions():
query = "INSERT INTO tag(tag_id, name) values(?, ?)"
self.cursor.execute(query, (tag_id, name))
log("Create tag_id: %s name: %s" % (tag_id, name), 2)
log.debug("Create tag_id: %s name: %s" % (tag_id, name))
else:
# Kodi Helix
query = ' '.join((
@ -833,13 +834,13 @@ class Kodidb_Functions():
query = "INSERT INTO tag(idTag, strTag) values(?, ?)"
self.cursor.execute(query, (tag_id, name))
log("Create idTag: %s name: %s" % (tag_id, name), 2)
log.debug("Create idTag: %s name: %s" % (tag_id, name))
return tag_id
def updateTag(self, oldtag, newtag, kodiid, mediatype):
log("Updating: %s with %s for %s: %s" % (oldtag, newtag, mediatype, kodiid), 2)
log.debug("Updating: %s with %s for %s: %s" % (oldtag, newtag, mediatype, kodiid))
if self.kodiversion in (15, 16, 17):
# Kodi Isengard, Jarvis, Krypton
@ -856,7 +857,6 @@ class Kodidb_Functions():
except Exception as e:
# The new tag we are going to apply already exists for this item
# delete current tag instead
log("Exception: %s" % e, 1)
query = ' '.join((
"DELETE FROM tag_link",
@ -880,7 +880,6 @@ class Kodidb_Functions():
except Exception as e:
# The new tag we are going to apply already exists for this item
# delete current tag instead
log("Exception: %s" % e, 1)
query = ' '.join((
"DELETE FROM taglinks",
@ -941,7 +940,7 @@ class Kodidb_Functions():
def createBoxset(self, boxsetname):
log("Adding boxset: %s" % boxsetname, 2)
log.debug("Adding boxset: %s" % boxsetname)
query = ' '.join((
"SELECT idSet",

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import xbmc
import xbmcgui
@ -11,7 +12,11 @@ import clientinfo
import downloadutils
import embydb_functions as embydb
import playbackutils as pbutils
from utils import Logging, window, settings, kodiSQL
from utils import window, settings, kodiSQL
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -21,23 +26,20 @@ class KodiMonitor(xbmc.Monitor):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.doUtils = downloadutils.DownloadUtils()
log("Kodi monitor started.", 1)
log.info("Kodi monitor started.")
def onScanStarted(self, library):
log("Kodi library scan %s running." % library, 2)
log.debug("Kodi library scan %s running." % library)
if library == "video":
window('emby_kodiScan', value="true")
def onScanFinished(self, library):
log("Kodi library scan %s finished." % library, 2)
log.debug("Kodi library scan %s finished." % library)
if library == "video":
window('emby_kodiScan', clear=True)
@ -62,14 +64,14 @@ class KodiMonitor(xbmc.Monitor):
currentLog = settings('logLevel')
if window('emby_logLevel') != currentLog:
# The log level changed, set new prop
log("New log level: %s" % currentLog, 1)
log.info("New log level: %s" % currentLog)
window('emby_logLevel', value=currentLog)
def onNotification(self, sender, method, data):
doUtils = self.doUtils
if method not in ("Playlist.OnAdd"):
log("Method: %s Data: %s" % (method, data), 1)
log.info("Method: %s Data: %s" % (method, data))
if data:
data = json.loads(data,'utf-8')
@ -82,7 +84,7 @@ class KodiMonitor(xbmc.Monitor):
kodiid = item['id']
item_type = item['type']
except (KeyError, TypeError):
log("Item is invalid for playstate update.", 1)
log.info("Item is invalid for playstate update.")
else:
if ((settings('useDirectPaths') == "1" and not item_type == "song") or
(item_type == "song" and settings('enableMusic') == "true")):
@ -94,11 +96,11 @@ class KodiMonitor(xbmc.Monitor):
try:
itemid = emby_dbitem[0]
except TypeError:
log("No kodiId returned.", 1)
log.info("No kodiId returned.")
else:
url = "{server}/emby/Users/{UserId}/Items/%s?format=json" % itemid
result = doUtils.downloadUrl(url)
log("Item: %s" % result, 2)
log.debug("Item: %s" % result)
playurl = None
count = 0
@ -130,7 +132,7 @@ class KodiMonitor(xbmc.Monitor):
kodiid = item['id']
item_type = item['type']
except (KeyError, TypeError):
log("Item is invalid for playstate update.", 1)
log.info("Item is invalid for playstate update.")
else:
# Send notification to the server.
embyconn = kodiSQL('emby')
@ -140,7 +142,7 @@ class KodiMonitor(xbmc.Monitor):
try:
itemid = emby_dbitem[0]
except TypeError:
log("Could not find itemid in emby database.", 1)
log.info("Could not find itemid in emby database.")
else:
# Stop from manually marking as watched unwatched, with actual playback.
if window('emby_skipWatched%s' % itemid) == "true":
@ -151,10 +153,10 @@ class KodiMonitor(xbmc.Monitor):
url = "{server}/emby/Users/{UserId}/PlayedItems/%s?format=json" % itemid
if playcount != 0:
doUtils.downloadUrl(url, action_type="POST")
log("Mark as watched for itemid: %s" % itemid, 1)
log.info("Mark as watched for itemid: %s" % itemid)
else:
doUtils.downloadUrl(url, action_type="DELETE")
log("Mark as unwatched for itemid: %s" % itemid, 1)
log.info("Mark as unwatched for itemid: %s" % itemid)
finally:
embycursor.close()
@ -197,7 +199,7 @@ class KodiMonitor(xbmc.Monitor):
elif method == "System.OnSleep":
# Connection is going to sleep
log("Marking the server as offline. System.OnSleep activating.", 1)
log.info("Marking the server as offline. System.OnSleep activated.")
window('emby_online', value="sleep")
elif method == "System.OnWake":

View file

@ -2,6 +2,7 @@
##################################################################################################
import logging
import sqlite3
import threading
from datetime import datetime, timedelta, time
@ -20,10 +21,13 @@ import kodidb_functions as kodidb
import read_embyserver as embyserver
import userclient
import videonodes
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
class LibrarySync(threading.Thread):
@ -43,9 +47,6 @@ class LibrarySync(threading.Thread):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
self.monitor = xbmc.Monitor()
@ -65,7 +66,7 @@ class LibrarySync(threading.Thread):
dialog = xbmcgui.DialogProgressBG()
dialog.create("Emby for Kodi", title)
log("Show progress dialog: %s" % title, 2)
log.debug("Show progress dialog: %s" % title)
return dialog
@ -85,7 +86,7 @@ class LibrarySync(threading.Thread):
for plugin in result:
if plugin['Name'] == "Emby.Kodi Sync Queue":
log("Found server plugin.", 2)
log.debug("Found server plugin.")
completed = self.fastSync()
break
@ -105,7 +106,7 @@ class LibrarySync(threading.Thread):
lastSync = "2010-01-01T00:00:00Z"
lastSyncTime = utils.convertDate(lastSync)
log("Last sync run: %s" % lastSyncTime, 1)
log.info("Last sync run: %s" % lastSyncTime)
# get server RetentionDateTime
result = self.doUtils("{server}/emby/Emby.Kodi.SyncQueue/GetServerDateTime?format=json")
@ -115,11 +116,11 @@ class LibrarySync(threading.Thread):
retention_time = "2010-01-01T00:00:00Z"
retention_time = utils.convertDate(retention_time)
log("RetentionDateTime: %s" % retention_time, 1)
log.info("RetentionDateTime: %s" % retention_time)
# if last sync before retention time do a full sync
if retention_time > lastSyncTime:
log("Fast sync server retention insufficient, fall back to full sync", 1)
log.info("Fast sync server retention insufficient, fall back to full sync")
return False
params = {'LastUpdateDT': lastSync}
@ -136,11 +137,11 @@ class LibrarySync(threading.Thread):
}
except (KeyError, TypeError):
log("Failed to retrieve latest updates using fast sync.", 1)
log.error("Failed to retrieve latest updates using fast sync.")
return False
else:
log("Fast sync changes: %s" % result, 1)
log.info("Fast sync changes: %s" % result)
for action in processlist:
self.triage_items(action, processlist[action])
@ -158,14 +159,14 @@ class LibrarySync(threading.Thread):
except Exception as e:
# If the server plugin is not installed or an error happened.
log("An exception occurred: %s" % e, 1)
log.error("An exception occurred: %s" % e)
time_now = datetime.utcnow()-timedelta(minutes=overlap)
lastSync = time_now.strftime('%Y-%m-%dT%H:%M:%SZ')
log("New sync time: client time -%s min: %s" % (overlap, lastSync), 1)
log.info("New sync time: client time -%s min: %s" % (overlap, lastSync))
else:
lastSync = (server_time - timedelta(minutes=overlap)).strftime('%Y-%m-%dT%H:%M:%SZ')
log("New sync time: server time -%s min: %s" % (overlap, lastSync), 1)
log.info("New sync time: server time -%s min: %s" % (overlap, lastSync))
finally:
settings('LastIncrementalSync', value=lastSync)
@ -185,20 +186,20 @@ class LibrarySync(threading.Thread):
while kodidb_scan:
log("Kodi scan is running. Waiting...", 1)
log.info("Kodi scan is running. Waiting...")
kodidb_scan = window('emby_kodiScan') == "true"
if self.shouldStop():
log("Commit unsuccessful. Sync terminated.", 1)
log.info("Commit unsuccessful. Sync terminated.")
break
if self.monitor.waitForAbort(1):
# Abort was requested while waiting. We should exit
log("Commit unsuccessful.", 1)
log.info("Commit unsuccessful.")
break
else:
connection.commit()
log("Commit successful.", 1)
log.info("Commit successful.")
def fullSync(self, manualrun=False, repair=False):
# Only run once when first setting up. Can be run manually.
@ -268,8 +269,8 @@ class LibrarySync(threading.Thread):
self.dbCommit(kodiconn)
embyconn.commit()
elapsedTime = datetime.now() - startTime
log("SyncDatabase (finished %s in: %s)"
% (itemtype, str(elapsedTime).split('.')[0]), 1)
log.info("SyncDatabase (finished %s in: %s)"
% (itemtype, str(elapsedTime).split('.')[0]))
else:
# Close the Kodi cursor
kodicursor.close()
@ -296,8 +297,8 @@ class LibrarySync(threading.Thread):
musicconn.commit()
embyconn.commit()
elapsedTime = datetime.now() - startTime
log("SyncDatabase (finished music in: %s)"
% (str(elapsedTime).split('.')[0]), 1)
log.info("SyncDatabase (finished music in: %s)"
% (str(elapsedTime).split('.')[0]))
musiccursor.close()
if pDialog:
@ -363,7 +364,7 @@ class LibrarySync(threading.Thread):
if view['type'] == "mixed":
sorted_views.append(view['name'])
sorted_views.append(view['name'])
log("Sorted views: %s" % sorted_views, 1)
log.info("Sorted views: %s" % sorted_views)
# total nodes for window properties
self.vnodes.clearProperties()
@ -423,7 +424,7 @@ class LibrarySync(threading.Thread):
else:
# Unable to find a match, add the name to our sorted_view list
sorted_views.append(foldername)
log("Couldn't find corresponding grouped view: %s" % sorted_views, 1)
log.info("Couldn't find corresponding grouped view: %s" % sorted_views)
# Failsafe
try:
@ -439,7 +440,7 @@ class LibrarySync(threading.Thread):
current_tagid = view[2]
except TypeError:
log("Creating viewid: %s in Emby database." % folderid, 1)
log.info("Creating viewid: %s in Emby database." % folderid)
tagid = kodi_db.createTag(foldername)
# Create playlist for the video library
if (foldername not in playlists and
@ -458,12 +459,12 @@ class LibrarySync(threading.Thread):
emby_db.addView(folderid, foldername, viewtype, tagid)
else:
log(' '.join((
log.debug(' '.join((
"Found viewid: %s" % folderid,
"viewname: %s" % current_viewname,
"viewtype: %s" % current_viewtype,
"tagid: %s" % current_tagid)), 2)
"tagid: %s" % current_tagid)))
# View is still valid
try:
@ -474,7 +475,7 @@ class LibrarySync(threading.Thread):
# View was modified, update with latest info
if current_viewname != foldername:
log("viewid: %s new viewname: %s" % (folderid, foldername), 1)
log.info("viewid: %s new viewname: %s" % (folderid, foldername))
tagid = kodi_db.createTag(foldername)
# Update view with new info
@ -542,7 +543,7 @@ class LibrarySync(threading.Thread):
window('Emby.nodes.total', str(totalnodes))
# Remove any old referenced views
log("Removing views: %s" % current_views, 1)
log.info("Removing views: %s" % current_views)
for view in current_views:
emby_db.removeView(view)
@ -554,7 +555,7 @@ class LibrarySync(threading.Thread):
views = emby_db.getView_byType('movies')
views += emby_db.getView_byType('mixed')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
##### PROCESS MOVIES #####
for view in views:
@ -589,7 +590,7 @@ class LibrarySync(threading.Thread):
count += 1
movies.add_update(embymovie, view['name'], view['id'])
else:
log("Movies finished.", 2)
log.debug("Movies finished.")
##### PROCESS BOXSETS #####
@ -616,7 +617,7 @@ class LibrarySync(threading.Thread):
count += 1
movies.add_updateBoxset(boxset)
else:
log("Boxsets finished.", 2)
log.debug("Boxsets finished.")
return True
@ -627,7 +628,7 @@ class LibrarySync(threading.Thread):
mvideos = itemtypes.MusicVideos(embycursor, kodicursor)
views = emby_db.getView_byType('musicvideos')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
for view in views:
@ -664,7 +665,7 @@ class LibrarySync(threading.Thread):
count += 1
mvideos.add_update(embymvideo, viewName, viewId)
else:
log("MusicVideos finished.", 2)
log.debug("MusicVideos finished.")
return True
@ -676,7 +677,7 @@ class LibrarySync(threading.Thread):
views = emby_db.getView_byType('tvshows')
views += emby_db.getView_byType('mixed')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
for view in views:
@ -722,7 +723,7 @@ class LibrarySync(threading.Thread):
pdialog.update(percentage, message="%s - %s" % (title, episodetitle))
tvshows.add_updateEpisode(episode)
else:
log("TVShows finished.", 2)
log.debug("TVShows finished.")
return True
@ -763,7 +764,7 @@ class LibrarySync(threading.Thread):
process[itemtype][1](embyitem)
else:
log("%s finished." % itemtype, 2)
log.debug("%s finished." % itemtype)
return True
@ -784,7 +785,7 @@ class LibrarySync(threading.Thread):
itemids.append(item['ItemId'])
items = itemids
log("Queue %s: %s" % (process, items), 1)
log.info("Queue %s: %s" % (process, items))
processlist[process].extend(items)
def incrementalSync(self):
@ -806,7 +807,7 @@ class LibrarySync(threading.Thread):
incSyncIndicator = int(settings('incSyncIndicator'))
totalUpdates = len(self.addedItems) + len(self.updateItems) + len(self.userdataItems) + len(self.removeItems)
log("incSyncIndicator=" + str(incSyncIndicator) + " totalUpdates=" + str(totalUpdates), 1)
log.info("incSyncIndicator=" + str(incSyncIndicator) + " totalUpdates=" + str(totalUpdates))
if incSyncIndicator != -1 and totalUpdates > incSyncIndicator:
# Only present dialog if we are going to process items
@ -859,7 +860,7 @@ class LibrarySync(threading.Thread):
if update_embydb:
update_embydb = False
log("Updating emby database.", 1)
log.info("Updating emby database.")
embyconn.commit()
self.saveLastSync()
@ -868,7 +869,7 @@ class LibrarySync(threading.Thread):
self.forceLibraryUpdate = False
self.dbCommit(kodiconn)
log("Updating video library.", 1)
log.info("Updating video library.")
window('emby_kodiScan', value="true")
xbmc.executebuiltin('UpdateLibrary(video)')
@ -881,7 +882,7 @@ class LibrarySync(threading.Thread):
def compareDBVersion(self, current, minimum):
# It returns True is database is up to date. False otherwise.
log("current: %s minimum: %s" % (current, minimum), 1)
log.info("current: %s minimum: %s" % (current, minimum))
currMajor, currMinor, currPatch = current.split(".")
minMajor, minMinor, minPatch = minimum.split(".")
@ -906,6 +907,7 @@ class LibrarySync(threading.Thread):
"Library sync thread has exited! "
"You should restart Kodi now. "
"Please report this on the forum."))
log.exception(e)
raise
def run_internal(self):
@ -914,7 +916,7 @@ class LibrarySync(threading.Thread):
startupComplete = False
log("---===### Starting LibrarySync ###===---", 0)
log.warn("---===### Starting LibrarySync ###===---")
while not self.monitor.abortRequested():
@ -932,12 +934,12 @@ class LibrarySync(threading.Thread):
uptoDate = self.compareDBVersion(currentVersion, minVersion)
if not uptoDate:
log("Database version out of date: %s minimum version required: %s"
% (currentVersion, minVersion), 0)
log.warn("Database version out of date: %s minimum version required: %s"
% (currentVersion, minVersion))
resp = dialog.yesno(lang(29999), lang(33022))
if not resp:
log("Database version is out of date! USER IGNORED!", 0)
log.warn("Database version is out of date! USER IGNORED!")
dialog.ok(lang(29999), lang(33023))
else:
utils.reset()
@ -952,11 +954,11 @@ class LibrarySync(threading.Thread):
videoDb = utils.getKodiVideoDBPath()
if not xbmcvfs.exists(videoDb):
# Database does not exists
log(
log.error(
"The current Kodi version is incompatible "
"with the Emby for Kodi add-on. Please visit "
"https://github.com/MediaBrowser/Emby.Kodi/wiki "
"to know which Kodi versions are supported.", 0)
"to know which Kodi versions are supported.")
dialog.ok(
heading=lang(29999),
@ -964,13 +966,13 @@ class LibrarySync(threading.Thread):
break
# Run start up sync
log("Database version: %s" % settings('dbCreatedWithVersion'), 0)
log("SyncDatabase (started)", 1)
log.warn("Database version: %s" % settings('dbCreatedWithVersion'))
log.info("SyncDatabase (started)")
startTime = datetime.now()
librarySync = self.startSync()
elapsedTime = datetime.now() - startTime
log("SyncDatabase (finished in: %s) %s"
% (str(elapsedTime).split('.')[0], librarySync), 1)
log.info("SyncDatabase (finished in: %s) %s"
% (str(elapsedTime).split('.')[0], librarySync))
# Only try the initial sync once per kodi session regardless
# This will prevent an infinite loop in case something goes wrong.
startupComplete = True
@ -984,32 +986,32 @@ class LibrarySync(threading.Thread):
# Set in kodimonitor.py
window('emby_onWake', clear=True)
if window('emby_syncRunning') != "true":
log("SyncDatabase onWake (started)", 0)
log.info("SyncDatabase onWake (started)")
librarySync = self.startSync()
log("SyncDatabase onWake (finished) %s" % librarySync, 0)
log.info("SyncDatabase onWake (finished) %s" % librarySync)
if self.stop_thread:
# Set in service.py
log("Service terminated thread.", 2)
log.debug("Service terminated thread.")
break
if self.monitor.waitForAbort(1):
# Abort was requested while waiting. We should exit
break
log("###===--- LibrarySync Stopped ---===###", 0)
log.warn("###===--- LibrarySync Stopped ---===###")
def stopThread(self):
self.stop_thread = True
log("Ending thread...", 2)
log.debug("Ending thread...")
def suspendThread(self):
self.suspend_thread = True
log("Pausing thread...", 0)
log.debug("Pausing thread...")
def resumeThread(self):
self.suspend_thread = False
log("Resuming thread...", 0)
log.debug("Resuming thread...")
class ManualSync(LibrarySync):
@ -1032,7 +1034,7 @@ class ManualSync(LibrarySync):
views = emby_db.getView_byType('movies')
views += emby_db.getView_byType('mixed')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
# Pull the list of movies and boxsets in Kodi
try:
@ -1079,7 +1081,7 @@ class ManualSync(LibrarySync):
# Only update if movie is not in Kodi or checksum is different
updatelist.append(itemid)
log("Movies to update for %s: %s" % (viewName, updatelist), 1)
log.info("Movies to update for %s: %s" % (viewName, updatelist))
embymovies = self.emby.getFullItems(updatelist)
total = len(updatelist)
del updatelist[:]
@ -1121,7 +1123,7 @@ class ManualSync(LibrarySync):
updatelist.append(itemid)
embyboxsets.append(boxset)
log("Boxsets to update: %s" % updatelist, 1)
log.info("Boxsets to update: %s" % updatelist)
total = len(updatelist)
if pdialog:
@ -1145,13 +1147,13 @@ class ManualSync(LibrarySync):
if kodimovie not in all_embymoviesIds:
movies.remove(kodimovie)
else:
log("Movies compare finished.", 1)
log.info("Movies compare finished.")
for boxset in all_kodisets:
if boxset not in all_embyboxsetsIds:
movies.remove(boxset)
else:
log("Boxsets compare finished.", 1)
log.info("Boxsets compare finished.")
return True
@ -1162,7 +1164,7 @@ class ManualSync(LibrarySync):
mvideos = itemtypes.MusicVideos(embycursor, kodicursor)
views = emby_db.getView_byType('musicvideos')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
# Pull the list of musicvideos in Kodi
try:
@ -1202,7 +1204,7 @@ class ManualSync(LibrarySync):
# Only update if musicvideo is not in Kodi or checksum is different
updatelist.append(itemid)
log("MusicVideos to update for %s: %s" % (viewName, updatelist), 1)
log.info("MusicVideos to update for %s: %s" % (viewName, updatelist))
embymvideos = self.emby.getFullItems(updatelist)
total = len(updatelist)
del updatelist[:]
@ -1229,7 +1231,7 @@ class ManualSync(LibrarySync):
if kodimvideo not in all_embymvideosIds:
mvideos.remove(kodimvideo)
else:
log("MusicVideos compare finished.", 1)
log.info("MusicVideos compare finished.")
return True
@ -1241,7 +1243,7 @@ class ManualSync(LibrarySync):
views = emby_db.getView_byType('tvshows')
views += emby_db.getView_byType('mixed')
log("Media folders: %s" % views, 1)
log.info("Media folders: %s" % views)
# Pull the list of tvshows and episodes in Kodi
try:
@ -1288,7 +1290,7 @@ class ManualSync(LibrarySync):
# Only update if movie is not in Kodi or checksum is different
updatelist.append(itemid)
log("TVShows to update for %s: %s" % (viewName, updatelist), 1)
log.info("TVShows to update for %s: %s" % (viewName, updatelist))
embytvshows = self.emby.getFullItems(updatelist)
total = len(updatelist)
del updatelist[:]
@ -1332,7 +1334,7 @@ class ManualSync(LibrarySync):
# Only update if movie is not in Kodi or checksum is different
updatelist.append(itemid)
log("Episodes to update for %s: %s" % (viewName, updatelist), 1)
log.info("Episodes to update for %s: %s" % (viewName, updatelist))
embyepisodes = self.emby.getFullItems(updatelist)
total = len(updatelist)
del updatelist[:]
@ -1357,13 +1359,13 @@ class ManualSync(LibrarySync):
if koditvshow not in all_embytvshowsIds:
tvshows.remove(koditvshow)
else:
log("TVShows compare finished.", 1)
log.info("TVShows compare finished.")
for kodiepisode in all_kodiepisodes:
if kodiepisode not in all_embyepisodesIds:
tvshows.remove(kodiepisode)
else:
log("Episodes compare finished.", 1)
log.info("Episodes compare finished.")
return True
@ -1429,7 +1431,7 @@ class ManualSync(LibrarySync):
if all_kodisongs.get(itemid) != API.getChecksum():
# Only update if songs is not in Kodi or checksum is different
updatelist.append(itemid)
log("%s to update: %s" % (data_type, updatelist), 1)
log.info("%s to update: %s" % (data_type, updatelist))
embyitems = self.emby.getFullItems(updatelist)
total = len(updatelist)
del updatelist[:]
@ -1450,15 +1452,15 @@ class ManualSync(LibrarySync):
if kodiartist not in all_embyartistsIds and all_kodiartists[kodiartist] is not None:
music.remove(kodiartist)
else:
log("Artist compare finished.", 1)
log.info("Artist compare finished.")
for kodialbum in all_kodialbums:
if kodialbum not in all_embyalbumsIds:
music.remove(kodialbum)
else:
log("Albums compare finished.", 1)
log.info("Albums compare finished.")
for kodisong in all_kodisongs:
if kodisong not in all_embysongsIds:
music.remove(kodisong)
else:
log("Songs compare finished.", 1)
log.info("Songs compare finished.")
return True

View file

@ -0,0 +1,73 @@
# -*- coding: utf-8 -*-
##################################################################################################
import logging
import xbmc
from utils import window
##################################################################################################
def config():
logger = logging.getLogger('EMBY')
logger.addHandler(LogHandler())
logger.setLevel(logging.DEBUG)
class LogHandler(logging.StreamHandler):
def __init__(self):
logging.StreamHandler.__init__(self)
self.setFormatter(MyFormatter())
def emit(self, record):
if self._getLogLevel(record.levelno):
try:
xbmc.log(self.format(record))
except UnicodeEncodeError:
xbmc.log(self.format(record).encode('utf-8'))
def _getLogLevel(self, level):
levels = {
logging.ERROR: 0,
logging.WARNING: 0,
logging.INFO: 1,
logging.DEBUG: 2,
}
try:
logLevel = int(window('emby_logLevel'))
except ValueError:
logLevel = 0
return logLevel >= levels[level]
class MyFormatter(logging.Formatter):
def __init__(self, fmt="%(name)s -> %(message)s"):
logging.Formatter.__init__(self, fmt)
def format(self, record):
# Save the original format configured by the user
# when the logger formatter was instantiated
format_orig = self._fmt
# Replace the original format with one customized by logging level
if record.levelno in (logging.DEBUG, logging.ERROR):
self._fmt = '%(name)s -> %(levelname)s:: %(message)s'
# Call the original formatter class to do the grunt work
result = logging.Formatter.format(self, record)
# Restore the original format configured by the user
self._fmt = format_orig
return result

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import os
import xbmc
@ -14,8 +15,11 @@ from mutagen import id3
import base64
import read_embyserver as embyserver
from utils import Logging, window
log = Logging('MusicTools').log
from utils import window
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -25,7 +29,7 @@ def getRealFileName(filename, isTemp=False):
#get the filename path accessible by python if possible...
if not xbmcvfs.exists(filename):
log("File does not exist! %s" % filename, 0)
log.warn("File does not exist! %s" % filename)
return (False, "")
#if we use os.path method on older python versions (sunch as some android builds), we need to pass arguments as string
@ -102,7 +106,7 @@ def getAdditionalSongTags(embyid, emby_rating, API, kodicursor, emby_db, enablei
elif file_rating is None and not currentvalue:
return (emby_rating, comment, False)
log("getAdditionalSongTags --> embyid: %s - emby_rating: %s - file_rating: %s - current rating in kodidb: %s" %(embyid, emby_rating, file_rating, currentvalue))
log.info("getAdditionalSongTags --> embyid: %s - emby_rating: %s - file_rating: %s - current rating in kodidb: %s" %(embyid, emby_rating, file_rating, currentvalue))
updateFileRating = False
updateEmbyRating = False
@ -181,7 +185,7 @@ def getSongTags(file):
hasEmbeddedCover = False
isTemp,filename = getRealFileName(file)
log( "getting song ID3 tags for " + filename)
log.info( "getting song ID3 tags for " + filename)
try:
###### FLAC FILES #############
@ -215,14 +219,14 @@ def getSongTags(file):
#POPM rating is 0-255 and needs to be converted to 0-5 range
if rating > 5: rating = (rating / 255) * 5
else:
log( "Not supported fileformat or unable to access file: %s" %(filename))
log.info( "Not supported fileformat or unable to access file: %s" %(filename))
#the rating must be a round value
rating = int(round(rating,0))
except Exception as e:
#file in use ?
log("Exception in getSongTags %s" % e,0)
log.error("Exception in getSongTags %s" % e)
rating = None
#remove tempfile if needed....
@ -244,7 +248,7 @@ def updateRatingToFile(rating, file):
xbmcvfs.copy(file, tempfile)
tempfile = xbmc.translatePath(tempfile).decode("utf-8")
log( "setting song rating: %s for filename: %s - using tempfile: %s" %(rating,file,tempfile))
log.info( "setting song rating: %s for filename: %s - using tempfile: %s" %(rating,file,tempfile))
if not tempfile:
return
@ -261,7 +265,7 @@ def updateRatingToFile(rating, file):
audio.add(id3.POPM(email="Windows Media Player 9 Series", rating=calcrating, count=1))
audio.save()
else:
log( "Not supported fileformat: %s" %(tempfile))
log.info( "Not supported fileformat: %s" %(tempfile))
#once we have succesfully written the flags we move the temp file to destination, otherwise not proceeding and just delete the temp
#safety check: we check the file size of the temp file before proceeding with overwite of original file
@ -272,14 +276,14 @@ def updateRatingToFile(rating, file):
xbmcvfs.delete(file)
xbmcvfs.copy(tempfile,file)
else:
log( "Checksum mismatch for filename: %s - using tempfile: %s - not proceeding with file overwite!" %(rating,file,tempfile))
log.info( "Checksum mismatch for filename: %s - using tempfile: %s - not proceeding with file overwite!" %(rating,file,tempfile))
#always delete the tempfile
xbmcvfs.delete(tempfile)
except Exception as e:
#file in use ?
log("Exception in updateRatingToFile %s" %e,0)
log.error("Exception in updateRatingToFile %s" % e)

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import sys
import xbmc
@ -11,13 +12,16 @@ import xbmcplugin
import api
import artwork
import clientinfo
import downloadutils
import playutils as putils
import playlist
import read_embyserver as embyserver
import shutil
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -27,14 +31,9 @@ class PlaybackUtils():
def __init__(self, item):
global log
log = Logging(self.__class__.__name__).log
self.item = item
self.API = api.API(self.item)
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.doUtils = downloadutils.DownloadUtils().downloadUrl
self.userid = window('emby_currUser')
@ -50,7 +49,7 @@ class PlaybackUtils():
listitem = xbmcgui.ListItem()
playutils = putils.PlayUtils(self.item)
log("Play called.", 1)
log.info("Play called.")
playurl = playutils.getPlayUrl()
if not playurl:
return xbmcplugin.setResolvedUrl(int(sys.argv[1]), False, listitem)
@ -73,9 +72,9 @@ class PlaybackUtils():
introsPlaylist = False
dummyPlaylist = False
log("Playlist start position: %s" % startPos, 2)
log("Playlist plugin position: %s" % currentPosition, 2)
log("Playlist size: %s" % sizePlaylist, 2)
log.debug("Playlist start position: %s" % startPos)
log.debug("Playlist plugin position: %s" % currentPosition)
log.debug("Playlist size: %s" % sizePlaylist)
############### RESUME POINT ################
@ -87,11 +86,11 @@ class PlaybackUtils():
if not propertiesPlayback:
window('emby_playbackProps', value="true")
log("Setting up properties in playlist.", 1)
log.info("Setting up properties in playlist.")
if not homeScreen and not seektime and window('emby_customPlaylist') != "true":
log("Adding dummy file to playlist.", 2)
log.debug("Adding dummy file to playlist.")
dummyPlaylist = True
playlist.add(playurl, listitem, index=startPos)
# Remove the original item from playlist
@ -115,14 +114,14 @@ class PlaybackUtils():
if not resp:
# User selected to not play trailers
getTrailers = False
log("Skip trailers.", 1)
log.info("Skip trailers.")
if getTrailers:
for intro in intros['Items']:
# The server randomly returns intros, process them.
introListItem = xbmcgui.ListItem()
introPlayurl = putils.PlayUtils(intro).getPlayUrl()
log("Adding Intro: %s" % introPlayurl, 1)
log.info("Adding Intro: %s" % introPlayurl)
# Set listitem and properties for intros
pbutils = PlaybackUtils(intro)
@ -138,7 +137,7 @@ class PlaybackUtils():
if homeScreen and not seektime and not sizePlaylist:
# Extend our current playlist with the actual item to play
# only if there's no playlist first
log("Adding main item to playlist.", 1)
log.info("Adding main item to playlist.")
self.pl.addtoPlaylist(dbid, self.item['Type'].lower())
# Ensure that additional parts are played after the main item
@ -155,7 +154,7 @@ class PlaybackUtils():
additionalListItem = xbmcgui.ListItem()
additionalPlayurl = putils.PlayUtils(part).getPlayUrl()
log("Adding additional part: %s" % partcount, 1)
log.info("Adding additional part: %s" % partcount)
# Set listitem and properties for each additional parts
pbutils = PlaybackUtils(part)
@ -169,13 +168,13 @@ class PlaybackUtils():
if dummyPlaylist:
# Added a dummy file to the playlist,
# because the first item is going to fail automatically.
log("Processed as a playlist. First item is skipped.", 1)
log.info("Processed as a playlist. First item is skipped.")
return xbmcplugin.setResolvedUrl(int(sys.argv[1]), False, listitem)
# We just skipped adding properties. Reset flag for next time.
elif propertiesPlayback:
log("Resetting properties playback flag.", 2)
log.debug("Resetting properties playback flag.")
window('emby_playbackProps', clear=True)
#self.pl.verifyPlaylist()
@ -185,7 +184,7 @@ class PlaybackUtils():
if window('emby_%s.playmethod' % playurl) == "Transcode":
# Filter ISO since Emby does not probe anymore
if self.item.get('VideoType') == "Iso":
log("Skipping audio/subs prompt, ISO detected.", 1)
log.info("Skipping audio/subs prompt, ISO detected.")
else:
playurl = playutils.audioSubsPref(playurl, listitem)
window('emby_%s.playmethod' % playurl, value="Transcode")
@ -196,18 +195,18 @@ class PlaybackUtils():
############### PLAYBACK ################
if homeScreen and seektime and window('emby_customPlaylist') != "true":
log("Play as a widget item.", 1)
log.info("Play as a widget item.")
self.setListItem(listitem)
xbmcplugin.setResolvedUrl(int(sys.argv[1]), True, listitem)
elif ((introsPlaylist and window('emby_customPlaylist') == "true") or
(homeScreen and not sizePlaylist)):
# Playlist was created just now, play it.
log("Play playlist.", 1)
log.info("Play playlist.")
xbmc.Player().play(playlist, startpos=startPos)
else:
log("Play as a regular item.", 1)
log.info("Play as a regular item.")
xbmcplugin.setResolvedUrl(int(sys.argv[1]), True, listitem)
def setProperties(self, playurl, listitem):

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import xbmc
import xbmcgui
@ -11,7 +12,11 @@ import clientinfo
import downloadutils
import kodidb_functions as kodidb
import websocket_client as wsc
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -28,18 +33,14 @@ class Player(xbmc.Player):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.doUtils = downloadutils.DownloadUtils().downloadUrl
self.ws = wsc.WebSocket_Client()
self.xbmcplayer = xbmc.Player()
log("Starting playback monitor.", 2)
log.debug("Starting playback monitor.")
def GetPlayStats(self):
@ -63,7 +64,7 @@ class Player(xbmc.Player):
except: pass
if count == 5: # try 5 times
log("Cancelling playback report...", 1)
log.info("Cancelling playback report...")
break
else: count += 1
@ -80,12 +81,12 @@ class Player(xbmc.Player):
xbmc.sleep(200)
itemId = window("emby_%s.itemid" % currentFile)
if tryCount == 20: # try 20 times or about 10 seconds
log("Could not find itemId, cancelling playback report...", 1)
log.info("Could not find itemId, cancelling playback report...")
break
else: tryCount += 1
else:
log("ONPLAYBACK_STARTED: %s itemid: %s" % (currentFile, itemId), 0)
log.info("ONPLAYBACK_STARTED: %s itemid: %s" % (currentFile, itemId))
# Only proceed if an itemId was found.
embyitem = "emby_%s" % currentFile
@ -98,7 +99,7 @@ class Player(xbmc.Player):
customseek = window('emby_customPlaylist.seektime')
if window('emby_customPlaylist') == "true" and customseek:
# Start at, when using custom playlist (play to Kodi from webclient)
log("Seeking to: %s" % customseek, 1)
log.info("Seeking to: %s" % customseek)
self.xbmcplayer.seekTime(int(customseek)/10000000.0)
window('emby_customPlaylist.seektime', clear=True)
@ -185,7 +186,7 @@ class Player(xbmc.Player):
if mapping: # Set in playbackutils.py
log("Mapping for external subtitles index: %s" % mapping, 2)
log.debug("Mapping for external subtitles index: %s" % mapping)
externalIndex = json.loads(mapping)
if externalIndex.get(str(indexSubs)):
@ -203,7 +204,7 @@ class Player(xbmc.Player):
# Post playback to server
log("Sending POST play started: %s." % postdata, 2)
log.debug("Sending POST play started: %s." % postdata)
self.doUtils(url, postBody=postdata, action_type="POST")
# Ensure we do have a runtime
@ -211,7 +212,7 @@ class Player(xbmc.Player):
runtime = int(runtime)
except ValueError:
runtime = self.xbmcplayer.getTotalTime()
log("Runtime is missing, Kodi runtime: %s" % runtime, 1)
log.info("Runtime is missing, Kodi runtime: %s" % runtime)
# Save data map for updates and position calls
data = {
@ -228,7 +229,7 @@ class Player(xbmc.Player):
}
self.played_info[currentFile] = data
log("ADDING_FILE: %s" % self.played_info, 1)
log.info("ADDING_FILE: %s" % self.played_info)
# log some playback stats
'''if(itemType != None):
@ -247,7 +248,7 @@ class Player(xbmc.Player):
def reportPlayback(self):
log("reportPlayback Called", 2)
log.debug("reportPlayback Called")
# Get current file
currentFile = self.currentFile
@ -345,7 +346,7 @@ class Player(xbmc.Player):
if mapping: # Set in PlaybackUtils.py
log("Mapping for external subtitles index: %s" % mapping, 2)
log.debug("Mapping for external subtitles index: %s" % mapping)
externalIndex = json.loads(mapping)
if externalIndex.get(str(indexSubs)):
@ -365,13 +366,13 @@ class Player(xbmc.Player):
# Report progress via websocketclient
postdata = json.dumps(postdata)
log("Report: %s" % postdata, 2)
log.debug("Report: %s" % postdata)
self.ws.sendProgressUpdate(postdata)
def onPlayBackPaused(self):
currentFile = self.currentFile
log("PLAYBACK_PAUSED: %s" % currentFile, 2)
log.debug("PLAYBACK_PAUSED: %s" % currentFile)
if self.played_info.get(currentFile):
self.played_info[currentFile]['paused'] = True
@ -381,7 +382,7 @@ class Player(xbmc.Player):
def onPlayBackResumed(self):
currentFile = self.currentFile
log("PLAYBACK_RESUMED: %s" % currentFile, 2)
log.debug("PLAYBACK_RESUMED: %s" % currentFile)
if self.played_info.get(currentFile):
self.played_info[currentFile]['paused'] = False
@ -391,7 +392,7 @@ class Player(xbmc.Player):
def onPlayBackSeek(self, time, seekOffset):
# Make position when seeking a bit more accurate
currentFile = self.currentFile
log("PLAYBACK_SEEK: %s" % currentFile, 2)
log.debug("PLAYBACK_SEEK: %s" % currentFile)
if self.played_info.get(currentFile):
position = self.xbmcplayer.getTime()
@ -401,16 +402,16 @@ class Player(xbmc.Player):
def onPlayBackStopped(self):
# Will be called when user stops xbmc playing a file
log("ONPLAYBACK_STOPPED", 2)
log.debug("ONPLAYBACK_STOPPED")
window('emby_customPlaylist', clear=True)
window('emby_customPlaylist.seektime', clear=True)
window('emby_playbackProps', clear=True)
log("Clear playlist properties.", 1)
log.info("Clear playlist properties.")
self.stopAll()
def onPlayBackEnded(self):
# Will be called when xbmc stops playing a file
log("ONPLAYBACK_ENDED", 2)
log.debug("ONPLAYBACK_ENDED")
window('emby_customPlaylist.seektime', clear=True)
self.stopAll()
@ -419,15 +420,15 @@ class Player(xbmc.Player):
if not self.played_info:
return
log("Played_information: %s" % self.played_info, 1)
log.info("Played_information: %s" % self.played_info)
# Process each items
for item in self.played_info:
data = self.played_info.get(item)
if data:
log("Item path: %s" % item, 2)
log("Item data: %s" % data, 2)
log.debug("Item path: %s" % item)
log.debug("Item data: %s" % data)
runtime = data['runtime']
currentPosition = data['currentPosition']
@ -448,8 +449,8 @@ class Player(xbmc.Player):
percentComplete = 0
markPlayedAt = float(settings('markPlayed')) / 100
log("Percent complete: %s Mark played at: %s"
% (percentComplete, markPlayedAt), 1)
log.info("Percent complete: %s Mark played at: %s"
% (percentComplete, markPlayedAt))
# Send the delete action to the server.
offerDelete = False
@ -467,16 +468,16 @@ class Player(xbmc.Player):
resp = xbmcgui.Dialog().yesno(lang(30091), lang(33015), autoclose=120000)
if resp:
url = "{server}/emby/Items/%s?format=json" % itemid
log("Deleting request: %s" % itemid, 1)
log.info("Deleting request: %s" % itemid)
self.doUtils(url, action_type="DELETE")
else:
log("User skipped deletion.", 1)
log.info("User skipped deletion.")
self.stopPlayback(data)
# Stop transcoding
if playMethod == "Transcode":
log("Transcoding for %s terminated." % itemid, 1)
log.info("Transcoding for %s terminated." % itemid)
deviceId = self.clientInfo.getDeviceId()
url = "{server}/emby/Videos/ActiveEncodings?DeviceId=%s" % deviceId
self.doUtils(url, action_type="DELETE")
@ -485,7 +486,7 @@ class Player(xbmc.Player):
def stopPlayback(self, data):
log("stopPlayback called", 2)
log.debug("stopPlayback called")
itemId = data['item_id']
currentPosition = data['currentPosition']

View file

@ -3,17 +3,21 @@
#################################################################################################
import json
import logging
import xbmc
import xbmcgui
import xbmcplugin
import clientinfo
import playutils
import playbackutils
import embydb_functions as embydb
import read_embyserver as embyserver
from utils import Logging, window, settings, language as lang, kodiSQL
from utils import window, settings, language as lang, kodiSQL
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -23,12 +27,6 @@ class Playlist():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.userid = window('emby_currUser')
self.server = window('emby_server%s' % self.userid)
@ -45,8 +43,8 @@ class Playlist():
playlist = xbmc.PlayList(xbmc.PLAYLIST_VIDEO)
playlist.clear()
log("---*** PLAY ALL ***---", 1)
log("Items: %s and start at: %s" % (itemids, startat), 1)
log.info("---*** PLAY ALL ***---")
log.info("Items: %s and start at: %s" % (itemids, startat))
started = False
window('emby_customplaylist', value="true")
@ -62,14 +60,14 @@ class Playlist():
mediatype = embydb_item[4]
except TypeError:
# Item is not found in our database, add item manually
log("Item was not found in the database, manually adding item.", 1)
log.info("Item was not found in the database, manually adding item.")
item = self.emby.getItem(itemid)
self.addtoPlaylist_xbmc(playlist, item)
else:
# Add to playlist
self.addtoPlaylist(dbid, mediatype)
log("Adding %s to playlist." % itemid, 1)
log.info("Adding %s to playlist." % itemid)
if not started:
started = True
@ -84,8 +82,8 @@ class Playlist():
embycursor = embyconn.cursor()
emby_db = embydb.Embydb_Functions(embycursor)
log("---*** ADD TO PLAYLIST ***---", 1)
log("Items: %s" % itemids, 1)
log.info("---*** ADD TO PLAYLIST ***---")
log.info("Items: %s" % itemids)
player = xbmc.Player()
playlist = xbmc.PlayList(xbmc.PLAYLIST_VIDEO)
@ -103,7 +101,7 @@ class Playlist():
# Add to playlist
self.addtoPlaylist(dbid, mediatype)
log("Adding %s to playlist." % itemid, 1)
log.info("Adding %s to playlist." % itemid)
self.verifyPlaylist()
embycursor.close()
@ -126,17 +124,17 @@ class Playlist():
else:
pl['params']['item'] = {'file': url}
log(xbmc.executeJSONRPC(json.dumps(pl)), 2)
log.debug(xbmc.executeJSONRPC(json.dumps(pl)))
def addtoPlaylist_xbmc(self, playlist, item):
playurl = playutils.PlayUtils(item).getPlayUrl()
if not playurl:
# Playurl failed
log("Failed to retrieve playurl.", 1)
log.info("Failed to retrieve playurl.")
return
log("Playurl: %s" % playurl)
log.info("Playurl: %s" % playurl)
listitem = xbmcgui.ListItem()
playbackutils.PlaybackUtils(item).setProperties(playurl, listitem)
@ -160,7 +158,7 @@ class Playlist():
else:
pl['params']['item'] = {'file': url}
log(xbmc.executeJSONRPC(json.dumps(pl)), 2)
log.debug(xbmc.executeJSONRPC(json.dumps(pl)))
def verifyPlaylist(self):
@ -174,7 +172,7 @@ class Playlist():
'playlistid': 1
}
}
log(xbmc.executeJSONRPC(json.dumps(pl)), 2)
log.debug(xbmc.executeJSONRPC(json.dumps(pl)))
def removefromPlaylist(self, position):
@ -189,4 +187,4 @@ class Playlist():
'position': position
}
}
log(xbmc.executeJSONRPC(json.dumps(pl)), 2)
log.debug(xbmc.executeJSONRPC(json.dumps(pl)))

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import sys
import xbmc
@ -9,7 +10,11 @@ import xbmcgui
import xbmcvfs
import clientinfo
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -19,12 +24,8 @@ class PlayUtils():
def __init__(self, item):
global log
log = Logging(self.__class__.__name__).log
self.item = item
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.userid = window('emby_currUser')
self.server = window('emby_server%s' % self.userid)
@ -37,19 +38,19 @@ class PlayUtils():
if (self.item.get('Type') in ("Recording", "TvChannel") and self.item.get('MediaSources')
and self.item['MediaSources'][0]['Protocol'] == "Http"):
# Play LiveTV or recordings
log("File protocol is http (livetv).", 1)
log.info("File protocol is http (livetv).")
playurl = "%s/emby/Videos/%s/stream.ts?audioCodec=copy&videoCodec=copy" % (self.server, self.item['Id'])
window('emby_%s.playmethod' % playurl, value="Transcode")
elif self.item.get('MediaSources') and self.item['MediaSources'][0]['Protocol'] == "Http":
# Only play as http, used for channels, or online hosting of content
log("File protocol is http.", 1)
log.info("File protocol is http.")
playurl = self.httpPlay()
window('emby_%s.playmethod' % playurl, value="DirectStream")
elif self.isDirectPlay():
log("File is direct playing.", 1)
log.info("File is direct playing.")
playurl = self.directPlay()
playurl = playurl.encode('utf-8')
# Set playmethod property
@ -57,14 +58,14 @@ class PlayUtils():
elif self.isDirectStream():
log("File is direct streaming.", 1)
log.info("File is direct streaming.")
playurl = self.directStream()
# Set playmethod property
window('emby_%s.playmethod' % playurl, value="DirectStream")
elif self.isTranscoding():
log("File is transcoding.", 1)
log.info("File is transcoding.")
playurl = self.transcoding()
# Set playmethod property
window('emby_%s.playmethod' % playurl, value="Transcode")
@ -89,7 +90,7 @@ class PlayUtils():
# Requirement: Filesystem, Accessible path
if settings('playFromStream') == "true":
# User forcing to play via HTTP
log("Can't direct play, play from HTTP enabled.", 1)
log.info("Can't direct play, play from HTTP enabled.")
return False
videotrack = self.item['MediaSources'][0]['Name']
@ -109,23 +110,23 @@ class PlayUtils():
'2': 720,
'3': 1080
}
log("Resolution is: %sP, transcode for resolution: %sP+"
% (resolution, res[transcodeH265]), 1)
log.info("Resolution is: %sP, transcode for resolution: %sP+"
% (resolution, res[transcodeH265]))
if res[transcodeH265] <= resolution:
return False
canDirectPlay = self.item['MediaSources'][0]['SupportsDirectPlay']
# Make sure direct play is supported by the server
if not canDirectPlay:
log("Can't direct play, server doesn't allow/support it.", 1)
log.info("Can't direct play, server doesn't allow/support it.")
return False
location = self.item['LocationType']
if location == "FileSystem":
# Verify the path
if not self.fileExists():
log("Unable to direct play.", 1)
log(self.directPlay(), 1)
log.info("Unable to direct play.")
log.info(self.directPlay())
xbmcgui.Dialog().ok(
heading=lang(29999),
line1=lang(33011),
@ -167,18 +168,18 @@ class PlayUtils():
# Convert path to direct play
path = self.directPlay()
log("Verifying path: %s" % path, 1)
log.info("Verifying path: %s" % path)
if xbmcvfs.exists(path):
log("Path exists.", 1)
log.info("Path exists.")
return True
elif ":" not in path:
log("Can't verify path, assumed linux. Still try to direct play.", 1)
log.info("Can't verify path, assumed linux. Still try to direct play.")
return True
else:
log("Failed to find file.", 1)
log.info("Failed to find file.")
return False
def isDirectStream(self):
@ -200,8 +201,8 @@ class PlayUtils():
'2': 720,
'3': 1080
}
log("Resolution is: %sP, transcode for resolution: %sP+"
% (resolution, res[transcodeH265]), 1)
log.info("Resolution is: %sP, transcode for resolution: %sP+"
% (resolution, res[transcodeH265]))
if res[transcodeH265] <= resolution:
return False
@ -213,7 +214,7 @@ class PlayUtils():
# Verify the bitrate
if not self.isNetworkSufficient():
log("The network speed is insufficient to direct stream file.", 1)
log.info("The network speed is insufficient to direct stream file.")
return False
return True
@ -237,10 +238,10 @@ class PlayUtils():
try:
sourceBitrate = int(self.item['MediaSources'][0]['Bitrate'])
except (KeyError, TypeError):
log("Bitrate value is missing.", 1)
log.info("Bitrate value is missing.")
else:
log("The add-on settings bitrate is: %s, the video bitrate required is: %s"
% (settings, sourceBitrate), 1)
log.info("The add-on settings bitrate is: %s, the video bitrate required is: %s"
% (settings, sourceBitrate))
if settings < sourceBitrate:
return False

View file

@ -2,11 +2,16 @@
#################################################################################################
import logging
import xbmc
import clientinfo
import downloadutils
from utils import Logging, window, settings, kodiSQL
from utils import window, settings, kodiSQL
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -18,11 +23,6 @@ class Read_EmbyServer():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.doUtils = downloadutils.DownloadUtils().downloadUrl
self.userId = window('emby_currUser')
@ -211,7 +211,7 @@ class Read_EmbyServer():
items['TotalRecordCount'] = total
except TypeError: # Failed to retrieve
log("%s:%s Failed to retrieve the server response." % (url, params), 2)
log.debug("%s:%s Failed to retrieve the server response." % (url, params))
else:
index = 0
@ -253,27 +253,27 @@ class Read_EmbyServer():
# Something happened to the connection
if not throttled:
throttled = True
log("Throttle activated.", 1)
log.info("Throttle activated.")
if jump == highestjump:
# We already tried with the highestjump, but it failed. Reset value.
log("Reset highest value.", 1)
log.info("Reset highest value.")
highestjump = 0
# Lower the number by half
if highestjump:
throttled = False
jump = highestjump
log("Throttle deactivated.", 1)
log.info("Throttle deactivated.")
else:
jump = int(jump/4)
log("Set jump limit to recover: %s" % jump, 2)
log.debug("Set jump limit to recover: %s" % jump)
retry = 0
while window('emby_online') != "true":
# Wait server to come back online
if retry == 5:
log("Unable to reconnect to server. Abort process.", 1)
log.info("Unable to reconnect to server. Abort process.")
return items
retry += 1
@ -301,7 +301,7 @@ class Read_EmbyServer():
increment = 10
jump += increment
log("Increase jump limit to: %s" % jump, 1)
log.info("Increase jump limit to: %s" % jump)
return items
def getViews(self, mediatype="", root=False, sortedlist=False):
@ -318,7 +318,7 @@ class Read_EmbyServer():
try:
items = result['Items']
except TypeError:
log("Error retrieving views for type: %s" % mediatype, 2)
log.debug("Error retrieving views for type: %s" % mediatype)
else:
for item in items:
@ -462,7 +462,7 @@ class Read_EmbyServer():
items['TotalRecordCount'] = total
except TypeError: # Failed to retrieve
log("%s:%s Failed to retrieve the server response." % (url, params), 2)
log.debug("%s:%s Failed to retrieve the server response." % (url, params))
else:
index = 1
@ -550,9 +550,9 @@ class Read_EmbyServer():
url = "{server}/emby/Users/{UserId}/FavoriteItems/%s?format=json" % itemid
doUtils(url, action_type="DELETE")
else:
log("Error processing user rating.", 1)
log.info("Error processing user rating.")
log("Update user rating to emby for itemid: %s | favourite: %s" % (itemid, favourite), 1)
log.info("Update user rating to emby for itemid: %s | favourite: %s" % (itemid, favourite))
def refreshItem(self, itemid):

View file

@ -3,6 +3,7 @@
##################################################################################################
import hashlib
import logging
import threading
import xbmc
@ -13,7 +14,11 @@ import xbmcvfs
import artwork
import clientinfo
import downloadutils
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
@ -39,13 +44,9 @@ class UserClient(threading.Thread):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
self.addon = xbmcaddon.Addon()
self.addonName = clientinfo.ClientInfo().getAddonName()
self.doUtils = downloadutils.DownloadUtils()
threading.Thread.__init__(self)
@ -63,7 +64,7 @@ class UserClient(threading.Thread):
username = settings('username')
if not username:
log("No username saved.", 2)
log.debug("No username saved.")
return ""
return username
@ -88,17 +89,17 @@ class UserClient(threading.Thread):
if not s_userId:
# Save access token if it's missing from settings
settings('userId%s' % username, value=w_userId)
log("Returning userId from WINDOW for username: %s UserId: %s"
% (username, w_userId), 2)
log.debug("Returning userId from WINDOW for username: %s UserId: %s"
% (username, w_userId))
return w_userId
# Verify the settings
elif s_userId:
log("Returning userId from SETTINGS for username: %s userId: %s"
% (username, s_userId), 2)
log.debug("Returning userId from SETTINGS for username: %s userId: %s"
% (username, s_userId))
return s_userId
# No userId found
else:
log("No userId saved for username: %s." % username, 1)
log.info("No userId saved for username: %s." % username)
def getServer(self, prefix=True):
@ -117,7 +118,7 @@ class UserClient(threading.Thread):
server = host + ":" + port
if not host:
log("No server information saved.", 2)
log.debug("No server information saved.")
return False
# If https is true
@ -144,17 +145,17 @@ class UserClient(threading.Thread):
if not s_token:
# Save access token if it's missing from settings
settings('accessToken', value=w_token)
log("Returning accessToken from WINDOW for username: %s accessToken: %s"
% (username, w_token), 2)
log.debug("Returning accessToken from WINDOW for username: %s accessToken: %s"
% (username, w_token))
return w_token
# Verify the settings
elif s_token:
log("Returning accessToken from SETTINGS for username: %s accessToken: %s"
% (username, s_token), 2)
log.debug("Returning accessToken from SETTINGS for username: %s accessToken: %s"
% (username, s_token))
window('emby_accessToken%s' % username, value=s_token)
return s_token
else:
log("No token found.", 1)
log.info("No token found.")
return ""
def getSSLverify(self):
@ -210,7 +211,7 @@ class UserClient(threading.Thread):
if result == False:
# Access is restricted, set in downloadutils.py via exception
log("Access is restricted.", 1)
log.info("Access is restricted.")
self.HasAccess = False
elif window('emby_online') != "true":
@ -218,7 +219,7 @@ class UserClient(threading.Thread):
pass
elif window('emby_serverStatus') == "restricted":
log("Access is granted.", 1)
log.info("Access is granted.")
self.HasAccess = True
window('emby_serverStatus', clear=True)
xbmcgui.Dialog().notification(lang(29999), lang(33007))
@ -283,12 +284,12 @@ class UserClient(threading.Thread):
# If there's no settings.xml
if not hasSettings:
log("No settings.xml found.", 1)
log.info("No settings.xml found.")
self.auth = False
return
# If no user information
elif not server or not username:
log("Missing server information.", 1)
log.info("Missing server information.")
self.auth = False
return
# If there's a token, load the user
@ -298,9 +299,9 @@ class UserClient(threading.Thread):
if result == False:
pass
else:
log("Current user: %s" % self.currUser, 1)
log("Current userId: %s" % self.currUserId, 1)
log("Current accessToken: %s" % self.currToken, 2)
log.info("Current user: %s" % self.currUser)
log.info("Current userId: %s" % self.currUserId)
log.debug("Current accessToken: %s" % self.currToken)
return
##### AUTHENTICATE USER #####
@ -320,7 +321,7 @@ class UserClient(threading.Thread):
option=xbmcgui.ALPHANUM_HIDE_INPUT)
# If password dialog is cancelled
if not password:
log("No password entered.", 0)
log.warn("No password entered.")
window('emby_serverStatus', value="Stop")
self.auth = False
return
@ -335,17 +336,17 @@ class UserClient(threading.Thread):
# Authenticate username and password
data = {'username': username, 'password': sha1}
log(data, 2)
log.debug(data)
url = "%s/emby/Users/AuthenticateByName?format=json" % server
result = self.doUtils.downloadUrl(url, postBody=data, action_type="POST", authenticate=False)
try:
log("Auth response: %s" % result, 1)
log.info("Auth response: %s" % result)
accessToken = result['AccessToken']
except (KeyError, TypeError):
log("Failed to retrieve the api key.", 1)
log.info("Failed to retrieve the api key.")
accessToken = None
if accessToken is not None:
@ -354,20 +355,20 @@ class UserClient(threading.Thread):
"%s %s!" % (lang(33000), self.currUser.decode('utf-8')))
settings('accessToken', value=accessToken)
settings('userId%s' % username, value=result['User']['Id'])
log("User Authenticated: %s" % accessToken, 1)
log.info("User Authenticated: %s" % accessToken)
self.loadCurrUser(authenticated=True)
window('emby_serverStatus', clear=True)
self.retry = 0
else:
log("User authentication failed.", 1)
log.error("User authentication failed.")
settings('accessToken', value="")
settings('userId%s' % username, value="")
dialog.ok(lang(33001), lang(33009))
# Give two attempts at entering password
if self.retry == 2:
log("Too many retries. "
"You can retry by resetting attempts in the addon settings.", 1)
log.info("Too many retries. "
"You can retry by resetting attempts in the addon settings.")
window('emby_serverStatus', value="Stop")
dialog.ok(lang(33001), lang(33010))
@ -376,13 +377,13 @@ class UserClient(threading.Thread):
def resetClient(self):
log("Reset UserClient authentication.", 1)
log.info("Reset UserClient authentication.")
if self.currToken is not None:
# In case of 401, removed saved token
settings('accessToken', value="")
window('emby_accessToken%s' % self.getUserId(), clear=True)
self.currToken = None
log("User token has been removed.", 1)
log.info("User token has been removed.")
self.auth = True
self.currUser = None
@ -390,7 +391,7 @@ class UserClient(threading.Thread):
def run(self):
monitor = xbmc.Monitor()
log("----===## Starting UserClient ##===----", 0)
log.warn("----===## Starting UserClient ##===----")
while not monitor.abortRequested():
@ -425,8 +426,8 @@ class UserClient(threading.Thread):
# The status Stop is for when user cancelled password dialog.
if server and username and status != "Stop":
# Only if there's information found to login
log("Server found: %s" % server, 2)
log("Username found: %s" % username, 2)
log.debug("Server found: %s" % server)
log.debug("Username found: %s" % username)
self.auth = True
@ -439,7 +440,7 @@ class UserClient(threading.Thread):
break
self.doUtils.stopSession()
log("##===---- UserClient Stopped ----===##", 0)
log.warn("##===---- UserClient Stopped ----===##")
def stopClient(self):
# When emby for kodi terminates

View file

@ -5,6 +5,7 @@
import cProfile
import inspect
import json
import logging
import pstats
import sqlite3
import StringIO
@ -19,46 +20,13 @@ import xbmcaddon
import xbmcgui
import xbmcvfs
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
# Main methods
class Logging(object):
def __init__(self, title=""):
self.title = title
def _getLogLevel(self, level):
try:
logLevel = int(window('emby_logLevel'))
except ValueError:
logLevel = 0
return logLevel >= level
def _printMsg(self, title, msg):
try:
xbmc.log("%s -> %s" % (title, msg))
except UnicodeEncodeError:
xbmc.log("%s -> %s" % (title, msg.encode('utf-8')))
def log(self, msg, level=1):
extra = ""
if level == -1:
# Error mode
extra = "::ERROR"
if self._getLogLevel(level):
self._printMsg("EMBY %s%s" % (self.title, extra), msg)
# Initiate class for utils.py document logging
log = Logging('Utils').log
def window(property, value=None, clear=False, window_id=10000):
# Get or set window property
WINDOW = xbmcgui.Window(window_id)
@ -143,7 +111,7 @@ def querySQL(query, args=None, cursor=None, conntype=None):
if cursor is None:
if conntype is None:
log("New connection type is missing.", 1)
log.info("New connection type is missing.")
return result
else:
manualconn = True
@ -153,7 +121,7 @@ def querySQL(query, args=None, cursor=None, conntype=None):
attempts = 0
while attempts < 3:
try:
log("Query: %s Args: %s" % (query, args), 2)
log.debug("Query: %s Args: %s" % (query, args))
if args is None:
result = cursor.execute(query)
else:
@ -161,22 +129,22 @@ def querySQL(query, args=None, cursor=None, conntype=None):
break # Query successful, break out of while loop
except sqlite3.OperationalError as e:
if "database is locked" in e:
log("%s...Attempt: %s" % (e, attempts), 0)
log.warn("%s...Attempt: %s" % (e, attempts))
attempts += 1
xbmc.sleep(1000)
else:
log("Error sqlite3: %s" % e, 0)
log.error(e)
if manualconn:
cursor.close()
raise
except sqlite3.Error as e:
log("Error sqlite3: %s" % e, 0)
log.error(e)
if manualconn:
cursor.close()
raise
else:
failed = True
log("FAILED // Query: %s Args: %s" % (query, args), 1)
log.info("FAILED // Query: %s Args: %s" % (query, args))
if manualconn:
if failed:
@ -185,7 +153,7 @@ def querySQL(query, args=None, cursor=None, conntype=None):
connection.commit()
cursor.close()
log(result, 2)
log.debug(result)
return result
#################################################################################################
@ -219,7 +187,7 @@ def setScreensaver(value):
}
}
result = xbmc.executeJSONRPC(json.dumps(query))
log("Toggling screensaver: %s %s" % (value, result), 1)
log.info("Toggling screensaver: %s %s" % (value, result))
def convertDate(date):
try:
@ -300,7 +268,7 @@ def profiling(sortby="cumulative"):
s = StringIO.StringIO()
ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
ps.print_stats()
log(s.getvalue(), 1)
log.info(s.getvalue())
return result
@ -321,7 +289,7 @@ def reset():
window('emby_shouldStop', value="true")
count = 10
while window('emby_dbScan') == "true":
log("Sync is running, will retry: %s..." % count)
log.info("Sync is running, will retry: %s..." % count)
count -= 1
if count == 0:
dialog.ok(language(29999), language(33085))
@ -335,7 +303,7 @@ def reset():
deleteNodes()
# Wipe the kodi databases
log("Resetting the Kodi video database.", 0)
log.warn("Resetting the Kodi video database.")
connection = kodiSQL('video')
cursor = connection.cursor()
cursor.execute('SELECT tbl_name FROM sqlite_master WHERE type="table"')
@ -348,7 +316,7 @@ def reset():
cursor.close()
if settings('enableMusic') == "true":
log("Resetting the Kodi music database.", 0)
log.warn("Resetting the Kodi music database.")
connection = kodiSQL('music')
cursor = connection.cursor()
cursor.execute('SELECT tbl_name FROM sqlite_master WHERE type="table"')
@ -361,7 +329,7 @@ def reset():
cursor.close()
# Wipe the emby database
log("Resetting the Emby database.", 0)
log.warn("Resetting the Emby database.")
connection = kodiSQL('emby')
cursor = connection.cursor()
cursor.execute('SELECT tbl_name FROM sqlite_master WHERE type="table"')
@ -378,7 +346,7 @@ def reset():
# Offer to wipe cached thumbnails
resp = dialog.yesno(language(29999), language(33086))
if resp:
log("Resetting all cached artwork.", 0)
log.warn("Resetting all cached artwork.")
# Remove all existing textures first
path = xbmc.translatePath("special://thumbnails/").decode('utf-8')
if xbmcvfs.exists(path):
@ -414,7 +382,7 @@ def reset():
addondir = xbmc.translatePath(addon.getAddonInfo('profile')).decode('utf-8')
dataPath = "%ssettings.xml" % addondir
xbmcvfs.delete(dataPath)
log("Deleting: settings.xml", 1)
log.info("Deleting: settings.xml")
dialog.ok(heading=language(29999), line1=language(33088))
xbmc.executebuiltin('RestartApp')
@ -488,11 +456,11 @@ def passwordsXML():
for path in paths:
if path.find('.//from').text == "smb://%s/" % credentials:
paths.remove(path)
log("Successfully removed credentials for: %s" % credentials, 1)
log.info("Successfully removed credentials for: %s" % credentials)
etree.ElementTree(root).write(xmlpath)
break
else:
log("Failed to find saved server: %s in passwords.xml" % credentials, 1)
log.info("Failed to find saved server: %s in passwords.xml" % credentials)
settings('networkCreds', value="")
xbmcgui.Dialog().notification(
@ -541,7 +509,7 @@ def passwordsXML():
# Add credentials
settings('networkCreds', value="%s" % server)
log("Added server: %s to passwords.xml" % server, 1)
log.info("Added server: %s to passwords.xml" % server)
# Prettify and write to file
try:
indent(root)
@ -569,7 +537,7 @@ def playlistXSP(mediatype, tagname, viewid, viewtype="", delete=False):
# Create the playlist directory
if not xbmcvfs.exists(path):
log("Creating directory: %s" % path, 1)
log.info("Creating directory: %s" % path)
xbmcvfs.mkdirs(path)
# Only add the playlist if it doesn't already exists
@ -577,7 +545,7 @@ def playlistXSP(mediatype, tagname, viewid, viewtype="", delete=False):
if delete:
xbmcvfs.delete(xsppath)
log("Successfully removed playlist: %s." % tagname, 1)
log.info("Successfully removed playlist: %s." % tagname)
return
@ -585,11 +553,11 @@ def playlistXSP(mediatype, tagname, viewid, viewtype="", delete=False):
itemtypes = {
'homevideos': "movies"
}
log("Writing playlist file to: %s" % xsppath, 1)
log.info("Writing playlist file to: %s" % xsppath)
try:
f = xbmcvfs.File(xsppath, 'w')
except:
log("Failed to create playlist: %s" % xsppath, 1)
log.info("Failed to create playlist: %s" % xsppath)
return
else:
f.write(
@ -603,7 +571,7 @@ def playlistXSP(mediatype, tagname, viewid, viewtype="", delete=False):
'</smartplaylist>'
% (itemtypes.get(mediatype, mediatype), plname, tagname))
f.close()
log("Successfully added playlist: %s" % tagname, 1)
log.info("Successfully added playlist: %s" % tagname)
def deletePlaylists():
@ -625,10 +593,10 @@ def deleteNodes():
try:
shutil.rmtree("%s%s" % (path, dir.decode('utf-8')))
except:
log("Failed to delete directory: %s" % dir.decode('utf-8'), 0)
log.warn("Failed to delete directory: %s" % dir.decode('utf-8'))
for file in files:
if file.decode('utf-8').startswith('emby'):
try:
xbmcvfs.delete("%s%s" % (path, file.decode('utf-8')))
except:
log("Failed to file: %s" % file.decode('utf-8'), 0)
log.warn("Failed to delete file: %s" % file.decode('utf-8'))

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import shutil
import xml.etree.ElementTree as etree
@ -9,9 +10,12 @@ import xbmc
import xbmcaddon
import xbmcvfs
import clientinfo
import utils
from utils import Logging, window, language as lang
from utils import window, language as lang
#################################################################################################
log = logging.getLogger("EMBY."+__name__)
#################################################################################################
@ -21,12 +25,6 @@ class VideoNodes(object):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
clientInfo = clientinfo.ClientInfo()
self.addonName = clientInfo.getAddonName()
self.kodiversion = int(xbmc.getInfoLabel('System.BuildVersion')[:2])
@ -79,7 +77,7 @@ class VideoNodes(object):
for file in files:
xbmcvfs.delete(nodepath + file)
log("Sucessfully removed videonode: %s." % tagname, 1)
log.info("Sucessfully removed videonode: %s." % tagname)
return
# Create index entry
@ -364,7 +362,7 @@ class VideoNodes(object):
def clearProperties(self):
log("Clearing nodes properties.", 1)
log.info("Clearing nodes properties.")
embyprops = window('Emby.nodes.total')
propnames = [

View file

@ -3,6 +3,7 @@
#################################################################################################
import json
import logging
import threading
import websocket
@ -14,9 +15,13 @@ import downloadutils
import librarysync
import playlist
import userclient
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
#################################################################################################
##################################################################################################
log = logging.getLogger("EMBY."+__name__)
##################################################################################################
class WebSocket_Client(threading.Thread):
@ -29,15 +34,11 @@ class WebSocket_Client(threading.Thread):
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.__dict__ = self._shared_state
self.monitor = xbmc.Monitor()
self.doUtils = downloadutils.DownloadUtils()
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
self.deviceId = self.clientInfo.getDeviceId()
self.librarySync = librarysync.LibrarySync()
@ -46,7 +47,7 @@ class WebSocket_Client(threading.Thread):
def sendProgressUpdate(self, data):
log("sendProgressUpdate", 2)
log.debug("sendProgressUpdate")
try:
messageData = {
@ -55,10 +56,10 @@ class WebSocket_Client(threading.Thread):
}
messageString = json.dumps(messageData)
self.client.send(messageString)
log("Message data: %s" % messageString, 2)
log.debug("Message data: %s" % messageString)
except Exception as e:
log("Exception: %s" % e, 1)
log.exception(e)
def on_message(self, ws, message):
@ -69,7 +70,7 @@ class WebSocket_Client(threading.Thread):
if messageType not in ('SessionEnded'):
# Mute certain events
log("Message: %s" % message, 1)
log.info("Message: %s" % message)
if messageType == "Play":
# A remote control play command has been sent from the server.
@ -118,10 +119,10 @@ class WebSocket_Client(threading.Thread):
seekto = data['SeekPositionTicks']
seektime = seekto / 10000000.0
action(seektime)
log("Seek to %s." % seektime, 1)
log.info("Seek to %s." % seektime)
else:
action()
log("Command: %s completed." % command, 1)
log.info("Command: %s completed." % command)
window('emby_command', value="true")
@ -254,7 +255,7 @@ class WebSocket_Client(threading.Thread):
self.librarySync.refresh_views = True
def on_close(self, ws):
log("Closed.", 2)
log.debug("Closed.")
def on_open(self, ws):
self.doUtils.postCapabilities(self.deviceId)
@ -264,7 +265,7 @@ class WebSocket_Client(threading.Thread):
# Server is offline
pass
else:
log("Error: %s" % error, 2)
log.debug("Error: %s" % error)
def run(self):
@ -281,7 +282,7 @@ class WebSocket_Client(threading.Thread):
server = server.replace('http', "ws")
websocket_url = "%s?api_key=%s&deviceId=%s" % (server, token, self.deviceId)
log("websocket url: %s" % websocket_url, 1)
log.info("websocket url: %s" % websocket_url)
self.client = websocket.WebSocketApp(websocket_url,
on_message=self.on_message,
@ -289,7 +290,7 @@ class WebSocket_Client(threading.Thread):
on_close=self.on_close)
self.client.on_open = self.on_open
log("----===## Starting WebSocketClient ##===----", 0)
log.warn("----===## Starting WebSocketClient ##===----")
while not self.monitor.abortRequested():
@ -301,10 +302,10 @@ class WebSocket_Client(threading.Thread):
# Abort was requested, exit
break
log("##===---- WebSocketClient Stopped ----===##", 0)
log.warn("##===---- WebSocketClient Stopped ----===##")
def stopClient(self):
self.stopWebsocket = True
self.client.close()
log("Stopping thread.", 1)
log.info("Stopping thread.")

View file

@ -2,6 +2,7 @@
#################################################################################################
import logging
import os
import sys
import time
@ -30,7 +31,14 @@ import librarysync
import player
import videonodes
import websocket_client as wsc
from utils import Logging, window, settings, language as lang
from utils import window, settings, language as lang
#################################################################################################
import loghandler
loghandler.config()
log = logging.getLogger("EMBY.service")
#################################################################################################
@ -49,9 +57,6 @@ class Service():
def __init__(self):
global log
log = Logging(self.__class__.__name__).log
self.clientInfo = clientinfo.ClientInfo()
self.addonName = self.clientInfo.getAddonName()
logLevel = userclient.UserClient().getLogLevel()
@ -61,12 +66,12 @@ class Service():
window('emby_kodiProfile', value=xbmc.translatePath('special://profile'))
# Initial logging
log("======== START %s ========" % self.addonName, 0)
log("Platform: %s" % (self.clientInfo.getPlatform()), 0)
log("KODI Version: %s" % xbmc.getInfoLabel('System.BuildVersion'), 0)
log("%s Version: %s" % (self.addonName, self.clientInfo.getVersion()), 0)
log("Using plugin paths: %s" % (settings('useDirectPaths') == "0"), 0)
log("Log Level: %s" % logLevel, 0)
log.warn("======== START %s ========" % self.addonName)
log.warn("Platform: %s" % (self.clientInfo.getPlatform()))
log.warn("KODI Version: %s" % xbmc.getInfoLabel('System.BuildVersion'))
log.warn("%s Version: %s" % (self.addonName, self.clientInfo.getVersion()))
log.warn("Using plugin paths: %s" % (settings('useDirectPaths') == "0"))
log.warn("Log Level: %s" % logLevel)
# Reset window props for profile switch
properties = [
@ -108,8 +113,8 @@ class Service():
if window('emby_kodiProfile') != kodiProfile:
# Profile change happened, terminate this thread and others
log("Kodi profile was: %s and changed to: %s. Terminating old Emby thread."
% (kodiProfile, window('emby_kodiProfile')), 1)
log.info("Kodi profile was: %s and changed to: %s. Terminating old Emby thread."
% (kodiProfile, window('emby_kodiProfile')))
break
@ -151,9 +156,8 @@ class Service():
kplayer.reportPlayback()
lastProgressUpdate = datetime.today()
except Exception as e:
log("Exception in Playback Monitor Service: %s" % e, 1)
pass
except Exception:
log.exception("Exception in Playback Monitor Service")
else:
# Start up events
self.warn_auth = True
@ -192,7 +196,7 @@ class Service():
if (user.currUser is None) and self.warn_auth:
# Alert user is not authenticated and suppress future warning
self.warn_auth = False
log("Not authenticated yet.", 1)
log.info("Not authenticated yet.")
# User access is restricted.
# Keep verifying until access is granted
@ -221,7 +225,7 @@ class Service():
# Server is offline.
# Alert the user and suppress future warning
if self.server_online:
log("Server is offline.", 1)
log.info("Server is offline.")
window('emby_online', value="false")
xbmcgui.Dialog().notification(
@ -235,13 +239,11 @@ class Service():
elif window('emby_online') == "sleep":
# device going to sleep
if self.websocket_running:
log("Stop websocket thread")
ws.stopClient()
ws = wsc.WebSocket_Client()
self.websocket_running = False
if self.library_running:
log("Stop library thread")
library.stopThread()
library = librarysync.LibrarySync()
self.library_running = False
@ -263,12 +265,11 @@ class Service():
sound=False)
self.server_online = True
log("Server is online and ready.", 1)
log.info("Server is online and ready.")
window('emby_online', value="true")
# Start the userclient thread
if not self.userclient_running:
log("Start user thread")
self.userclient_running = True
user.start()
@ -293,14 +294,14 @@ class Service():
if self.websocket_running:
ws.stopClient()
log("======== STOP %s ========" % self.addonName, 0)
log.warn("======== STOP %s ========" % self.addonName)
# Delay option
delay = int(settings('startupDelay'))
xbmc.log("Delaying emby startup by: %s sec..." % delay)
log.info("Delaying emby startup by: %s sec..." % delay)
if delay and xbmc.Monitor().waitForAbort(delay):
# Start the service
xbmc.log("Abort requested while waiting. Emby for kodi not started.")
log.warn("Abort requested while waiting. Emby for kodi not started.")
else:
Service().ServiceEntryPoint()