From d7728afea05f9a37adb56c73e8690cf4112e4d95 Mon Sep 17 00:00:00 2001 From: shaun Date: Tue, 1 Nov 2016 20:48:24 +1100 Subject: [PATCH 1/3] add throttling to error metric logging add back in consumption of exception in function wrapper --- addon.xml | 2 +- changelog.txt | 3 +++ resources/lib/ga_client.py | 16 +++++++++++++++- resources/lib/objects/_common.py | 6 +++--- 4 files changed, 22 insertions(+), 5 deletions(-) diff --git a/addon.xml b/addon.xml index b4476d57..71fcf025 100644 --- a/addon.xml +++ b/addon.xml @@ -1,7 +1,7 @@ diff --git a/changelog.txt b/changelog.txt index 612f9efd..c6b947e5 100644 --- a/changelog.txt +++ b/changelog.txt @@ -1,3 +1,6 @@ +version 2.3.4 +- add throttling for error event logging + version 2.3.3 - minor fix to exception handling diff --git a/resources/lib/ga_client.py b/resources/lib/ga_client.py index d4b476d6..0c70b2f2 100644 --- a/resources/lib/ga_client.py +++ b/resources/lib/ga_client.py @@ -8,6 +8,7 @@ import md5 import xbmc import platform import xbmcgui +import time from utils import window, settings, language as lang log = logging.getLogger("EMBY."+__name__) @@ -15,6 +16,8 @@ log = logging.getLogger("EMBY."+__name__) # for info on the metrics that can be sent to Google Analytics # https://developers.google.com/analytics/devguides/collection/protocol/v1/parameters#events +logEventHistory = {} + class GoogleAnalytics(): testing = False @@ -128,7 +131,18 @@ class GoogleAnalytics(): self.sendData(data) - def sendEventData(self, eventCategory, eventAction, eventLabel=None): + def sendEventData(self, eventCategory, eventAction, eventLabel=None, throttle=False): + + # if throttling is enabled then only log the same event every 60 seconds + if(throttle): + throttleKey = eventCategory + "-" + eventAction + "-" + str(eventLabel) + lastLogged = logEventHistory.get(throttleKey) + if(lastLogged != None): + timeSinceLastLog = time.time() - lastLogged + if(timeSinceLastLog < 60): + log.info("SKIPPING_LOG_EVENT : " + str(timeSinceLastLog) + " " + throttleKey) + return + logEventHistory[throttleKey] = time.time() data = self.getBaseData() data['t'] = 'event' # action type diff --git a/resources/lib/objects/_common.py b/resources/lib/objects/_common.py index 4100cb30..484b602d 100644 --- a/resources/lib/objects/_common.py +++ b/resources/lib/objects/_common.py @@ -22,7 +22,7 @@ ga = GoogleAnalytics() ################################################################################################## -def catch_except(errors=(Exception, )): +def catch_except(errors=(Exception, ), default_value=False): # Will wrap method with try/except and print parameters for easier debugging def decorator(func): def wrapper(*args, **kwargs): @@ -30,11 +30,11 @@ def catch_except(errors=(Exception, )): return func(*args, **kwargs) except errors as error: errStrings = ga.formatException() - ga.sendEventData("Exception", errStrings[0], errStrings[1]) + ga.sendEventData("Exception", errStrings[0], errStrings[1], True) log.exception(error) log.error("function: %s \n args: %s \n kwargs: %s", func.__name__, args, kwargs) - raise + return default_value return wrapper return decorator From 1554a52bf7df720fe7bb036baef1cb65852ffbca Mon Sep 17 00:00:00 2001 From: shaun Date: Wed, 2 Nov 2016 07:08:33 +1100 Subject: [PATCH 2/3] throttling is once every 5 min for an error --- resources/lib/ga_client.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/resources/lib/ga_client.py b/resources/lib/ga_client.py index 0c70b2f2..8a886fc9 100644 --- a/resources/lib/ga_client.py +++ b/resources/lib/ga_client.py @@ -133,13 +133,13 @@ class GoogleAnalytics(): def sendEventData(self, eventCategory, eventAction, eventLabel=None, throttle=False): - # if throttling is enabled then only log the same event every 60 seconds + # if throttling is enabled then only log the same event every 5 min if(throttle): throttleKey = eventCategory + "-" + eventAction + "-" + str(eventLabel) lastLogged = logEventHistory.get(throttleKey) if(lastLogged != None): timeSinceLastLog = time.time() - lastLogged - if(timeSinceLastLog < 60): + if(timeSinceLastLog < 300): log.info("SKIPPING_LOG_EVENT : " + str(timeSinceLastLog) + " " + throttleKey) return logEventHistory[throttleKey] = time.time() From e34734931de3b1ef4022a817efc5ed94780ec909 Mon Sep 17 00:00:00 2001 From: sfaulds Date: Wed, 2 Nov 2016 15:11:04 +1100 Subject: [PATCH 3/3] add wrapper fun for logging errors --- addon.xml | 2 +- resources/lib/ga_client.py | 20 +++++++++++++++++++- resources/lib/kodimonitor.py | 2 ++ resources/lib/player.py | 8 +++++++- resources/lib/websocket_client.py | 2 ++ 5 files changed, 31 insertions(+), 3 deletions(-) diff --git a/addon.xml b/addon.xml index 71fcf025..ddab9325 100644 --- a/addon.xml +++ b/addon.xml @@ -1,7 +1,7 @@ diff --git a/resources/lib/ga_client.py b/resources/lib/ga_client.py index 8a886fc9..ce7394a6 100644 --- a/resources/lib/ga_client.py +++ b/resources/lib/ga_client.py @@ -9,7 +9,7 @@ import xbmc import platform import xbmcgui import time -from utils import window, settings, language as lang +from utils import settings, language as lang log = logging.getLogger("EMBY."+__name__) @@ -18,6 +18,24 @@ log = logging.getLogger("EMBY."+__name__) logEventHistory = {} +# wrap a function to catch, log and then re throw an exception +def log_error(errors=(Exception, )): + def decorator(func): + def wrapper(*args, **kwargs): + try: + return func(*args, **kwargs) + except errors as error: + ga = GoogleAnalytics() + errStrings = ga.formatException() + ga.sendEventData("Exception", errStrings[0], errStrings[1], True) + log.exception(error) + log.error("log_error: %s \n args: %s \n kwargs: %s", + func.__name__, args, kwargs) + raise + return wrapper + return decorator + +# main GA class class GoogleAnalytics(): testing = False diff --git a/resources/lib/kodimonitor.py b/resources/lib/kodimonitor.py index 6247a82e..a66e790b 100644 --- a/resources/lib/kodimonitor.py +++ b/resources/lib/kodimonitor.py @@ -12,6 +12,7 @@ import downloadutils import embydb_functions as embydb import playbackutils as pbutils from utils import window, settings, kodiSQL +from ga_client import log_error ################################################################################################# @@ -56,6 +57,7 @@ class KodiMonitor(xbmc.Monitor): log.info("New context setting: %s", current_context) window('emby_context', value=current_context) + @log_error() def onNotification(self, sender, method, data): if method not in ('Playlist.OnAdd', 'Player.OnStop', 'Player.OnClear'): diff --git a/resources/lib/player.py b/resources/lib/player.py index 3f19979a..9505238d 100644 --- a/resources/lib/player.py +++ b/resources/lib/player.py @@ -14,7 +14,7 @@ import downloadutils import kodidb_functions as kodidb import websocket_client as wsc from utils import window, settings, language as lang -from ga_client import GoogleAnalytics +from ga_client import GoogleAnalytics, log_error ################################################################################################# @@ -44,6 +44,7 @@ class Player(xbmc.Player): log.debug("Starting playback monitor.") xbmc.Player.__init__(self) + @log_error() def onPlayBackStarted(self): # Will be called when xbmc starts playing a file self.stopAll() @@ -356,6 +357,7 @@ class Player(xbmc.Player): log.debug("Report: %s" % postdata) self.ws.send_progress_update(postdata) + @log_error() def onPlayBackPaused(self): currentFile = self.currentFile @@ -366,6 +368,7 @@ class Player(xbmc.Player): self.reportPlayback() + @log_error() def onPlayBackResumed(self): currentFile = self.currentFile @@ -376,6 +379,7 @@ class Player(xbmc.Player): self.reportPlayback() + @log_error() def onPlayBackSeek(self, time, seekOffset): # Make position when seeking a bit more accurate currentFile = self.currentFile @@ -387,6 +391,7 @@ class Player(xbmc.Player): self.reportPlayback() + @log_error() def onPlayBackStopped(self): # Will be called when user stops xbmc playing a file log.debug("ONPLAYBACK_STOPPED") @@ -396,6 +401,7 @@ class Player(xbmc.Player): log.info("Clear playlist properties.") self.stopAll() + @log_error() def onPlayBackEnded(self): # Will be called when xbmc stops playing a file log.debug("ONPLAYBACK_ENDED") diff --git a/resources/lib/websocket_client.py b/resources/lib/websocket_client.py index fb86f82a..52d8ace2 100644 --- a/resources/lib/websocket_client.py +++ b/resources/lib/websocket_client.py @@ -15,6 +15,7 @@ import librarysync import playlist import userclient from utils import window, settings, dialog, language as lang, JSONRPC +from ga_client import log_error ################################################################################################## @@ -60,6 +61,7 @@ class WebSocketClient(threading.Thread): except Exception as error: log.exception(error) + @log_error() def on_message(self, ws, message): result = json.loads(message)