Feature/fix adba logger and unicode

CHANGELOG.md

@@ -13,6 +13,7 @@
 #### Fixes
 - Fixed many release name parsing issues as a result of updating `guessit` ([#4244](https://github.com/pymedusa/Medusa/pull/4244))
 - Fixed Speed.CD provider exception during searches ([#5190](https://github.com/pymedusa/Medusa/pull/5190))
+- Fixed adba lib trowing exceptions getting release groups for some anime shows ([#5125](https://github.com/pymedusa/Medusa/pull/5125))
 
 -----
 

ext/adba/__init__.py

@@ -34,6 +34,9 @@
 
 version = 100
 
+logger = logging.getLogger(__name__)
+logger.addHandler(logging.NullHandler())
+
 
 def StartLogging():
     # set up the format string
@@ -118,7 +121,7 @@ def cut(self):
 
     def handle_response(self, response):
         if response.rescode in ('501', '506') and response.req.command != 'AUTH':
-            logging.debug("seems like the last command got a not authed error back trying to reconnect now")
+            logger.debug("seems like the last command got a not authed error back trying to reconnect now")
             if self._reAuthenticate():
                 response.req.resp = None
                 self.handle(response.req, response.req.callback)
@@ -151,7 +154,7 @@ def callback_wrapper(resp):
             if callback:
                 callback(resp)
 
-        logging.debug("handling(" + str(self.counter) + "-" + str(self.link.delay) + ") command " + str(command.command))
+        logger.debug("handling(" + str(self.counter) + "-" + str(self.link.delay) + ") command " + str(command.command))
 
         # make live request
         command.authorize(self.mode, self.link.new_tag(), self.link.session, callback_wrapper)
@@ -183,7 +186,7 @@ def authed(self, reAuthenticate=False):
 
     def _reAuthenticate(self):
         if self._username and self._password:
-            logging.info("auto re authenticating !")
+            logger.info("auto re authenticating !")
             resp = self.auth(self._username, self._password)
             if resp.rescode != '500':
                 return True
@@ -192,11 +195,11 @@ def _reAuthenticate(self):
 
     def _keep_alive(self):
         self.lastKeepAliveCheck = time()
-        logging.info("auto check !")
+        logger.info("auto check !")
         # check every 30 minutes if the session is still valid
         # if not reauthenticate
         if self.lastAuth and time() - self.lastAuth > 1800:
-            logging.info("auto uptime !")
+            logger.info("auto uptime !")
             self.uptime()  # this will update the self.link.session and will refresh the session if it is still alive
 
             if self.authed():  # if we are authed we set the time
@@ -207,7 +210,7 @@ def _keep_alive(self):
         # issue a ping every 20 minutes after the last package
         # this ensures the connection will be kept alive
         if self.link.lastpacket and time() - self.link.lastpacket > 1200:
-            logging.info("auto ping !")
+            logger.info("auto ping !")
             self.ping()
 
     def run(self):
@@ -262,18 +265,18 @@ def auth(self, username, password, nat=None, mtu=None, callback=None):
 
         if needauth:
             self.lastAuth = time()
-            logging.debug('No valid session, so authenticating')
+            logger.debug('No valid session, so authenticating')
             try:
                 self.handle(AuthCommand(username, password, 3, self.clientname, self.clientver, nat, 1, 'utf8', mtu), callback)
             except Exception as e:
-                logging.debug('Auth command with exception %s', e)
+                logger.debug('Auth command with exception %s', e)
                 # we force a config file with logged out to ensure a known state if an exception occurs, forcing us to log in again
                 config['DEFAULT'] = {'loggedin': 'yes', 'sessionkey': self.link.session, 'exception': str(e),
                                      'lastcommandtime': repr(time())}
                 with open(self.SessionFile, 'w') as configfile:
                     config.write(configfile)
                 return e
-            logging.debug('Successfully authenticated and recording session details')
+            logger.debug('Successfully authenticated and recording session details')
             config['DEFAULT'] = {'loggedin': 'yes', 'sessionkey': self.link.session, 'lastcommandtime': repr(time())}
             with open(self.SessionFile, 'w') as configfile:
                 config.write(configfile)
@@ -294,9 +297,9 @@ def logout(self, cutConnection=True, callback=None):
             config['DEFAULT']['loggedin'] = 'no'
             with open(self.SessionFile, 'w') as configfile:
                 config.write(configfile)
-            logging.debug('Logging out')
+            logger.debug('Logging out')
             return result
-        logging.debug('Not logging out')
+        logger.debug('Not logging out')
         return
 
     def stayloggedin(self):
@@ -309,7 +312,7 @@ def stayloggedin(self):
         with open(self.SessionFile, 'w') as configfile:
             config.write(configfile)
         self.link._do_delay()
-        logging.debug('Staying logged in')
+        logger.debug('Staying logged in')
         return
 
     def push(self, notify, msg, buddy=None, callback=None):

ext/adba/aniDBAbstracter.py

@@ -28,6 +28,9 @@
 from .aniDBtvDBmaper import TvDBMap
 from .aniDBfileInfo import read_anidb_xml
 
+logger = logging.getLogger(__name__)
+logger.addHandler(logging.NullHandler())
+
 
 class aniDBabstractObject(object):
     def __init__(self, aniDB, load=False):
@@ -163,7 +166,7 @@ def get_groups(self):
         self.rawData = self.aniDB.groupstatus(aid=self.aid)
         self.release_groups = []
         for line in self.rawData.datalines:
-            self.release_groups.append({"name": line["name"],
+            self.release_groups.append({"name": line["name"].decode("utf-8"),
                                         "rating": line["rating"],
                                         "range": line["episode_range"]
                                         })
@@ -276,10 +279,10 @@ def add_to_mylist(self, state=None, viewed=None, source=None, storage=None, othe
         try:
             self.aniDB.mylistadd(size=self.size, ed2k=self.ed2k, state=state, viewed=viewed, source=source, storage=storage, other=other)
         except Exception as e:
-            logging.exception("Exception: %s", e)
+            logger.exception("Exception: %s", e)
         else:
             # TODO: add the name or something
-            logging.info("Added the episode to anidb")
+            logger.info("Added the episode to anidb")
 
     def edit_to_mylist(self, state=None, viewed=None, source=None, storage=None, other=None):
         """
@@ -301,30 +304,30 @@ def edit_to_mylist(self, state=None, viewed=None, source=None, storage=None, oth
         try:
             edit_response = self.aniDB.mylistadd(size=self.size, ed2k=self.ed2k, edit=1, state=state, viewed=viewed, source=source, storage=storage, other=other)
         except Exception as e:
-            logging.exception("Exception: %s", e)
+            logger.exception("Exception: %s", e)
         # handling the case that the entry is not in anidb yet, non ideal to check the string but isinstance is having issue
         # currently raises an exception for less changes in the code, unsure if this is the ideal way to do so
         if edit_response.codestr == "NO_SUCH_MYLIST_ENTRY":
-            logging.info("attempted an edit before add")
+            logger.info("attempted an edit before add")
             raise AniDBError("Attempted to edit file without adding")
         else:
-            logging.info("Edited the episode in anidb")
+            logger.info("Edited the episode in anidb")
 
     def delete_from_mylist(self):
         if self.filePath and not (self.ed2k or self.size):
             (self.ed2k, self.size) = self._calculate_file_stuff(self.filePath)
         try:
             self.aniDB.mylistdel(size=self.size, ed2k=self.ed2k)
         except Exception as e:
-            logging.exception("Exception: %s", e)
+            logger.exception("Exception: %s", e)
         else:
-            logging.info("Deleted the episode from anidb")
+            logger.info("Deleted the episode from anidb")
 
     @staticmethod
     def _calculate_file_stuff(filePath):
         if not filePath:
             return None, None
-        logging.info("Calculating the ed2k. Please wait...")
+        logger.info("Calculating the ed2k. Please wait...")
         ed2k = fileInfo.get_ED2K(filePath)
         size = fileInfo.get_file_size(filePath)
         return ed2k, size

ext/adba/aniDBfileInfo.py

@@ -27,6 +27,10 @@
 import xml.etree.cElementTree as etree
 
 
+logger = logging.getLogger(__name__)
+logger.addHandler(logging.NullHandler())
+
+
 # http://www.radicand.org/blog/orz/2010/2/21/edonkey2000-hash-in-python/
 def get_ED2K(filePath, forceHash=False, cacheLocation=os.path.normpath(sys.path[0] + os.sep + "ED2KCache.pickle")):
     """ Returns the ed2k hash of a given file."""
@@ -62,7 +66,7 @@ def writeCacheToDisk():
                 with open(cacheLocation, 'wb') as f:
                     pickle.dump(get_ED2K.ED2KCache, f, pickle.HIGHEST_PROTOCOL)
         except:
-            logging.error("Error occurred while writing back to disk")
+            logger.error("Error occurred while writing back to disk")
         return
 
     file_modified_time = os.path.getmtime(filePath)
@@ -137,7 +141,7 @@ def _remove_file_failed(file):
     try:
         os.remove(file)
     except OSError:
-        logging.warning("Error occurred while trying to remove file %s", file)
+        logger.warning("Error occurred while trying to remove file %s", file)
 
 
 def download_file(url, filename):

ext/adba/aniDBlink.py

@@ -27,6 +27,9 @@
 from .aniDBerrors import *
 from .aniDBresponses import ResponseResolver
 
+logger = logging.getLogger(__name__)
+logger.addHandler(logging.NullHandler())
+
 
 class AniDBLink(threading.Thread):
     def __init__(self, server, port, myport, delay=2, timeout=20):
@@ -78,7 +81,7 @@ def disconnectSocket(self):
         # self.sock.close()
 
     def stop(self):
-        logging.info("Releasing socket and stopping link thread")
+        logger.info("Releasing socket and stopping link thread")
         self._quiting = True
         self.disconnectSocket()
         self._stop.set()
@@ -92,28 +95,25 @@ def print_log_dummy(self, data):
     def run(self):
         while not self._quiting:
             try:
-                data = self.sock.recv(8192).decode('UTF-8')
+                data = self.sock.recv(8192)
             except socket.timeout:
                 self._handle_timeouts()
                 continue
             except OSError as error:
-                logging.exception('Exception: %s', error)
-                break
-            except UnicodeDecodeError as error:
-                logging.exception('Bad response from server: %s', error)
+                logger.exception('Exception: %s', error)
                 break
-            logging.debug("NetIO < %r", data)
+            logger.debug("NetIO < %r", data)
             try:
                 for i in range(2):
                     try:
                         tmp = data
                         resp = None
-                        if tmp[:2] == '\x00\x00':
+                        if tmp[:2] == b'\x00\x00':
                             tmp = zlib.decompressobj().decompress(tmp[2:])
-                            logging.debug("UnZip | %r", tmp)
+                            logger.debug("UnZip | %r", tmp)
                         resp = ResponseResolver(tmp)
                     except Exception as e:
-                        logging.exception('Exception: %s', e)
+                        logger.exception('Exception: %s', e)
                         sys.excepthook(*sys.exc_info())
                         self.crypt = None
                         self.session = None
@@ -124,26 +124,26 @@ def run(self):
                 cmd = self._cmd_dequeue(resp)
                 resp = resp.resolve(cmd)
                 resp.parse()
-                if resp.rescode in ('200', '201'):
-                    self.session = resp.attrs['sesskey']
-                if resp.rescode in ('209',):
-                    logging.error("sorry encryption is not supported")
+                if resp.rescode in (b'200', b'201'):
+                    self.session = resp.attrs[b'sesskey']
+                if resp.rescode in (b'209',):
+                    logger.error("sorry encryption is not supported")
                     raise AniDBError()
                     # self.crypt=aes(md5(resp.req.apipassword+resp.attrs['salt']).digest())
-                if resp.rescode in ('203', '403', '500', '501', '503', '506'):
+                if resp.rescode in (b'203', b'403', b'500', b'501', b'503', b'506'):
                     self.session = None
                     self.crypt = None
-                if resp.rescode in ('504', '555'):
+                if resp.rescode in (b'504', b'555'):
                     self.banned = True
-                    logging.critical(("AniDB API informs that user or client is banned:", resp.resstr))
+                    logger.critical(("AniDB API informs that user or client is banned:", resp.resstr))
                 resp.handle()
                 if not cmd or not cmd.mode:
                     self._resp_queue(resp)
                 else:
                     self.tags.remove(resp.restag)
             except:
                 sys.excepthook(*sys.exc_info())
-                logging.error("Avoiding flood by paranoidly panicing: Aborting link thread, killing connection, releasing waiters and quiting")
+                logger.error("Avoiding flood by paranoidly panicing: Aborting link thread, killing connection, releasing waiters and quiting")
                 self.sock.close()
                 try:
                     cmd.waiter.release()
@@ -206,27 +206,27 @@ def _do_delay(self):
 
     def _send(self, command):
         if self.banned:
-            logging.debug("NetIO | BANNED")
+            logger.debug("NetIO | BANNED")
             raise AniDBError("Not sending, banned")
         self._do_delay()
         self.lastpacket = time()
         command.started = time()
         data = command.raw_data()
 
-        self.sock.sendto(bytes(data, "ASCII"), self.target)
-        if command.command == 'AUTH':
-            logging.debug("NetIO > sensitive data is not logged!")
+        self.sock.sendto(bytes(data, b"ASCII"), self.target)
+        if command.command == b'AUTH':
+            logger.debug("NetIO > sensitive data is not logged!")
 
     def new_tag(self):
         if not len(self.tags):
-            maxtag = "T000"
+            maxtag = b"T000"
         else:
             maxtag = max(self.tags)
-        newtag = "T%03d" % (int(maxtag[1:]) + 1)
+        newtag = b"T%03d" % (int(maxtag[1:]) + 1)
         return newtag
 
     def request(self, command):
-        if not (self.session and command.session) and command.command not in ('AUTH', 'PING', 'ENCRYPT'):
+        if not (self.session and command.session) and command.command not in (b'AUTH', b'PING', b'ENCRYPT'):
             raise AniDBMustAuthError("You must be authed to execute commands besides AUTH and PING")
         command.started = time()
         self._cmd_queue(command)

ext/readme.md

@@ -1,7 +1,7 @@
 ## ext
  Status  |  Package  |  Version / Commit  | Usage | py2 | py3 | Notes
 :------: | :-------: | :----------------: | :---- | :--: | :--: | :----
-:: | `adba` | pymedusa/[70bc381](https://github.com/pymedusa/adba/tree/70bc381a75e20e1813c848c1edb7c6f16987397e) | **`medusa`** | v | v | -
+:: | `adba` | pymedusa/[fcb4bf4](https://github.com/pymedusa/adba/tree/fcb4bf43f10ca53f3beb915707c877581b1bf2a5) | **`medusa`** | v | v | -
 :: | <code><b>appdirs</b>.py</code> | [1.4.3](https://pypi.org/project/appdirs/1.4.3/) | `subliminal` (cli only), `simpleanidb` | v | v | -
 :: | `attrs` | [18.1.0](https://pypi.org/project/attrs/18.1.0/) | `imdbpie` | v | v | Module: `attr`
 :: | `babelfish` | [f403000](https://github.com/Diaoul/babelfish/tree/f403000dd63092cfaaae80be9f309fd85c7f20c9) | **`medusa`**, `guessit`, `knowit`, `subliminal` | v | v | -

medusa/logger/__init__.py

@@ -40,6 +40,8 @@
 )
 from logging.handlers import RotatingFileHandler
 
+import adba
+
 import knowit
 
 from medusa import app
@@ -611,6 +613,7 @@ def init_logging(self, console_logging):
         self.loggers.extend([access_log, app_log, gen_log])
         self.loggers.extend(get_loggers(traktor))
         self.loggers.extend(get_loggers(knowit))
+        self.loggers.extend(get_loggers(adba))
 
         logging.addLevelName(DB, 'DB')  # add a new logging level DB
         logging.getLogger().addHandler(NullHandler())  # nullify root logger