use several loggers for parts of weboob

weboob/applications/havesex/havesex.py

@@ -18,7 +18,6 @@
 
 from __future__ import with_statement
 
-import logging
 import sys
 
 import weboob
@@ -97,7 +96,7 @@ class HaveSex(ReplApplication):
                 found = 1
 
         if not found:
-            logging.error(u'Profile not found')
+            self.logger.error(u'Profile not found')
 
         return True
 
@@ -116,7 +115,7 @@ class HaveSex(ReplApplication):
             except weboob.core.CallErrors, errors:
                 for backend, error, backtrace in errors:
                     if isinstance(error, OptimizationNotFound):
-                        logging.error(u'Optimization "%s" not found' % optim)
+                        self.logger.error(u'Optimization "%s" not found' % optim)
 
     def do_start(self, *optims):
         """

weboob/backends/aum/backend.py

@@ -19,7 +19,6 @@ from __future__ import with_statement
 
 import datetime
 from dateutil import tz
-from logging import warning, debug
 
 from weboob.capabilities.base import NotLoaded
 from weboob.capabilities.chat import ICapChat
@@ -30,6 +29,7 @@ from weboob.capabilities.account import ICapAccount
 from weboob.tools.backend import BaseBackend
 from weboob.tools.browser import BrowserUnavailable
 from weboob.tools.value import Value, ValuesDict, ValueBool
+from weboob.tools.log import getLogger
 
 from .captcha import CaptchaError
 from .antispam import AntiSpam
@@ -105,7 +105,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
             if not contact.get_id():
                 continue
             if self.antispam and not self.antispam.check(contact):
-                debug('Skipped a spam-thread from %s' % contact.get_name())
+                self.logger.debug('Skipped a spam-thread from %s' % contact.get_name())
                 self.report_spam(contact.get_id(), contact.get_suppr_id())
                 continue
             thread = Thread(contact.get_id())
@@ -141,7 +141,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
         for mail in mails:
             flags = 0
             if self.antispam and not self.antispam.check(mail):
-                debug('Skipped a spam-mail from %s' % mail.sender)
+                self.logger.debug('Skipped a spam-mail from %s' % mail.sender)
                 self.report_spam(thread.id, contact and contact.get_suppr_id())
                 break
 
@@ -152,7 +152,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                     with self.browser:
                         profiles[mail.profile_link] = self.browser.get_profile(mail.profile_link)
                 if self.antispam and not self.antispam.check(profiles[mail.profile_link]):
-                    debug('Skipped a spam-mail-profile from %s' % mail.sender)
+                    self.logger.debug('Skipped a spam-mail-profile from %s' % mail.sender)
                     self.report_spam(thread.id, contact and contact.get_suppr_id())
                     break
                 mail.signature += u'\n%s' % profiles[mail.profile_link].get_profile_text()
@@ -203,7 +203,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                 if not contact.get_id():
                     continue
                 if self.antispam and not self.antispam.check(contact):
-                    debug('Skipped a spam-unread-thread from %s' % contact.get_name())
+                    self.logger.debug('Skipped a spam-unread-thread from %s' % contact.get_name())
                     self.report_spam(contact.get_id(), contact.get_suppr_id())
                     continue
                 slut = self._get_slut(contact.get_id())
@@ -224,7 +224,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                         new_baskets -= 1
                         profile = self.browser.get_profile(ids[new_baskets])
                         if self.antispam and not self.antispam.check(profile):
-                            debug('Skipped a spam-basket from %s' % profile.get_name())
+                            self.logger.debug('Skipped a spam-basket from %s' % profile.get_name())
                             self.report_spam(profile.get_id())
                             continue
 
@@ -242,7 +242,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                                               flags=Message.IS_UNREAD)
                         yield thread.root
         except BrowserUnavailable, e:
-            debug('No messages, browser is unavailable: %s' % e)
+            self.logger.debug('No messages, browser is unavailable: %s' % e)
             pass # don't care about waiting
 
     def set_message_read(self, message):
@@ -345,7 +345,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                 elif contact['cat'] == 2:
                     s = Contact.STATUS_AWAY
                 else:
-                    warning('Unknown AuM contact status: %s' % contact['cat'])
+                    self.logger.warning('Unknown AuM contact status: %s' % contact['cat'])
 
                 if not status & s or ids and contact['id'] in ids:
                     continue
@@ -405,7 +405,7 @@ class AuMBackend(BaseBackend, ICapMessages, ICapMessagesPost, ICapDating, ICapCh
                                  country=    account.properties['country'].value,
                                  godfather=  account.properties['godfather'].value)
             except CaptchaError:
-                debug('Unable to resolve captcha. Retrying...')
+                getLogger('aum').debug('Unable to resolve captcha. Retrying...')
                 browser = None
 
     def get_account(self):

weboob/backends/aum/browser.py

@@ -18,7 +18,6 @@
 
 import datetime
 import time
-from logging import warning
 import random
 import simplejson
 import urllib
@@ -225,20 +224,20 @@ class AuMBrowser(BaseBrowser):
     @pageaccess
     def send_charm(self, id):
         result = self.openurl('http://www.adopteunmec.com/fajax_addBasket.php?id=%s' % id).read()
-        warning('Charm: %s' % result)
+        self.logger.warning('Charm: %s' % result)
         return result.find('noMoreFlashes') < 0
 
     @pageaccess
     def add_basket(self, id):
         result = self.openurl('http://www.adopteunmec.com/fajax_addBasket.php?id=%s' % id).read()
-        warning('Basket: %s' % result)
+        self.logger.warning('Basket: %s' % result)
         # TODO check if it works (but it should)
         return True
 
     @pageaccess
     def deblock(self, id):
         result = self.openurl('http://www.adopteunmec.com/fajax_postMessage.php?action=deblock&to=%s' % id).read()
-        warning('Deblock: %s' % result)
+        self.logger.warning('Deblock: %s' % result)
         return True
 
     @pageaccess

weboob/backends/aum/optim/profiles_walker.py

@@ -18,11 +18,11 @@
 
 from __future__ import with_statement
 
-from logging import info
 from random import randint
 
 from weboob.tools.browser import BrowserUnavailable
 from weboob.capabilities.dating import Optimization
+from weboob.tools.log import getLogger
 
 
 __all__ = ['ProfilesWalker']
@@ -33,9 +33,10 @@ class ProfilesWalker(Optimization):
         self.sched = sched
         self.storage = storage
         self.browser = browser
+        self.logger = getLogger('walker', browser.logger)
 
         self.visited_profiles = set(storage.get('profiles_walker', 'viewed'))
-        info(u'Loaded %d already visited profiles from storage.' % len(self.visited_profiles))
+        self.logger.info(u'Loaded %d already visited profiles from storage.' % len(self.visited_profiles))
         self.profiles_queue = set()
 
     def save(self):
@@ -57,7 +58,7 @@ class ProfilesWalker(Optimization):
         try:
             with self.browser:
                 profiles_to_visit = self.browser.search_profiles().difference(self.visited_profiles)
-                info(u'Enqueuing profiles to visit: %s' % profiles_to_visit)
+                self.logger.info(u'Enqueuing profiles to visit: %s' % profiles_to_visit)
                 self.profiles_queue = set(profiles_to_visit)
             self.save()
         except BrowserUnavailable:
@@ -73,7 +74,7 @@ class ProfilesWalker(Optimization):
             try:
                 with self.browser:
                     profile = self.browser.get_profile(id)
-                info(u'Visited profile %s (%s)' % (profile.get_name(), id))
+                self.logger.info(u'Visited profile %s (%s)' % (profile.get_name(), id))
 
                 # Get score from the aum_score module
                 #d = self.nucentral_core.callService(context.Context.fromComponent(self), 'aum_score', 'score', profile)

weboob/backends/aum/pages/base.py

@@ -17,7 +17,6 @@
 
 
 import re
-from logging import error, warning
 from weboob.tools.browser import BasePage, BrowserUnavailable
 
 class PageBase(BasePage):
@@ -61,7 +60,7 @@ class PageBase(BasePage):
                 child = tag.childNodes[0].childNodes[0].childNodes[3]
                 return int(child.childNodes[0].childNodes[1].data.replace(' ', '').strip())
 
-        error("Error: I can't find the score :(")
+        self.logger.error("Error: I can't find the score :(")
         return '0'
 
     def __get_indicator(self, elementName):
@@ -74,14 +73,14 @@ class PageBase(BasePage):
 
                 if not hasattr(child, 'data'):
                     if child.tagName != u'blink':
-                        warning("Warning: %s counter isn't a blink and hasn't data" % elementName)
+                        self.logger.warning("Warning: %s counter isn't a blink and hasn't data" % elementName)
                     child = child.childNodes[0]
                 if not hasattr(child, 'data'):
                     break
 
                 return int(child.data)
 
-        error("Error: I can't find the %s counter :(" % elementName)
+        self.logger.error("Error: I can't find the %s counter :(" % elementName)
         return 0
 
     MYNAME_REGEXP = re.compile("Bonjour (.*)")
@@ -95,7 +94,7 @@ class PageBase(BasePage):
                 if m:
                     return m.group(1)
 
-        warning('Warning: Unable to fetch name')
+        self.logger.warning('Warning: Unable to fetch name')
         return '?'
 
     def nb_new_mails(self):

weboob/backends/aum/pages/profile.py

@@ -362,7 +362,7 @@ class ProfilePage(PageBase):
                 try:
                     fields[label1].put_value(d, value2)
                 except KeyError:
-                    warning('Unable to find "%s" (%s)' % (label1, repr(label1)))
+                    self.logger.warning('Unable to find "%s" (%s)' % (label1, repr(label1)))
             elif label1 and label2:
                 # two titles, so there will have a list of value in
                 # next lines on each columns

weboob/backends/fourchan/backend.py

@@ -18,8 +18,6 @@
 
 from __future__ import with_statement
 
-from logging import warning
-
 from weboob.capabilities.messages import ICapMessages, Message, Thread
 from weboob.tools.backend import BaseBackend
 from weboob.tools.value import Value, ValuesDict
@@ -52,7 +50,7 @@ class FourChanBackend(BaseBackend, ICapMessages):
             id = thread.id
 
         if not '.' in id:
-            warning('Malformated ID (%s)' % id)
+            self.logger.warning('Malformated ID (%s)' % id)
             return
 
         board, thread_id = self._splitid(id)

weboob/backends/fourchan/pages/board.py

@@ -18,7 +18,6 @@
 from datetime import datetime
 
 import re
-from logging import warning
 
 from weboob.tools.browser import BasePage
 
@@ -53,7 +52,7 @@ class BoardPage(BasePage):
         if m:
             self.board = m.group(1)
         else:
-            warning('Unable to find board')
+            self.logger.warning('Unable to find board')
             self.board = 'unknown'
 
         forms = self.document.getroot().cssselect('form')
@@ -65,7 +64,7 @@ class BoardPage(BasePage):
                 break
 
         if form is None:
-            warning('No delform :(')
+            self.logger.warning('No delform :(')
 
         article = None
         for div in form.getchildren():

weboob/core/bcall.py

@@ -19,11 +19,11 @@
 from __future__ import with_statement
 
 from copy import copy
-from logging import debug
 from threading import Thread, Event, RLock, Timer
 
 from weboob.capabilities.base import CapBaseObject
 from weboob.tools.misc import get_backtrace
+from weboob.tools.log import getLogger
 
 
 __all__ = ['BackendsCall', 'CallErrors']
@@ -44,6 +44,7 @@ class BackendsCall(object):
         @param function  backends' method name, or callable object
         @param args, kwargs  arguments given to called functions
         """
+        self.logger = getLogger('bcall')
         # Store if a backend is finished
         self.backends = {}
         for backend in backends:
@@ -64,7 +65,7 @@ class BackendsCall(object):
         # Create jobs for each backend
         with self.mutex:
             for backend in backends:
-                debug('Creating a new thread for %s' % backend)
+                self.logger.debug('Creating a new thread for %s' % backend)
                 self.threads.append(Timer(0, self._caller, (backend, function, args, kwargs)).start())
             if not backends:
                 self.finish_event.set()
@@ -82,21 +83,21 @@ class BackendsCall(object):
             self.response_event.set()
 
     def _caller(self, backend, function, args, kwargs):
-        debug('%s: Thread created successfully' % backend)
+        self.logger.debug('%s: Thread created successfully' % backend)
         with backend:
             try:
                 # Call method on backend
                 try:
-                    debug('%s: Calling function %s' % (backend, function))
+                    self.logger.debug('%s: Calling function %s' % (backend, function))
                     if callable(function):
                         result = function(backend, *args, **kwargs)
                     else:
                         result = getattr(backend, function)(*args, **kwargs)
                 except Exception, error:
-                    debug('%s: Called function %s raised an error: %r' % (backend, function, error))
+                    self.logger.debug('%s: Called function %s raised an error: %r' % (backend, function, error))
                     self._store_error(backend, error)
                 else:
-                    debug('%s: Called function %s returned: %r' % (backend, function, result))
+                    self.logger.debug('%s: Called function %s returned: %r' % (backend, function, result))
 
                     if hasattr(result, '__iter__') and not isinstance(result, basestring):
                         # Loop on iterator

weboob/core/modules.py

@@ -19,12 +19,12 @@
 from __future__ import with_statement
 
 import logging
-from logging import debug, error, exception
 import os
 import re
 
 from weboob.capabilities.base import IBaseCap
 from weboob.tools.backend import BaseBackend
+from weboob.tools.log import getLogger
 
 
 __all__ = ['Module', 'ModulesLoader']
@@ -32,6 +32,7 @@ __all__ = ['Module', 'ModulesLoader']
 
 class Module(object):
     def __init__(self, package):
+        self.logger = getLogger('backend')
         self.package = package
         self.klass = None
         for attrname in dir(self.package):
@@ -89,14 +90,15 @@ class Module(object):
         return False
 
     def create_instance(self, weboob, instance_name, config, storage):
-        backend_instance = self.klass(weboob, instance_name, config, storage)
+        backend_instance = self.klass(weboob, instance_name, config, storage, self.logger)
-        debug(u'Created backend instance "%s" for backend "%s"' % (instance_name, self.name))
+        self.logger.debug(u'Created backend instance "%s" for backend "%s"' % (instance_name, self.name))
         return backend_instance
 
 
 class ModulesLoader(object):
     def __init__(self):
         self.loaded = {}
+        self.logger = getLogger('modules')
 
     def get_or_load_module(self, module_name):
         if module_name not in self.loaded:
@@ -129,13 +131,13 @@ class ModulesLoader(object):
         except ImportError, e:
             msg = u'Unable to load module "%s": %s' % (module_name, e)
             if logging.root.level == logging.DEBUG:
-                exception(msg)
+                self.logger.exception(msg)
                 return
             else:
-                error(msg)
+                self.logger.error(msg)
                 return
         if module.name in self.loaded:
-            debug('Module "%s" is already loaded from %s' % (module_name, module.package.__path__[0]))
+            self.logger.debug('Module "%s" is already loaded from %s' % (module_name, module.package.__path__[0]))
             return
         self.loaded[module.name] = module
-        debug('Loaded module "%s" from %s' % (module_name, module.package.__path__[0]))
+        self.logger.debug('Loaded module "%s" from %s' % (module_name, module.package.__path__[0]))

weboob/core/ouiboube.py

@@ -18,7 +18,6 @@
 
 from __future__ import with_statement
 
-from logging import warning
 import os
 
 from weboob.core.bcall import BackendsCall
@@ -26,6 +25,7 @@ from weboob.core.modules import ModulesLoader
 from weboob.core.backendscfg import BackendsConfig
 from weboob.core.scheduler import Scheduler
 from weboob.tools.backend import BaseBackend
+from weboob.tools.log import getLogger
 
 
 __all__ = ['Weboob']
@@ -36,6 +36,7 @@ class Weboob(object):
     BACKENDS_FILENAME = 'backends'
 
     def __init__(self, workdir=WORKDIR, backends_filename=None, scheduler=None, storage=None):
+        self.logger = getLogger('weboob')
         self.workdir = workdir
         self.backend_instances = {}
 
@@ -48,7 +49,7 @@ class Weboob(object):
         if not os.path.exists(self.workdir):
             os.mkdir(self.workdir, 0700)
         elif not os.path.isdir(self.workdir):
-            warning(u'"%s" is not a directory' % self.workdir)
+            self.logger.warning(u'"%s" is not a directory' % self.workdir)
 
         # Backends loader
         self.modules_loader = ModulesLoader()
@@ -96,15 +97,15 @@ class Weboob(object):
                 continue
             module = self.modules_loader.get_or_load_module(module_name)
             if module is None:
-                warning(u'Backend "%s" is referenced in ~/.weboob/backends '
+                self.logger.warning(u'Backend "%s" is referenced in ~/.weboob/backends '
-                        'configuration file, but was not found. '
+                                     'configuration file, but was not found. '
-                        'Hint: is it installed?' % module_name)
+                                     'Hint: is it installed?' % module_name)
                 continue
             if caps is not None and not module.has_caps(caps):
                 continue
 
             if instance_name in self.backend_instances:
-                warning(u'Oops, the backend "%s" is already loaded. Unload it before reloading...' % instance_name)
+                self.logger.warning(u'Oops, the backend "%s" is already loaded. Unload it before reloading...' % instance_name)
                 self.unload_backends(instance_name)
 
             try:
@@ -186,7 +187,7 @@ class Weboob(object):
                     else:
                         backends.append(backend)
             else:
-                warning(u'The "backends" value isn\'t supported: %r' % _backends)
+                self.logger.warning(u'The "backends" value isn\'t supported: %r' % _backends)
 
         if 'caps' in kwargs:
             caps = kwargs.pop('caps')

weboob/core/scheduler.py

@@ -18,8 +18,8 @@
 
 from __future__ import with_statement
 
-import logging
 from threading import Timer, Event, RLock
+from weboob.tools.log import getLogger
 
 
 __all__ = ['Scheduler']
@@ -40,6 +40,7 @@ class IScheduler(object):
 
 class Scheduler(IScheduler):
     def __init__(self):
+        self.logger = getLogger('scheduler')
         self.mutex = RLock()
         self.stop_event = Event()
         self.count = 0
@@ -51,7 +52,7 @@ class Scheduler(IScheduler):
 
         with self.mutex:
             self.count += 1
-            logging.debug('function "%s" will be called in %s seconds' % (function.__name__, interval))
+            self.logger.debug('function "%s" will be called in %s seconds' % (function.__name__, interval))
             timer = Timer(interval, self._callback, (self.count, function, args))
             self.queue[self.count] = timer
             timer.start()

weboob/tools/backend.py

@@ -18,10 +18,10 @@
 
 import os
 from threading import RLock
-from logging import debug
 
 from weboob.capabilities.base import CapBaseObject, FieldNotFound, IBaseCap, NotLoaded
 from weboob.tools.misc import iter_fields
+from weboob.tools.log import getLogger
 
 
 __all__ = ['BaseBackend', 'ObjectNotAvailable']
@@ -95,7 +95,8 @@ class BaseBackend(object):
     def __repr__(self):
         return u"<Backend '%s'>" % self.name
 
-    def __init__(self, weboob, name, config, storage):
+    def __init__(self, weboob, name, config, storage, logger=None):
+        self.logger = getLogger(self.NAME, parent=logger)
         self.weboob = weboob
         self.name = name
         self.lock = RLock()
@@ -143,7 +144,7 @@ class BaseBackend(object):
         try:
             import xdg.IconTheme
         except ImportError:
-            debug(u'Python xdg module was not found. Please install it to read icon files.')
+            self.logger.debug(u'Python xdg module was not found. Please install it to read icon files.')
         else:
             return xdg.IconTheme.getIconPath(self.NAME)
 
@@ -178,6 +179,7 @@ class BaseBackend(object):
             kwargs['proxy'] = self._private_config['_proxy']
         elif 'HTTP_PROXY' in os.environ:
             kwargs['proxy'] = os.environ['HTTP_PROXY']
+        kwargs['logger'] = self.logger
 
         return self.BROWSER(*args, **kwargs)
 
@@ -235,5 +237,5 @@ class BaseBackend(object):
 
         for key, value in self.OBJECTS.iteritems():
             if isinstance(obj, key):
-                debug(u'Fill %r with fields: %s' % (obj, missing_fields))
+                self.logger.debug(u'Fill %r with fields: %s' % (obj, missing_fields))
                 return value(self, obj, missing_fields) or obj

weboob/tools/browser/browser.py

@@ -24,7 +24,7 @@ from weboob.tools.mech import ClientForm
 ControlNotFoundError = ClientForm.ControlNotFoundError
 import re
 import time
-from logging import warning, debug
+from logging import warning
 from copy import copy
 from threading import RLock
 import os
@@ -32,6 +32,7 @@ import tempfile
 
 from weboob.tools.parsers import get_parser
 from weboob.tools.decorators import retry
+from weboob.tools.log import getLogger
 
 # Try to load cookies
 try:
@@ -91,12 +92,13 @@ class BasePage(object):
     """
     Base page
     """
-    def __init__(self, browser, document, url='', groups=None, group_dict=None):
+    def __init__(self, browser, document, url='', groups=None, group_dict=None, logger=None):
         self.browser = browser
         self.document = document
         self.url = url
         self.groups = groups
         self.group_dict = group_dict
+        self.logger = getLogger('page', logger)
 
     def on_loaded(self):
         """
@@ -156,7 +158,7 @@ class BaseBrowser(mechanize.Browser):
     default_features.remove('_robots')
 
     def __init__(self, username=None, password=None, firefox_cookies=None,
-                 parser=None, history=NoHistory(), proxy=None):
+                 parser=None, history=NoHistory(), proxy=None, logger=None):
         """
         Constructor of Browser.
 
@@ -167,8 +169,11 @@ class BaseBrowser(mechanize.Browser):
         @param parser [IParser]  parser to use on HTML files.
         @param hisory [object]  History manager. Default value is an object
                                 which does not keep history.
+        @param proxy [str]  proxy URL to use.
         """
         mechanize.Browser.__init__(self, history=history)
+        self.logger = getLogger('browser', logger)
+
         self.addheaders = [
                 ['User-agent', self.USER_AGENT]
             ]
@@ -242,7 +247,7 @@ class BaseBrowser(mechanize.Browser):
         Open an URL but do not create a Page object.
         """
         if_fail = kwargs.pop('if_fail', 'raise')
-        debug('Opening URL "%s", %s' % (args, kwargs))
+        self.logger.debug('Opening URL "%s", %s' % (args, kwargs))
         try:
             return mechanize.Browser.open_novisit(self, *args, **kwargs)
         except (mechanize.response_seek_wrapper, urllib2.HTTPError, urllib2.URLError, BadStatusLine), e:
@@ -280,7 +285,7 @@ class BaseBrowser(mechanize.Browser):
         fd, path = tempfile.mkstemp(prefix="response", dir=tmpdir)
         with os.fdopen(fd, 'w') as f:
             f.write(result.read())
-        debug("Response saved to %s" % path)
+        self.logger.debug("Response saved to %s" % path)
         result.seek(0)
 
     def submit(self, *args, **kwargs):
@@ -366,23 +371,23 @@ class BaseBrowser(mechanize.Browser):
             #if isinstance(data, unicode):
             #    data = data.encode('utf-8')
             #print data
-            warning('Oh my fucking god, there isn\'t any page corresponding to URL %s' % result.geturl())
+            self.logger.warning('Oh my fucking god, there isn\'t any page corresponding to URL %s' % result.geturl())
             self.save_response(result)
 
             return
 
-        debug('[user_id=%s] Went on %s' % (self.username, result.geturl()))
+        self.logger.debug('[user_id=%s] Went on %s' % (self.username, result.geturl()))
         self.last_update = time.time()
 
         if self.SAVE_RESPONSES:
             self.save_response(result)
 
         document = self.get_document(result)
-        self.page = pageCls(self, document, result.geturl(), groups=page_groups, group_dict=page_group_dict)
+        self.page = pageCls(self, document, result.geturl(), groups=page_groups, group_dict=page_group_dict, logger=self.logger)
         self.page.on_loaded()
 
         if self.password is not None and not self.is_logged():
-            debug('!! Relogin !!')
+            self.logger.debug('!! Relogin !!')
             self.login()
             return