Merge pull request #40 from anxdpanic/dev

add kodi logging

Author: anxdpanic

addon.xml

@@ -13,6 +13,7 @@
 [add] helix api
 [add] add usher.live_request and usher.video_request
 [add] MobileClient().revoke_token and MobileClient().get_app_access_token queries
+[add] Kodi logging
         </news>
         <assets>
             <icon>icon.png</icon>

changelog.txt

@@ -8,6 +8,7 @@
 [add] helix api
 [add] add usher.live_request and usher.video_request
 [add] MobileClient().revoke_token and MobileClient().get_app_access_token queries
+[add] Kodi logging
 
 1.1.0
 *** Twitch API V5 is deprecated and will be removed entirely on 2/14/18

resources/lib/twitch/__init__.py

@@ -1,8 +1,6 @@
 # -*- encoding: utf-8 -*-
 
-import xbmcaddon
-
-VERSION = xbmcaddon.Addon('script.module.python.twitch').getAddonInfo('version')
+VERSION = '2.0.0'
 CLIENT_ID = ''
 CLIENT_SECRET = ''
 OAUTH_TOKEN = ''

resources/lib/twitch/api/usher.py

@@ -1,14 +1,12 @@
 # -*- encoding: utf-8 -*-
-
-from twitch.logging import log  # NOQA
-
-log.warning('By using this module you are violating the Twitch TOS')  # NOQA
+#  By using this module you are violating the Twitch TOS
 
 from twitch import keys
 from twitch.api.parameters import Boolean
 from twitch.parser import m3u8, clip_embed
 from twitch.queries import ClipsQuery, HiddenApiQuery, UsherQuery
 from twitch.queries import query
+from twitch.logging import log
 
 from six.moves.urllib.parse import urlencode
 
@@ -57,7 +55,9 @@ def live_request(channel):
         q.add_param(keys.ALLOW_SPECTRE, Boolean.TRUE)
         q.add_param(keys.ALLOW_AUDIO_ONLY, Boolean.TRUE)
         url = '?'.join([q.url, urlencode(q.params)])
-        return {'url': url, 'headers': q.headers}
+        request_dict = {'url': url, 'headers': q.headers}
+        log.debug('live_request: |{0}|'.format(str(request_dict)))
+        return request_dict
 
 
 @query
@@ -95,7 +95,9 @@ def video_request(video_id):
             q.add_param(keys.ALLOW_SOURCE, Boolean.TRUE)
             q.add_param(keys.ALLOW_AUDIO_ONLY, Boolean.TRUE)
             url = '?'.join([q.url, urlencode(q.params)])
-            return {'url': url, 'headers': q.headers}
+            request_dict = {'url': url, 'headers': q.headers}
+            log.debug('video_request: |{0}|'.format(str(request_dict)))
+            return request_dict
     else:
         raise NotImplementedError('Unknown Video Type')
 

resources/lib/twitch/api/v5/__init__.py

@@ -1,6 +1,9 @@
 # -*- encoding: utf-8 -*-
 # https://dev.twitch.tv/docs/
 # V5 is deprecated and will be removed entirely on 2/14/18
+from twitch.logging import log
+
+log.deprecated_api_version('V5', 'Helix', '2/14/18')
 
 from twitch.api.v5 import bits  # NOQA
 from twitch.api.v5 import channel_feed  # NOQA

resources/lib/twitch/api/v5/channels.py

@@ -5,6 +5,7 @@
 from twitch.api.parameters import Boolean, BroadcastType, Cursor, Direction, Duration, Language, VideoSort
 from twitch.queries import V5Query as Qry
 from twitch.queries import query
+from twitch.logging import log
 
 
 # required scope: channel_read
@@ -126,6 +127,7 @@ def reset_stream_key(channel_id):
 # deprecated
 @query
 def get_community(channel_id):
+    log.deprecated_query('channels.get_community', 'channels.get_communities')
     q = Qry('channels/{channel_id}/community')
     q.add_urlkw(keys.CHANNEL_ID, channel_id)
     return q
@@ -143,6 +145,7 @@ def get_communities(channel_id):
 # deprecated
 @query
 def set_community(channel_id, community_id):
+    log.deprecated_query('channels.set_community', 'channels.set_communities')
     q = Qry('channels/{channel_id}/community/{community_id}', method=methods.PUT)
     q.add_urlkw(keys.CHANNEL_ID, channel_id)
     q.add_urlkw(keys.COMMUNITY_ID, community_id)

resources/lib/twitch/logging.py

@@ -1,7 +1,8 @@
 # -*- coding: utf-8 -*-
 from __future__ import absolute_import
-
+import re
 import logging
+import copy
 
 try:
     from logging import NullHandler
@@ -10,11 +11,83 @@ class NullHandler(logging.Handler):
         def emit(self, record):
             pass
 
-log = logging.getLogger('twitch')
-log.addHandler(NullHandler())
+try:
+    import xbmc
+except ImportError:
+    xbmc = None
+
+
+def _mask(message):
+    mask = '*' * 11
+    masked_message = re.sub(r'((?:OAuth|Bearer)\s)[^\'"]+', r'\1' + mask, message)
+    masked_message = re.sub(r'(["\']email["\']:\s*[\'"])[^\'"]+', r'\1' + mask, masked_message)
+    masked_message = re.sub(r'(USER-IP=[\'"])[^\'"]+', r'\1' + mask, masked_message)
+    masked_message = re.sub(r'(["\']client_secret["\']:\s*[\'"])[^\'"]+', r'\1' + mask, masked_message)
+    masked_message = re.sub(r'(client_secret=).+?(&|$|\|)', r'\1' + mask + r'\2', masked_message)
+    return masked_message
+
+
+def _add_leader(message):
+    if xbmc:
+        message = 'script.module.python.twitch: %s' % message
+    return message
+
+
+def prep_log_message(message):
+    message = copy.deepcopy(message)
+    message = _mask(message)
+    message = _add_leader(message)
+    return message
+
+
+class Log:
+    def __init__(self):
+        if xbmc:
+            self._log = xbmc.log
+        else:
+            self._log = logging.getLogger('twitch')
+            self._log.addHandler(NullHandler())
+
+    def info(self, message):
+        message = prep_log_message(message)
+        if xbmc:
+            self._log(message, xbmc.LOGNOTICE)
+        else:
+            self._log.info(message)
+
+    def debug(self, message):
+        message = prep_log_message(message)
+        if xbmc:
+            self._log(message, xbmc.LOGDEBUG)
+        else:
+            self._log.debug(message)
+
+    def warning(self, message):
+        message = prep_log_message(message)
+        if xbmc:
+            self._log(message, xbmc.LOGWARNING)
+        else:
+            self._log.debug(message)
+
+    def error(self, message):
+        message = prep_log_message(message)
+        if xbmc:
+            self._log(message, xbmc.LOGERROR)
+        else:
+            self._log.error(message)
+
+    def critical(self, message):
+        message = prep_log_message(message)
+        if xbmc:
+            self._log(message, xbmc.LOGFATAL)
+        else:
+            self._log.critical(message)
+
+    def deprecated_query(self, old, new):
+        self.warning('DEPRECATED call to |{0}| detected, please use |{1}| instead'.format(old, new))
+
+    def deprecated_api_version(self, old, new, eol_date):
+        self.warning('API version |{0}| is deprecated, update to |{1}| by |{2}|'.format(old, new, eol_date))
 
 
-def deprecation_warning(logger, old, new):
-    logger.warning("DEPRECATED call to '%s\' detected, "
-                   "please use '%s' instead",
-                   old, new)
+log = Log()

resources/lib/twitch/queries.py

@@ -4,7 +4,7 @@
 
 from twitch import CLIENT_ID, OAUTH_TOKEN, APP_TOKEN
 from twitch.exceptions import ResourceUnavailableException
-from twitch.logging import log
+from twitch.logging import log, prep_log_message
 from twitch.scraper import download, get_json, get_json_and_headers
 from twitch import methods
 
@@ -91,7 +91,7 @@ def execute(self, f):
         try:
             return f(self.url, self.params, self.headers, self.data, self.method)
         except:
-            raise ResourceUnavailableException(str(self))
+            raise ResourceUnavailableException(prep_log_message(str(self)))
 
 
 class DownloadQuery(_Query):
@@ -193,18 +193,17 @@ def __init__(self, path, use_app_token=False, method=methods.GET):
 def assert_new(d, k):
     if k in d:
         v = d.get(k)
-        raise ValueError("Key '{0}' already set to '{1}'".format(k, v))
+        raise ValueError('Key |{0}| already set to |{1}|'.format(k, v))
 
 
 # TODO maybe rename
 def query(f):
     def wrapper(*args, **kwargs):
         qry = f(*args, **kwargs)
         if not isinstance(qry, _Query):
-            raise ValueError('{0} did not return a Query, was: {1}'.format(f.__name__, repr(qry)))
-        log.debug('%s QUERY: url: %s, params: %s, data: %s, '
-                  'headers: %r, target_func: %r',
-                  qry.method, qry.url, qry.params, qry.data, qry.headers, f.__name__)
+            raise ValueError('|{0}| did not return a Query, was: |{1}|'.format(f.__name__, repr(qry)))
+        log.debug('{0} QUERY: url: |{1}|, params: |{2}|, data: |{3}|, headers: |{4}|, target_func: |{5}|'
+                  .format(qry.method, qry.url, qry.params, qry.data, qry.headers, f.__name__))
         return qry.execute()
 
     return wrapper

resources/lib/twitch/scraper.py

@@ -35,7 +35,7 @@ def get_json(baseurl, parameters={}, headers={}, data={}, method=methods.GET):
     method = methods.validate(method)
     jsonString = download(baseurl, parameters, headers, data, method)
     jsonDict = json.loads(jsonString)
-    log.debug(json.dumps(jsonDict, indent=4, sort_keys=True))
+    log.debug('url: |{0}| parameters: |{1}|\n{2}'.format(baseurl, parameters, json.dumps(jsonDict, indent=4, sort_keys=True)))
     return jsonDict
 
 
@@ -51,7 +51,7 @@ def get_json_and_headers(baseurl, parameters={}, headers={}, data={}, method=met
     method = methods.validate(method)
     content = download(baseurl, parameters, headers, data, method, response_headers=True)
     content['response'] = json.loads(content['response'])
-    log.debug(json.dumps(content['response'], indent=4, sort_keys=True))
+    log.debug('url: |{0}| parameters: |{1}|\n{2}'.format(baseurl, parameters, json.dumps(content['response'], indent=4, sort_keys=True)))
     return content
 
 
@@ -67,29 +67,33 @@ def download(baseurl, parameters={}, headers={}, data={}, method=methods.GET, re
     @returns String of data from URL or {'response': {}, 'headers': {}} if response_headers is True
     '''
     method = methods.validate(method)
-    if isinstance(parameters, dict):
+
+    if not parameters:
+        url = baseurl
+    elif isinstance(parameters, dict):
         url = '?'.join([baseurl, urlencode(parameters)])
     else:
         _parameters = ''
         for param in parameters:
             _parameters += '{0}={1}&'.format(param[0], quote_plus(str(param[1])))
         _parameters = _parameters.rstrip('&')
         url = '?'.join([baseurl, _parameters])
-    log.debug('Downloading: ' + url)
+
+    log.debug('Downloading: |{0}|'.format(url))
     content = ""
     for _ in range(MAX_RETRIES):
         try:
             headers.update({USER_AGENT: USER_AGENT_STRING})
             response = requests.request(method=method, url=url, headers=headers, data=data, verify=SSL_VERIFICATION)
             content = response.content
             if not content:
-                content = '{"status": %d}' % response.status_code
+                content = '{{"status": {0}}}'.format(response.status_code)
             break
         except Exception as err:
             if not isinstance(err, URLError):
-                log.debug("Error %s during HTTP Request, abort", repr(err))
+                log.debug('Error |{0}| during HTTP Request, abort'.format(repr(err)))
                 raise  # propagate non-URLError
-            log.debug("Error %s during HTTP Request, retrying", repr(err))
+            log.debug('Error |{0}| during HTTP Request, retrying'.format(repr(err)))
     else:
         raise