Run getLogger in all functions and classes (#2320)

ESSArch_Core/WorkflowEngine/dbtask.py

@@ -45,9 +45,6 @@
 
 User = get_user_model()
 
-logger = logging.getLogger('essarch')
-
-
 # import time
 # from contextlib import contextmanager
 #
@@ -75,6 +72,7 @@ class DBTask(Task):
     event_type = None
     queue = 'celery'
     track = True
+    logger = logging.getLogger('essarch')
 
     def __call__(self, *args, **kwargs):
         for k, v in self.result_params.items():
@@ -144,20 +142,20 @@ def _run(self, *args, **kwargs):
                         try:
                             ip = InformationPackage.objects.select_related('submission_agreement').get(pk=self.ip)
                         except InformationPackage.DoesNotExist as e:
-                            logger.warning(
+                            self.logger.warning(
                                 'exception in _run for task_id: {}, step_id: {}, DoesNotExist when get ip: {} \
 - retry'.format(self.task_id, self.step, self.ip))
                             raise e
             except RetryError:
-                logger.warning('RetryError in _run for task_id: {}, step_id: {}, DoesNotExist when get ip: {} \
+                self.logger.warning('RetryError in _run for task_id: {}, step_id: {}, DoesNotExist when get ip: {} \
 - try to _run_task without IP'.format(self.task_id, self.step, self.ip))
                 return self._run_task(*args, **kwargs)
             self.extra_data.update(fill_specification_data(ip=ip, sa=ip.submission_agreement).to_dict())
 
-            logger.debug('{} acquiring lock for IP {}'.format(self.task_id, str(ip.pk)))
+            self.logger.debug('{} acquiring lock for IP {}'.format(self.task_id, str(ip.pk)))
             # with cache_lock(ip.get_lock_key()):
             with cache.lock(ip.get_lock_key(), blocking_timeout=300):
-                logger.info('{} acquired lock for IP {}'.format(self.task_id, str(ip.pk)))
+                self.logger.info('{} acquired lock for IP {}'.format(self.task_id, str(ip.pk)))
 
                 t = self.get_processtask()
                 if t.run_if and not self.parse_params(t.run_if)[0]:
@@ -166,7 +164,7 @@ def _run(self, *args, **kwargs):
                     t.save()
                 else:
                     r = self._run_task(*args, **kwargs)
-            logger.info('{} released lock for IP {}'.format(self.task_id, str(ip.pk)))
+            self.logger.info('{} released lock for IP {}'.format(self.task_id, str(ip.pk)))
             return r
 
         return self._run_task(*args, **kwargs)
@@ -178,7 +176,7 @@ def _run_task(self, *args, **kwargs):
                 for ancestor in step.get_ancestors(include_self=True):
                     self.extra_data.update(ancestor.context)
             except ProcessStep.DoesNotExist:
-                logger.warning('exception in _run_task for task_id: {}, step_id: {}, DoesNotExist when get \
+                self.logger.warning('exception in _run_task for task_id: {}, step_id: {}, DoesNotExist when get \
 step, (self.ip: {})'.format(self.task_id, self.step, self.ip))
 
         try:
@@ -202,7 +200,7 @@ def _run_task(self, *args, **kwargs):
                     exception=einfo.exception,
                     traceback=einfo.traceback,
                 )
-                logger.error('Task with flag "allow failure" failed with exception {}'.format(einfo.exception))
+                self.logger.error('Task with flag "allow failure" failed with exception {}'.format(einfo.exception))
                 return None
 
             raise
@@ -258,7 +256,7 @@ def create_event(self, status, msg, retval, einfo):
             'task': ProcessTask.objects.get(celery_id=self.task_id).pk,
             'outcome': outcome
         }
-        logger.log(level, outcome_detail_note, extra=extra)
+        self.logger.log(level, outcome_detail_note, extra=extra)
 
     def failure(self, exc, einfo):
         '''

ESSArch_Core/WorkflowEngine/models.py

@@ -49,8 +49,6 @@
     wait_fixed,
 )
 
-logger = logging.getLogger('essarch.WorkflowEngine')
-
 
 def create_task(name):
     """
@@ -59,12 +57,14 @@ def create_task(name):
     Args:
         name: The name of the task, including package and module
     """
+    logger = logging.getLogger('essarch.WorkflowEngine')
     [module, task] = name.rsplit('.', 1)
     logger.debug('Importing task {} from module {}'.format(task, module))
     return getattr(importlib.import_module(module), task)
 
 
 def create_sub_task(t, step=None, immutable=True, link_error=None):
+    logger = logging.getLogger('essarch.WorkflowEngine')
     if t.queue:
         logger.debug('Creating sub task in queue: {}'.format(t.queue))
     else:
@@ -219,6 +219,7 @@ def clear_cache(self):
             self.parent.clear_cache()
 
     def run_children(self, tasks, steps, direct=True):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         tasks = tasks.filter(status=celery_states.PENDING,)
 
         if not tasks.exists() and not steps.exists():
@@ -336,6 +337,7 @@ def resume(self, direct=True):
             otherwise
         """
 
+        logger = logging.getLogger('essarch.WorkflowEngine')
         logger.debug('Resuming step {} ({})'.format(self.name, self.pk))
         ProcessTask.objects.filter(
             processstep__in=self.get_descendants(include_self=True),
@@ -608,8 +610,10 @@ def reraise(self):
         raise exc.with_traceback(tb)
 
     @retry(retry=retry_if_exception_type(RequestException), reraise=True, stop=stop_after_attempt(5),
-           wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG))
+           wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.WorkflowEngine'),
+                                                              logging.DEBUG))
     def create_remote_copy(self, session, host, exclude_remote_params=True):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         create_remote_task_url = urljoin(host, reverse('processtask-list'))
         params = copy.deepcopy(self.params)
         params.pop('_options', None)
@@ -641,8 +645,10 @@ def create_remote_copy(self, session, host, exclude_remote_params=True):
         return r
 
     @retry(retry=retry_if_exception_type(RequestException), reraise=True, stop=stop_after_attempt(5),
-           wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG))
+           wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.WorkflowEngine'),
+                                                              logging.DEBUG))
     def update_remote_copy(self, session, host, exclude_remote_params=True):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         update_remote_task_url = urljoin(host, reverse('processtask-detail', args=(str(self.pk),)))
         params = copy.deepcopy(self.params)
         params.pop('_options', None)
@@ -667,8 +673,10 @@ def update_remote_copy(self, session, host, exclude_remote_params=True):
         return r
 
     @retry(retry=retry_if_exception_type(RequestException), reraise=True, stop=stop_after_attempt(5),
-           wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG))
+           wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.WorkflowEngine'),
+                                                              logging.DEBUG))
     def run_remote_copy(self, session, host):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         run_remote_task_url = urljoin(host, reverse('processtask-run', args=(str(self.pk),)))
         r = session.post(run_remote_task_url, timeout=60)
         try:
@@ -680,8 +688,10 @@ def run_remote_copy(self, session, host):
         return r
 
     @retry(retry=retry_if_exception_type(RequestException), reraise=True, stop=stop_after_attempt(5),
-           wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG))
+           wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.WorkflowEngine'),
+                                                              logging.DEBUG))
     def retry_remote_copy(self, session, host):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         self.update_remote_copy(session, host)
         retry_remote_task_url = urljoin(host, reverse('processtask-retry', args=(str(self.pk),)))
         r = session.post(retry_remote_task_url, timeout=60)
@@ -694,8 +704,10 @@ def retry_remote_copy(self, session, host):
         return r
 
     @retry(retry=retry_if_exception_type(RequestException), reraise=True, stop=stop_after_attempt(5),
-           wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG))
+           wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.WorkflowEngine'),
+                                                              logging.DEBUG))
     def get_remote_copy(self, session, host):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         remote_task_url = urljoin(host, reverse('processtask-detail', args=(str(self.pk),)))
         r = session.get(remote_task_url, timeout=60)
         if r.status_code >= 400 and r.status_code != 404:
@@ -721,7 +733,7 @@ def run(self):
         """
         Runs the task
         """
-
+        logger = logging.getLogger('essarch.WorkflowEngine')
         t = create_task(self.name)
         if self.queue:
             t.queue = self.queue
@@ -765,6 +777,7 @@ def run(self):
         return res
 
     def revoke(self):
+        logger = logging.getLogger('essarch.WorkflowEngine')
         logger.debug('Revoking task ({})'.format(self.pk))
         current_app.control.revoke(str(self.celery_id), terminate=True)
         self.status = celery_states.REVOKED
@@ -776,7 +789,7 @@ def retry(self):
         """
         Retries the task
         """
-
+        logger = logging.getLogger('essarch.WorkflowEngine')
         logger.debug('Retrying task ({})'.format(self.pk))
         self.reset()
         return self.run()

ESSArch_Core/agents/models.py

@@ -14,8 +14,6 @@
 from ESSArch_Core.auth.util import get_group_objs_model
 from ESSArch_Core.managers import OrganizationManager
 
-logger = logging.getLogger('essarch')
-
 
 class AgentRelationType(models.Model):
     name = models.CharField(_('name'), max_length=255, blank=False, unique=True)
@@ -163,6 +161,7 @@ def change_organization(self, organization, change_related_ips=False, change_rel
         group_objs_model.objects.change_organization(self, organization, force=force)
 
     def get_organization(self):
+        logger = logging.getLogger('essarch')
         group_objs_model = get_group_objs_model(self)
         try:
             go_obj = group_objs_model.objects.get_organization(self)

ESSArch_Core/auth/admin.py

@@ -41,7 +41,6 @@
 
 csrf_protect_m = method_decorator(csrf_protect)
 User = get_user_model()
-logger = logging.getLogger('essarch.auth')
 
 admin.site.unregister([
     GroupManagerMember,
@@ -169,12 +168,15 @@ def has_module_permission(self, request):
         return request.user.has_module_perms('auth')
 
     def log_addition(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to add user '{object}' with msg: '{message}'.")
 
     def log_change(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to change the user '{object}' with msg: '{message}'.")
 
     def log_deletion(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to delete the user '{object}' with msg: '{message}'.")
 
 
@@ -259,12 +261,15 @@ def has_module_permission(self, request):
         return request.user.has_module_perms('auth')
 
     def log_addition(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to add group '{object}' with msg: '{message}'.")
 
     def log_change(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to change the group '{object}' with msg: '{message}'.")
 
     def log_deletion(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to delete the group '{object}' with msg: '{message}'.")
 
 
@@ -287,12 +292,15 @@ def has_module_permission(self, request):
         return request.user.has_module_perms('groups_manager')
 
     def log_addition(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to create new group type '{object}' with msg: '{message}'.")
 
     def log_change(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to change the group type '{object}' with msg: '{message}'.")
 
     def log_deletion(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to delete the group type '{object}' with msg: '{message}'.")
 
 
@@ -322,12 +330,15 @@ class GroupMemberRoleAdmin(admin.ModelAdmin):
     actions = [duplicate]
 
     def log_addition(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to create role '{object}' with msg: '{message}'.")
 
     def log_change(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to change the role '{object}' with msg: '{message}'.")
 
     def log_deletion(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to delete the role '{object}' with msg: '{message}'.")
 
 
@@ -354,12 +365,15 @@ def has_view_permission(self, request, obj=None):
         return request.user.has_perm("%s.%s" % ('auth', 'view_permission'))
 
     def log_addition(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to create permission '{object.name}' with msg: '{message}'.")
 
     def log_change(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to change the permission '{object.name}' with msg: '{message}'.")
 
     def log_deletion(self, request, object, message):
+        logger = logging.getLogger('essarch.auth')
         logger.info(f"User '{request.user}' attempts to delete the permission '{object.name}' with msg: '{message}'.")
 
 

ESSArch_Core/auth/backends.py

@@ -8,8 +8,6 @@
 
 from ESSArch_Core.auth.util import get_group_objs_model, get_user_roles
 
-logger = logging.getLogger('essarch.auth')
-
 
 def _get_permission_objs(user, obj=None):
     perms = Permission.objects.none()
@@ -33,6 +31,7 @@ def authenticate(self, *args, **kwargs):
         return None
 
     def get_all_permissions(self, user_obj, obj=None):
+        logger = logging.getLogger('essarch.auth')
         go_obj = None
 
         if obj is not None:

ESSArch_Core/auth/consumers.py

@@ -2,23 +2,24 @@
 
 from channels.generic.websocket import AsyncJsonWebsocketConsumer
 
-logger = logging.getLogger('essarch.core.auth.consumers')
-
 
 class NotificationConsumer(AsyncJsonWebsocketConsumer):
     async def connect(self):
+        logger = logging.getLogger('essarch.core.auth.consumers')
         user = self.scope["user"]
         grp = 'notifications_{}'.format(user.pk)
         await self.accept()
         await self.channel_layer.group_add(grp, self.channel_name)
         logger.info("Added {} channel to {}".format(self.channel_name, grp))
 
     async def disconnect(self, close_code):
+        logger = logging.getLogger('essarch.core.auth.consumers')
         user = self.scope["user"]
         grp = 'notifications_{}'.format(user.pk)
         await self.channel_layer.group_discard(grp, self.channel_name)
         logger.info("Removed {} channel from {}".format(self.channel_name, grp))
 
     async def notify(self, event):
+        logger = logging.getLogger('essarch.core.auth.consumers')
         await self.send_json(event)
         logger.info("Notification with id {} sent to channel {}".format(event['id'], self.channel_name))

ESSArch_Core/auth/models.py

@@ -50,7 +50,6 @@
 from relativity.mptt import MPTTDescendants
 
 DjangoUser = get_user_model()
-logger = logging.getLogger('essarch.auth')
 
 
 class BaseGenericObjects(models.Model):
@@ -101,6 +100,7 @@ def get_organization(self, obj, list=False):
                 return self.model.objects.get(content_object_id=obj.pk)
 
     def change_organization(self, obj, organization, force=False):
+        logger = logging.getLogger('essarch.auth')
         if organization.group_type.codename != 'organization':
             raise ValueError('{} is not an organization'.format(organization))
         if isinstance(obj, list) or isinstance(obj, QuerySet):