From dd39d96edabeb7e98bdf37ac52c07ac1ad464d10 Mon Sep 17 00:00:00 2001 From: Henrik Ek Date: Thu, 4 Jul 2024 21:42:20 +0200 Subject: [PATCH] Run getLogger in all functions and classes (#2320) --- ESSArch_Core/WorkflowEngine/dbtask.py | 20 ++++++------ ESSArch_Core/WorkflowEngine/models.py | 31 +++++++++++++------ ESSArch_Core/agents/models.py | 3 +- ESSArch_Core/auth/admin.py | 16 +++++++++- ESSArch_Core/auth/backends.py | 3 +- ESSArch_Core/auth/consumers.py | 5 +-- ESSArch_Core/auth/models.py | 2 +- ESSArch_Core/auth/signals.py | 11 ++++++- ESSArch_Core/auth/views.py | 3 +- ESSArch_Core/configuration/views.py | 5 +-- ESSArch_Core/db/utils.py | 3 +- ESSArch_Core/essxml/Generator/xmlGenerator.py | 5 ++- ESSArch_Core/essxml/ProfileMaker/views.py | 3 -- ESSArch_Core/essxml/util.py | 3 +- ESSArch_Core/fixity/checksum.py | 3 +- ESSArch_Core/fixity/format.py | 7 +++-- ESSArch_Core/fixity/receipt/backends/email.py | 3 +- ESSArch_Core/fixity/receipt/backends/xml.py | 3 +- .../fixity/validation/backends/checksum.py | 3 +- .../fixity/validation/backends/encryption.py | 3 +- .../fixity/validation/backends/filename.py | 3 +- .../fixity/validation/backends/fixed_width.py | 7 +++-- .../fixity/validation/backends/format.py | 3 +- .../validation/backends/repeated_extension.py | 3 +- .../fixity/validation/backends/structure.py | 3 +- .../fixity/validation/backends/xml.py | 11 +++++-- ESSArch_Core/install/update_remote.py | 4 ++- ESSArch_Core/ip/models.py | 16 ++++++---- ESSArch_Core/ip/signals.py | 4 +-- ESSArch_Core/ip/tasks.py | 9 +++--- ESSArch_Core/maintenance/models.py | 5 +-- ESSArch_Core/search/documents.py | 3 +- ESSArch_Core/search/importers/base.py | 5 +-- ESSArch_Core/search/ingest.py | 4 +-- ESSArch_Core/storage/backends/disk.py | 5 +-- ESSArch_Core/storage/backends/s3.py | 2 +- ESSArch_Core/storage/backends/tape.py | 7 ++++- ESSArch_Core/storage/copy.py | 10 +++--- ESSArch_Core/storage/models.py | 20 +++++++----- ESSArch_Core/storage/serializers.py | 3 +- ESSArch_Core/storage/tape.py | 13 +++++++- ESSArch_Core/tags/models.py | 8 ++++- ESSArch_Core/tags/search.py | 4 ++- ESSArch_Core/tags/signals.py | 6 ++-- ESSArch_Core/tasks.py | 3 +- ESSArch_Core/util.py | 8 +++-- ESSArch_Core/workflow/tasks.py | 1 - 47 files changed, 189 insertions(+), 116 deletions(-) diff --git a/ESSArch_Core/WorkflowEngine/dbtask.py b/ESSArch_Core/WorkflowEngine/dbtask.py index 266b7c1cc..cce309724 100644 --- a/ESSArch_Core/WorkflowEngine/dbtask.py +++ b/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): ''' diff --git a/ESSArch_Core/WorkflowEngine/models.py b/ESSArch_Core/WorkflowEngine/models.py index 6d3de3909..d5886d33e 100644 --- a/ESSArch_Core/WorkflowEngine/models.py +++ b/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() diff --git a/ESSArch_Core/agents/models.py b/ESSArch_Core/agents/models.py index 9eb912f11..e9a5e0f38 100644 --- a/ESSArch_Core/agents/models.py +++ b/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) diff --git a/ESSArch_Core/auth/admin.py b/ESSArch_Core/auth/admin.py index bc2f52d80..63c1e763a 100644 --- a/ESSArch_Core/auth/admin.py +++ b/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}'.") diff --git a/ESSArch_Core/auth/backends.py b/ESSArch_Core/auth/backends.py index 526b6d401..cd77d7f09 100644 --- a/ESSArch_Core/auth/backends.py +++ b/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: diff --git a/ESSArch_Core/auth/consumers.py b/ESSArch_Core/auth/consumers.py index 6b7e3bcbc..bbe0096e1 100644 --- a/ESSArch_Core/auth/consumers.py +++ b/ESSArch_Core/auth/consumers.py @@ -2,11 +2,10 @@ 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() @@ -14,11 +13,13 @@ async def connect(self): 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)) diff --git a/ESSArch_Core/auth/models.py b/ESSArch_Core/auth/models.py index 4143a457d..7810552ae 100644 --- a/ESSArch_Core/auth/models.py +++ b/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): diff --git a/ESSArch_Core/auth/signals.py b/ESSArch_Core/auth/signals.py index a8681890a..c86181ba1 100644 --- a/ESSArch_Core/auth/signals.py +++ b/ESSArch_Core/auth/signals.py @@ -38,7 +38,6 @@ from ESSArch_Core.auth.util import get_organization_groups User = get_user_model() -logger = logging.getLogger('essarch.auth') if getattr(settings, 'ENABLE_SSO_LOGIN', False) or getattr(settings, 'ENABLE_ADFS_LOGIN', False): from djangosaml2.signals import pre_user_save as saml_pre_user_save @@ -62,6 +61,7 @@ async def closing_group_send(channel_layer, channel, message): @receiver(post_save, sender=User) @receiver(post_save, sender=ProxyUser) def user_post_save(sender, instance, created, *args, **kwargs): + logger = logging.getLogger('essarch.auth') if created or not hasattr(instance, 'user_profile'): UserProfile.objects.create(user=instance) @@ -77,6 +77,7 @@ def user_post_save(sender, instance, created, *args, **kwargs): @receiver(user_logged_in) def user_logged_in(sender, user, request, **kwargs): + logger = logging.getLogger('essarch.auth') if user.user_profile.language == '': user.user_profile.language = 'DEFAULT' user.user_profile.save(update_fields=['language']) @@ -90,6 +91,7 @@ def user_logged_in(sender, user, request, **kwargs): @receiver(user_logged_out) def user_logged_out(sender, user, request, **kwargs): + logger = logging.getLogger('essarch.auth') host = request.META.get('REMOTE_ADDR') if host is None: logger.info("User {} successfully logged out from unknown host".format(user)) @@ -99,11 +101,13 @@ def user_logged_out(sender, user, request, **kwargs): @receiver(user_login_failed) def user_login_failed(sender, credentials, **kwargs): + logger = logging.getLogger('essarch.auth') logger.warning("Authentication failure with credentials: %s" % (repr(credentials))) @receiver(pre_delete, sender=Session) def log_before_deleting_session(sender, instance, **kwargs): + logger = logging.getLogger('essarch.auth') uid = instance.get_decoded().get('_auth_user_id') if uid: user = User.objects.get(id=uid) @@ -112,6 +116,7 @@ def log_before_deleting_session(sender, instance, **kwargs): @receiver(post_save, sender=Session) def log_before_creating_session(sender, instance, **kwargs): + logger = logging.getLogger('essarch.auth') uid = instance.get_decoded().get('_auth_user_id') if uid: user = User.objects.get(id=uid) @@ -126,6 +131,7 @@ def group_pre_save(sender, instance, *args, **kwargs): @receiver(post_save, sender=Group) def group_post_save(sender, instance, created, *args, **kwargs): + logger = logging.getLogger('essarch.auth') if created: logger.info(f"Created group '{instance.name}'") else: @@ -144,6 +150,7 @@ def group_post_delete(sender, instance, *args, **kwargs): @receiver(m2m_changed, sender=ProxyUser.groups.through) @receiver(m2m_changed, sender=User.groups.through) def group_users_change(sender, instance, action, reverse, pk_set=None, *args, **kwargs): + logger = logging.getLogger('essarch.auth') logger.info(f"Changing group for user '{instance}', action: {action}.") member = instance.essauth_member if action == 'post_add': @@ -159,12 +166,14 @@ def group_users_change(sender, instance, action, reverse, pk_set=None, *args, ** @receiver(post_save, sender=GroupMember) def group_member_save(sender, instance, created, *args, **kwargs): + logger = logging.getLogger('essarch.auth') logger.info(f"User '{instance.member}' is now member of group '{instance.group}'.") groups_manager_group_member_save(sender, instance, created, *args, **kwargs) @receiver(post_delete, sender=GroupMember) def group_member_delete(sender, instance, *args, **kwargs): + logger = logging.getLogger('essarch.auth') logger.info(f"User '{instance.member}' is no longer member of group '{instance.group}'.") groups_manager_group_member_delete(sender, instance, *args, **kwargs) diff --git a/ESSArch_Core/auth/views.py b/ESSArch_Core/auth/views.py index 4bf0c7ce5..73b473d0a 100644 --- a/ESSArch_Core/auth/views.py +++ b/ESSArch_Core/auth/views.py @@ -67,9 +67,7 @@ except ImportError: pass - User = get_user_model() -logger = logging.getLogger('essarch.auth') class UserViewSet(viewsets.ReadOnlyModelViewSet): @@ -212,6 +210,7 @@ def post(self, request, format=None): class LogoutView(rest_auth_LogoutView): def get(self, request, *args, **kwargs): + logger = logging.getLogger('essarch.auth') if getattr(settings, 'ENABLE_SSO_LOGIN', False) or getattr(settings, 'ENABLE_ADFS_LOGIN', False): try: if _get_subject_id(request.saml_session): diff --git a/ESSArch_Core/configuration/views.py b/ESSArch_Core/configuration/views.py index 00fed9705..216130d1c 100644 --- a/ESSArch_Core/configuration/views.py +++ b/ESSArch_Core/configuration/views.py @@ -66,8 +66,6 @@ ) from ESSArch_Core.WorkflowEngine import get_workers -logger = logging.getLogger('essarch.configuration') - def get_database_info(): vendor = connection.vendor @@ -92,6 +90,7 @@ def get_database_info(): def get_elasticsearch_info(full): + logger = logging.getLogger('essarch.configuration') if settings.ELASTICSEARCH_CONNECTIONS['default']['hosts'][0]['host']: try: props = get_es_connection().info() @@ -109,6 +108,7 @@ def get_elasticsearch_info(full): def get_redis_info(full=False): + logger = logging.getLogger('essarch.configuration') try: props = get_redis_connection().info() if full: @@ -124,6 +124,7 @@ def get_redis_info(full=False): def get_rabbitmq_info(full=False): + logger = logging.getLogger('essarch.configuration') try: props = current_app.connection(transport_options={'max_retries': 5}).connection.server_properties if full: diff --git a/ESSArch_Core/db/utils.py b/ESSArch_Core/db/utils.py index 890868a02..b849b340f 100644 --- a/ESSArch_Core/db/utils.py +++ b/ESSArch_Core/db/utils.py @@ -5,8 +5,6 @@ from django.db.models.functions import Cast, Length, StrIndex, Substr, Trim from django.db.utils import OperationalError -logger = logging.getLogger('essarch') - def natural_sort(qs, field): return qs.annotate( @@ -37,6 +35,7 @@ def check_db_connection(): """ Checks to see if the database connection is healthy. """ + logger = logging.getLogger('essarch') try: with connection.cursor() as cursor: cursor.execute("select 1") diff --git a/ESSArch_Core/essxml/Generator/xmlGenerator.py b/ESSArch_Core/essxml/Generator/xmlGenerator.py index c2e1dcfb4..2771f6124 100644 --- a/ESSArch_Core/essxml/Generator/xmlGenerator.py +++ b/ESSArch_Core/essxml/Generator/xmlGenerator.py @@ -45,7 +45,6 @@ normalize_path, ) -logger = logging.getLogger('essarch.essxml.generator') leading_underscore_tag_re = re.compile(r'%s *_(.*?(?=\}))%s' % (re.escape('{{'), re.escape('}}'))) @@ -207,6 +206,7 @@ def fid(self): return self._fid def createExternalElement(self, info, nsmap=None, files=None, folderToParse='', algorithm=None, external=None): + logger = logging.getLogger('essarch.essxml.generator') external_elements = [] if external is None: external = self.external @@ -320,6 +320,7 @@ def get_path(self, path=None): return path def get_FILEGROUPID(self, child, child_info): + logger = logging.getLogger('essarch.essxml.generator') id = None attr_label = None for attr in child.attr: @@ -374,6 +375,7 @@ def add_element(self, new): self.el.append(new.el) def createLXMLElement(self, info, nsmap=None, files=None, folderToParse='', parent=None, algorithm=None): + logger = logging.getLogger('essarch.essxml.generator') if nsmap is None: nsmap = {} @@ -705,6 +707,7 @@ def find_external_dirs(self): def generate(self, filesToCreate, folderToParse=None, extra_paths_to_parse=None, parsed_files=None, relpath=None, algorithm='SHA-256'): + logger = logging.getLogger('essarch.essxml.generator') self.toCreate = [] for fname, content in filesToCreate.items(): self.toCreate.append({ diff --git a/ESSArch_Core/essxml/ProfileMaker/views.py b/ESSArch_Core/essxml/ProfileMaker/views.py index 49fe0ebb8..f9199e9ec 100644 --- a/ESSArch_Core/essxml/ProfileMaker/views.py +++ b/ESSArch_Core/essxml/ProfileMaker/views.py @@ -24,7 +24,6 @@ import copy import json -import logging import uuid from collections import OrderedDict @@ -46,8 +45,6 @@ from .forms import AddExtensionForm, AddTemplateForm from .models import extensionPackage, templatePackage -logger = logging.getLogger('code.exceptions') - def constructContent(text): res = [] diff --git a/ESSArch_Core/essxml/util.py b/ESSArch_Core/essxml/util.py index d02ff39ea..86c862f1c 100644 --- a/ESSArch_Core/essxml/util.py +++ b/ESSArch_Core/essxml/util.py @@ -44,8 +44,6 @@ win_to_posix, ) -logger = logging.getLogger('essarch') - XSD_NAMESPACE = "http://www.w3.org/2001/XMLSchema" XSI_NAMESPACE = "http://www.w3.org/2001/XMLSchema-instance" @@ -520,6 +518,7 @@ def parse_file(filepath, fid, relpath=None, algorithm='SHA-256', rootdir='', pro def download_imported_https_schemas(schema, dst): + logger = logging.getLogger('essarch') from ESSArch_Core.ip.utils import download_schema for url in schema.xpath('//*[local-name()="import"]/@schemaLocation'): protocol = urlparse(url) diff --git a/ESSArch_Core/fixity/checksum.py b/ESSArch_Core/fixity/checksum.py index 76ca0f7e2..a4fbede38 100644 --- a/ESSArch_Core/fixity/checksum.py +++ b/ESSArch_Core/fixity/checksum.py @@ -5,8 +5,6 @@ MB = 1024 * 1024 -logger = logging.getLogger('essarch.fixity.checksum') - def alg_from_str(algname): valid = { @@ -37,6 +35,7 @@ def calculate_checksum(filename, algorithm='SHA-256', block_size=65536): The hexadecimal digest of the checksum """ + logger = logging.getLogger('essarch.fixity.checksum') hash_val = alg_from_str(algorithm)() if os.name == 'nt': diff --git a/ESSArch_Core/fixity/format.py b/ESSArch_Core/fixity/format.py index e5a4529ea..b8e3bc19a 100644 --- a/ESSArch_Core/fixity/format.py +++ b/ESSArch_Core/fixity/format.py @@ -17,9 +17,6 @@ ) MB = 1024 * 1024 - -logger = logging.getLogger('essarch.fixity.format') - DEFAULT_MIMETYPE = 'application/octet-stream' @@ -37,6 +34,7 @@ def __init__(self, allow_unknown_file_types=False, allow_encrypted_files=False, @property def fido(self): + logger = logging.getLogger('essarch.fixity.format') if self._fido is None: logger.debug('Initiating fido') format_files = [] @@ -61,6 +59,7 @@ def fido(self): return self._fido def _init_mimetypes(self): + logger = logging.getLogger('essarch.fixity.format') try: mimetypes_file = Path.objects.get( entity="mimetypes_definitionfile" @@ -86,6 +85,7 @@ def _init_mimetypes(self): return mime def get_mimetype(self, fname): + logger = logging.getLogger('essarch.fixity.format') logger.debug('Getting mimetype for %s' % fname) mime = self._init_mimetypes() @@ -162,6 +162,7 @@ def identify_file_format(self, filename): A tuple with the format name, version and registry key """ + logger = logging.getLogger('essarch.fixity.format') if os.name == 'nt': start_time = time.perf_counter() else: diff --git a/ESSArch_Core/fixity/receipt/backends/email.py b/ESSArch_Core/fixity/receipt/backends/email.py index b603ae3db..32fc14f61 100644 --- a/ESSArch_Core/fixity/receipt/backends/email.py +++ b/ESSArch_Core/fixity/receipt/backends/email.py @@ -9,8 +9,6 @@ from ESSArch_Core.fixity.receipt.backends.base import BaseReceiptBackend from ESSArch_Core.profiles.utils import fill_specification_data -logger = logging.getLogger('essarch.core.fixity.receipt.email') - class NoEmailRecipientError(ESSArchException): pass @@ -22,6 +20,7 @@ class NoEmailSentError(ESSArchException): class EmailReceiptBackend(BaseReceiptBackend): def create(self, template, destination, outcome, short_message, message, date=None, ip=None, task=None, **kwargs): + logger = logging.getLogger('essarch.core.fixity.receipt.email') if task is not None and destination is None: destination = task.responsible.email diff --git a/ESSArch_Core/fixity/receipt/backends/xml.py b/ESSArch_Core/fixity/receipt/backends/xml.py index afb8656a0..17e66ca42 100644 --- a/ESSArch_Core/fixity/receipt/backends/xml.py +++ b/ESSArch_Core/fixity/receipt/backends/xml.py @@ -14,11 +14,10 @@ from ESSArch_Core.profiles.utils import fill_specification_data from ESSArch_Core.storage.copy import copy_file -logger = logging.getLogger('essarch.core.fixity.receipt.xml') - class XMLReceiptBackend(BaseReceiptBackend): def create(self, template, destination, outcome, short_message, message, date=None, ip=None, task=None, **kwargs): + logger = logging.getLogger('essarch.core.fixity.receipt.xml') logger.debug('Creating XML receipt: {}'.format(destination)) spec = json.loads(get_template(template).template.source) diff --git a/ESSArch_Core/fixity/validation/backends/checksum.py b/ESSArch_Core/fixity/validation/backends/checksum.py index ac2661654..576360e58 100644 --- a/ESSArch_Core/fixity/validation/backends/checksum.py +++ b/ESSArch_Core/fixity/validation/backends/checksum.py @@ -9,8 +9,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.checksum') - class ChecksumValidator(BaseValidator): """ @@ -35,6 +33,7 @@ def __init__(self, *args, **kwargs): self.block_size = self.options.get('block_size', 65536) def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.checksum') logger.debug('Validating checksum of %s' % filepath) val_obj = Validation.objects.create( filename=filepath, diff --git a/ESSArch_Core/fixity/validation/backends/encryption.py b/ESSArch_Core/fixity/validation/backends/encryption.py index 6b57fd207..e44f809da 100644 --- a/ESSArch_Core/fixity/validation/backends/encryption.py +++ b/ESSArch_Core/fixity/validation/backends/encryption.py @@ -11,8 +11,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.encryption') - class FileEncryptionValidator(BaseValidator): """ @@ -56,6 +54,7 @@ def validate(self, filepath, expected=None): filepath: The file to validate excpected: If the expected outcome is: Encrypted(True) or not(False) """ + logger = logging.getLogger('essarch.fixity.validation.encryption') logger.debug('Validating encryption of %s' % filepath) result = self.is_file_encrypted(filepath) diff --git a/ESSArch_Core/fixity/validation/backends/filename.py b/ESSArch_Core/fixity/validation/backends/filename.py index fb2d0f7d8..6bad2f28a 100644 --- a/ESSArch_Core/fixity/validation/backends/filename.py +++ b/ESSArch_Core/fixity/validation/backends/filename.py @@ -10,8 +10,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.filename') - DEFAULT_EXPECTED_FILE = r'^[\da-zA-Z_\-]+\.[\da-zA-Z]+$' DEFAULT_EXPECTED_DIR = r'^[\da-zA-Z_\-]+$' @@ -27,6 +25,7 @@ def validate(self, filepath, expected=None): filepath: The file to validate expected: Regex pattern """ + logger = logging.getLogger('essarch.fixity.validation.filename') logger.debug('Validating filename of %s' % filepath) val_obj = Validation( diff --git a/ESSArch_Core/fixity/validation/backends/fixed_width.py b/ESSArch_Core/fixity/validation/backends/fixed_width.py index 0f94d56d0..a35ee1251 100644 --- a/ESSArch_Core/fixity/validation/backends/fixed_width.py +++ b/ESSArch_Core/fixity/validation/backends/fixed_width.py @@ -9,8 +9,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.fixed_width') - class FixedWidthValidator(BaseValidator): """ @@ -46,6 +44,7 @@ def _create_obj(self, filename, passed, msg): ) def _validate_str_column(self, field, col, row_number): + logger = logging.getLogger('essarch.fixity.validation.fixed_width') if col.isdigit(): msg = self.invalid_datatype_warn.format(col, row_number, field['datatype']) logger.warning(msg) @@ -64,6 +63,7 @@ def _validate_date_column(self, col): return False def _validate_fields(self, fields, filepath, line, row_number, filler): + logger = logging.getLogger('essarch.fixity.validation.fixed_width') for field in fields: if field['end'] - field['start'] != field['length']: msg = 'Conflicting field length on row {}: end - start != length'.format(row_number) @@ -108,6 +108,7 @@ def _validate_fields(self, fields, filepath, line, row_number, filler): self._create_obj(filepath, False, msg) def _validate_lines(self, filepath, input_file, fields, filler): + logger = logging.getLogger('essarch.fixity.validation.fixed_width') row_number = 0 for line in input_file: @@ -122,6 +123,7 @@ def _validate_lines(self, filepath, input_file, fields, filler): self._validate_fields(fields, filepath, line, row_number, filler) def _validate(self, filepath, fields, encoding, filler): + logger = logging.getLogger('essarch.fixity.validation.fixed_width') with open(filepath, encoding=encoding) as input_file: try: self._validate_lines(filepath, input_file, fields, filler) @@ -132,6 +134,7 @@ def _validate(self, filepath, fields, encoding, filler): self._create_obj(filepath, False, msg) def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.fixed_width') logger.debug('Validating filename of %s' % filepath) if expected is None: diff --git a/ESSArch_Core/fixity/validation/backends/format.py b/ESSArch_Core/fixity/validation/backends/format.py index b40980c81..978347528 100644 --- a/ESSArch_Core/fixity/validation/backends/format.py +++ b/ESSArch_Core/fixity/validation/backends/format.py @@ -9,8 +9,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.format') - class FormatValidator(BaseValidator): """ @@ -29,6 +27,7 @@ def validate(self, filepath, expected=None): filepath: The file to validate expected: The expected format registry key (PUID) e.g. fmt/354 """ + logger = logging.getLogger('essarch.fixity.validation.format') logger.debug('Validating format of %s' % filepath) name, version, reg_key = expected diff --git a/ESSArch_Core/fixity/validation/backends/repeated_extension.py b/ESSArch_Core/fixity/validation/backends/repeated_extension.py index 458b4c7a4..ec07f36ea 100644 --- a/ESSArch_Core/fixity/validation/backends/repeated_extension.py +++ b/ESSArch_Core/fixity/validation/backends/repeated_extension.py @@ -9,8 +9,6 @@ from ESSArch_Core.fixity.models import Validation from ESSArch_Core.fixity.validation.backends.base import BaseValidator -logger = logging.getLogger('essarch.fixity.validation.repeated_extension') - REPEATED_PATTERN = r'\.(\w+)\.\1' @@ -25,6 +23,7 @@ class RepeatedExtensionValidator(BaseValidator): """ def validate(self, filepath): + logger = logging.getLogger('essarch.fixity.validation.repeated_extension') logger.debug('Validating extension of %s' % filepath) val_obj = Validation( diff --git a/ESSArch_Core/fixity/validation/backends/structure.py b/ESSArch_Core/fixity/validation/backends/structure.py index 2fd356d1d..2064b3764 100644 --- a/ESSArch_Core/fixity/validation/backends/structure.py +++ b/ESSArch_Core/fixity/validation/backends/structure.py @@ -11,8 +11,6 @@ from ESSArch_Core.fixity.validation.backends.base import BaseValidator from ESSArch_Core.util import normalize_path -logger = logging.getLogger('essarch.fixity.validation.structure') - class StructureValidator(BaseValidator): """ @@ -111,6 +109,7 @@ def validate_folder(self, path, node): raise ValidationError('Missing {files} in {path}'.format(files=','.join(required_files), path=path)) def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.structure') root = self.options.get('tree', []) filepath = normalize_path(filepath) logger.debug("Validating structure of %s" % filepath) diff --git a/ESSArch_Core/fixity/validation/backends/xml.py b/ESSArch_Core/fixity/validation/backends/xml.py index 31ec6bc69..f64a96c7d 100644 --- a/ESSArch_Core/fixity/validation/backends/xml.py +++ b/ESSArch_Core/fixity/validation/backends/xml.py @@ -18,8 +18,6 @@ from ESSArch_Core.fixity.validation.backends.base import BaseValidator from ESSArch_Core.util import normalize_path, win_to_posix -logger = logging.getLogger('essarch.fixity.validation.xml') - class DiffCheckValidator(BaseValidator): """ @@ -120,6 +118,7 @@ def _get_size(self, input_file): return os.path.getsize(input_file) def _validate(self, filepath): + logger = logging.getLogger('essarch.fixity.validation.xml') relpath = normalize_path(os.path.relpath(self._get_filepath(filepath), self.rootdir)) newhash = self._get_checksum(filepath, relpath=relpath) @@ -171,6 +170,7 @@ def _validate(self, filepath): return self._create_obj(relpath, True, msg) def _validate_deleted_files(self, objs): + logger = logging.getLogger('essarch.fixity.validation.xml') delete_count = 0 for deleted_hash, deleted_hash_files in self.deleted.items(): present_hash_files = self.present.get(deleted_hash, []) @@ -201,6 +201,7 @@ def _validate_deleted_files(self, objs): return delete_count def _validate_present_files(self, objs): + logger = logging.getLogger('essarch.fixity.validation.xml') for _present_hash, present_hash_files in self.present.items(): for f in present_hash_files: self.added += 1 @@ -209,6 +210,7 @@ def _validate_present_files(self, objs): objs.append(self._create_obj(f, False, msg)) def validate(self, path, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') xmlfile = self.context objs = [] self._reset_dicts() @@ -265,6 +267,7 @@ def _get_size(self, input_file): return input_file.size def validate(self, path, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') xmlfile = self.context objs = [] self._reset_dicts() @@ -317,6 +320,7 @@ def validate(self, path, expected=None): class XMLSchemaValidator(BaseValidator): def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') if self.context: logger.debug('Validating schema of {xml} against {schema}'.format(xml=filepath, schema=self.context)) else: @@ -392,6 +396,7 @@ def cli(path, schema): class XMLSyntaxValidator(BaseValidator): def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') logger.debug('Validating syntax of {xml}'.format(xml=filepath)) etree.clear_error_log() @@ -465,6 +470,7 @@ def cli(path): class XMLSchematronValidator(BaseValidator): def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') logger.debug('Validating {xml} against {schema}'.format(xml=filepath, schema=self.context)) rootdir = self.options.get('rootdir') @@ -538,6 +544,7 @@ def _validate_schematron(self, filepath): class XMLISOSchematronValidator(BaseValidator): def validate(self, filepath, expected=None): + logger = logging.getLogger('essarch.fixity.validation.xml') logger.debug('Validating {xml} against {schema}'.format(xml=filepath, schema=self.context)) rootdir = self.options.get('rootdir') etree.clear_error_log() diff --git a/ESSArch_Core/install/update_remote.py b/ESSArch_Core/install/update_remote.py index a7c9f484c..eec54dae6 100644 --- a/ESSArch_Core/install/update_remote.py +++ b/ESSArch_Core/install/update_remote.py @@ -46,7 +46,6 @@ SubmissionAgreementSerializer, ) -logger = logging.getLogger('essarch.ip') host = 'https://essarch-media.org' # org_name = 'Default' @@ -60,6 +59,7 @@ def update_profile(profile_obj): + logger = logging.getLogger('essarch.ip') data = ProfileDetailSerializer(instance=profile_obj).data remote_url = urljoin(host, 'api/profiles/') response = session.post(remote_url, json=data, timeout=10) @@ -72,6 +72,7 @@ def update_profile(profile_obj): def update_storage_policy(storage_policy_obj): + logger = logging.getLogger('essarch.ip') data = StoragePolicySerializer(instance=storage_policy_obj).data # Blank remote_server if match host for sm_obj in data['storage_methods']: @@ -93,6 +94,7 @@ def update_storage_policy(storage_policy_obj): # @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)) def update_sa(id): + logger = logging.getLogger('essarch.ip') sa_obj = SubmissionAgreement.objects.get(id=id) sa_obj_data = SubmissionAgreementSerializer(instance=sa_obj).data diff --git a/ESSArch_Core/ip/models.py b/ESSArch_Core/ip/models.py index dea33fb20..e03e2415a 100644 --- a/ESSArch_Core/ip/models.py +++ b/ESSArch_Core/ip/models.py @@ -123,10 +123,6 @@ from ESSArch_Core.WorkflowEngine.util import create_workflow User = get_user_model() - - -logger = logging.getLogger('essarch.ip') - IP_LOCK_PREFIX = 'lock_ip_' @@ -646,6 +642,7 @@ def create_new_generation(self, state, responsible, object_identifier_value): return new_aip def get_content_type_importer_name(self): + logger = logging.getLogger('essarch.ip') ct_profile = self.get_profile('content_type') if ct_profile is None: msg = 'No content_type profile set for {objid}'.format(objid=self.object_identifier_value) @@ -1428,6 +1425,7 @@ def create_preservation_workflow(self): def create_access_workflow(self, user, tar=False, extracted=False, new=False, object_identifier_value=None, package_xml=False, aic_xml=False, diff_check=False, edit=False): + logger = logging.getLogger('essarch.ip') if new: dst_object_identifier_value = object_identifier_value or str(uuid.uuid4()) else: @@ -1986,6 +1984,7 @@ def create_access_workflow(self, user, tar=False, extracted=False, new=False, ob def create_migration_workflow(self, temp_path, storage_methods, export_path='', tar=False, extracted=False, package_xml=False, aic_xml=False, diff_check=True, responsible=None): + logger = logging.getLogger('essarch.ip') container_methods = self.policy.storage_methods.secure_storage().filter( remote=False, pk__in=storage_methods) # non_container_methods = self.policy.storage_methods.archival_storage().filter( @@ -2558,6 +2557,7 @@ def create_migration_workflow(self, temp_path, storage_methods, export_path='', return create_workflow(workflow, self, name='Migrate Information Package', responsible=responsible) def write_to_search_index(self, task): + logger = logging.getLogger('essarch.ip') srcdir = self.object_path ct_profile = self.get_profile('content_type') indexed_files = [] @@ -2615,6 +2615,7 @@ def get_cached_storage_object(self): ) def get_fastest_readable_storage_object(self): + logger = logging.getLogger('essarch.ip') NO_READABLE_CACHED_STORAGE_ERROR_MSG = ( 'No readable cached storage object for {} found, getting fastest storage object'.format( self.object_identifier_value @@ -2658,8 +2659,9 @@ def get_temp_container_aic_xml_path(self, temp_path=None): return os.path.join(temp_dir, self.aic.object_identifier_value + '.xml') @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.ip'), logging.DEBUG)) def update_remote_ip(self, host, session): + logger = logging.getLogger('essarch.ip') from ESSArch_Core.ip.serializers import ( InformationPackageFromMasterSerializer, ) @@ -2674,8 +2676,9 @@ def update_remote_ip(self, host, session): raise @retry(retry=retry_if_exception_type(StorageMediumFull), reraise=True, stop=stop_after_attempt(2), - wait=wait_fixed(60), before_sleep=before_sleep_log(logger, logging.DEBUG)) + wait=wait_fixed(60), before_sleep=before_sleep_log(logging.getLogger('essarch.ip'), logging.DEBUG)) def preserve(self, src: list, storage_target, container: bool, task): + logger = logging.getLogger('essarch.ip') qs = StorageMedium.objects.filter( storage_target__methods__containers=container, ).writeable().order_by('last_changed_local') @@ -2759,6 +2762,7 @@ def preserve(self, src: list, storage_target, container: bool, task): return str(storage_object.pk) def access(self, storage_object, task, dst=None): + logger = logging.getLogger('essarch.ip') logger.debug('Accessing information package {} from storage object {}'.format( self.object_identifier_value, str(storage_object.pk), )) diff --git a/ESSArch_Core/ip/signals.py b/ESSArch_Core/ip/signals.py index 987ae4bcb..e05e1a4bd 100644 --- a/ESSArch_Core/ip/signals.py +++ b/ESSArch_Core/ip/signals.py @@ -8,16 +8,16 @@ from ESSArch_Core.ip.models import InformationPackage, Workarea -logger = logging.getLogger('essarch.core') - @receiver(pre_delete, sender=InformationPackage) def ip_pre_delete(sender, instance, using, **kwargs): + logger = logging.getLogger('essarch.core') logger.debug('Deleting information package %s' % instance.pk) @receiver(post_delete, sender=InformationPackage) def ip_post_delete(sender, instance, using, **kwargs): + logger = logging.getLogger('essarch.core') logger.info('Information package %s was deleted' % instance.pk) instance.informationpackagegroupobjects_set.all().delete() diff --git a/ESSArch_Core/ip/tasks.py b/ESSArch_Core/ip/tasks.py index 9d11d2915..5a56e43bb 100644 --- a/ESSArch_Core/ip/tasks.py +++ b/ESSArch_Core/ip/tasks.py @@ -77,7 +77,6 @@ from ESSArch_Core.WorkflowEngine.models import ProcessTask User = get_user_model() -logger = logging.getLogger('essarch') @app.task(bind=True, event_type=10500) @@ -557,7 +556,7 @@ def CreateReceipt(self, task_id=None, backend=None, template=None, destination=N try: ip = self.get_information_package() except ObjectDoesNotExist: - logger.warning('exception ip DoesNotExist in CreateReceipt. task_id: {}, ip: {}'.format(task_id, self.ip)) + self.logger.warning('exception ip DoesNotExist in CreateReceipt. task_id: {}, ip: {}'.format(task_id, self.ip)) ip = None template, destination, outcome, short_message, message, date = self.parse_params( template, destination, outcome, short_message, message, date @@ -572,9 +571,9 @@ def CreateReceipt(self, task_id=None, backend=None, template=None, destination=N try: task = ProcessTask.objects.get(celery_id=task_id) except ProcessTask.DoesNotExist as e: - logger.warning('exception ProcessTask DoesNotExist for failed task_id: {} in CreateReceipt. ip: {}, \ + self.logger.warning('exception ProcessTask DoesNotExist for failed task_id: {} in CreateReceipt. ip: {}, \ CreateReceipt_task_id: {}'.format(task_id, self.ip, self.get_processtask())) - logger.exception(e) + self.logger.exception(e) task = None return backend.create(template, destination, outcome, short_message, message, date, ip=ip, task=task, **kwargs) @@ -607,7 +606,7 @@ def MarkArchived(self, remote_host=None, remote_credentials=None): if task.status == celery_states.PENDING: task.run_remote_copy(requests_session, remote_host) elif task.status != celery_states.SUCCESS: - logger.debug('task.status: {}'.format(task.status)) + self.logger.debug('task.status: {}'.format(task.status)) task.retry_remote_copy(requests_session, remote_host) task.status = celery_states.PENDING diff --git a/ESSArch_Core/maintenance/models.py b/ESSArch_Core/maintenance/models.py index fe5d05eca..759690d23 100644 --- a/ESSArch_Core/maintenance/models.py +++ b/ESSArch_Core/maintenance/models.py @@ -34,9 +34,7 @@ ) from ESSArch_Core.WorkflowEngine.util import create_workflow -logger = logging.getLogger('essarch.maintenance') User = get_user_model() - ARCHIVAL_OBJECT = 'archival_object' METADATA = 'metadata' TYPE_CHOICES = ( @@ -97,6 +95,7 @@ def get_report_context(self): return {'job': self, 'rule': self.template} def _generate_report(self): + logger = logging.getLogger('essarch.maintenance') logger.info(f"User '{self.user}' generating report with of type '{self.MAINTENANCE_TYPE}'") template = 'maintenance/%s_report.html' % self.MAINTENANCE_TYPE dst = self.get_report_pdf_path() @@ -108,6 +107,7 @@ def create_notification(self, status): raise NotImplementedError def _mark_as_complete(self): + logger = logging.getLogger('essarch.maintenance') try: self._generate_report() except Exception: @@ -269,6 +269,7 @@ def delete_document_tags(self, ip, new_ip, new_ip_tmpdir): @transaction.atomic def _run(self): + logger = logging.getLogger('essarch.maintenance') self.delete_event_type = EventType.objects.get(eventType=50710) entries = [] diff --git a/ESSArch_Core/search/documents.py b/ESSArch_Core/search/documents.py index b014f6f09..fea2b19fd 100644 --- a/ESSArch_Core/search/documents.py +++ b/ESSArch_Core/search/documents.py @@ -8,8 +8,6 @@ from ESSArch_Core.search.alias_migration import migrate -logger = logging.getLogger('essarch.search.documents.DocumentBase') - class DocumentBase(es.Document): @classmethod @@ -70,6 +68,7 @@ def perform_index(cls, queryset, batch_size, index_file_content=False): """ Performs the indexing. """ + logger = logging.getLogger('essarch.search.documents.DocumentBase') num = queryset.count() logger.debug('Perform bulk index for {} objects with batch_size: {}'.format(num, batch_size)) conn = get_es_connection() diff --git a/ESSArch_Core/search/importers/base.py b/ESSArch_Core/search/importers/base.py index b973e08b5..2b4389c88 100644 --- a/ESSArch_Core/search/importers/base.py +++ b/ESSArch_Core/search/importers/base.py @@ -9,8 +9,6 @@ from ESSArch_Core.tags.documents import Component from ESSArch_Core.tags.models import Tag, TagVersion -logger = logging.getLogger('essarch.search.importers.BaseImporter') - class BaseImporter(): def __init__(self, task=None): @@ -33,6 +31,7 @@ def import_content(self, path, rootdir=None, ip=None, **extra_paths): raise NotImplementedError def update_current_tag_versions(self): + logger = logging.getLogger('essarch.search.importers.BaseImporter') logger.info("Update current tag versions...") versions = TagVersion.objects.filter(tag=OuterRef('pk')) @@ -48,6 +47,7 @@ def update_current_tag_versions(self): @staticmethod def save_to_elasticsearch(components): + logger = logging.getLogger('essarch.search.importers.BaseImporter') logger.info("Saving to Elasticsearch...") conn = get_es_connection() count = 0 @@ -69,6 +69,7 @@ def save_to_elasticsearch(components): @staticmethod def cleanup_elasticsearch(task): + logger = logging.getLogger('essarch.search.importers.BaseImporter') logger.info("Deleting task tags already in Elasticsearch...") conn = get_es_connection() Search(using=conn, index='_all').query('term', task_id=str(task.pk)).delete() diff --git a/ESSArch_Core/search/ingest.py b/ESSArch_Core/search/ingest.py index 3e68f17d5..1f38f6840 100644 --- a/ESSArch_Core/search/ingest.py +++ b/ESSArch_Core/search/ingest.py @@ -20,10 +20,9 @@ timestamp_to_datetime, ) -logger = logging.getLogger('essarch.search.ingest') - def index_document(tag_version, filepath): + logger = logging.getLogger('essarch.search.ingest') exclude_file_format_from_indexing_content = settings.EXCLUDE_FILE_FORMAT_FROM_INDEXING_CONTENT fid = FormatIdentifier() @@ -99,6 +98,7 @@ def index_path(ip, path, parent=None): :rtype: File or Directory """ + logger = logging.getLogger('essarch.search.ingest') isfile = os.path.isfile(path) id = str(uuid.uuid4()) diff --git a/ESSArch_Core/storage/backends/disk.py b/ESSArch_Core/storage/backends/disk.py index 4b78ca81d..6ef352a7a 100644 --- a/ESSArch_Core/storage/backends/disk.py +++ b/ESSArch_Core/storage/backends/disk.py @@ -12,13 +12,12 @@ from ESSArch_Core.storage.models import DISK, StorageObject from ESSArch_Core.util import normalize_path, open_file -logger = logging.getLogger('essarch.storage.backends.disk') - class DiskStorageBackend(BaseStorageBackend): type = DISK def _extract(self, storage_object, dst): + logger = logging.getLogger('essarch.storage.backends.disk') path = storage_object.get_full_path() logger.debug('Extracting {src} to {dst}'.format(src=path, dst=dst)) @@ -54,6 +53,7 @@ def open(self, storage_object: StorageObject, file, mode='r', *args, **kwargs): return open(path, mode, *args, **kwargs) def read(self, storage_object, dst, extract=False, include_xml=True, block_size=DEFAULT_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.backends.disk') src = storage_object.get_full_path() if storage_object.container: @@ -84,6 +84,7 @@ def read(self, storage_object, dst, extract=False, include_xml=True, block_size= return copy(src, dst, block_size=block_size) def write(self, src, ip, container, storage_medium, block_size=DEFAULT_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.backends.disk') if isinstance(src, str): src = [src] dst = storage_medium.storage_target.target diff --git a/ESSArch_Core/storage/backends/s3.py b/ESSArch_Core/storage/backends/s3.py index 82b02e77e..911fc25cd 100644 --- a/ESSArch_Core/storage/backends/s3.py +++ b/ESSArch_Core/storage/backends/s3.py @@ -11,7 +11,6 @@ from ESSArch_Core.storage.copy import DEFAULT_BLOCK_SIZE from ESSArch_Core.storage.models import CAS, StorageObject -logger = logging.getLogger('essarch.storage.backends.s3') AWS = settings.AWS s3 = boto3.resource('s3', @@ -68,6 +67,7 @@ def read(self, storage_object, dst, extract=False, include_xml=True, block_size= return dst def write(self, src, ip, container, storage_medium, block_size=DEFAULT_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.backends.s3') if isinstance(src, str): src = [src] dst = storage_medium.storage_target.target diff --git a/ESSArch_Core/storage/backends/tape.py b/ESSArch_Core/storage/backends/tape.py index 9e34200eb..624c840db 100644 --- a/ESSArch_Core/storage/backends/tape.py +++ b/ESSArch_Core/storage/backends/tape.py @@ -29,7 +29,6 @@ ) User = get_user_model() -logger = logging.getLogger('essarch.storage.backends.tape') class TapeStorageBackend(BaseStorageBackend): @@ -37,6 +36,7 @@ class TapeStorageBackend(BaseStorageBackend): @staticmethod def lock_or_wait_for_drive(storage_medium, io_lock_key, wait_timeout=10 * 60): + logger = logging.getLogger('essarch.storage.backends.tape') drive = storage_medium.tape_drive if isinstance(io_lock_key, StorageObject): io_lock_key = pickle.dumps(str(io_lock_key.pk)) @@ -75,6 +75,7 @@ def lock_or_wait_for_drive(storage_medium, io_lock_key, wait_timeout=10 * 60): @staticmethod def wait_for_media_transit(storage_medium, wait_timeout=10 * 60): + logger = logging.getLogger('essarch.storage.backends.tape') timeout_at = time.monotonic() + wait_timeout while storage_medium.tape_drive.locked: logger.debug('Storage medium {} ({}) is in transit, sleeps for 5 seconds and checking again'.format( @@ -86,6 +87,7 @@ def wait_for_media_transit(storage_medium, wait_timeout=10 * 60): storage_medium.refresh_from_db() def prepare_for_io(self, storage_medium, io_lock_key=None, wait_timeout=10 * 60): + logger = logging.getLogger('essarch.storage.backends.tape') storage_medium.refresh_from_db() if storage_medium.tape_drive is not None: self.wait_for_media_transit(storage_medium) @@ -140,6 +142,7 @@ def prepare_for_read(self, storage_medium, io_lock_key=None): return self.prepare_for_io(storage_medium, io_lock_key) def read(self, storage_object, dst, extract=False, include_xml=True, block_size=DEFAULT_TAPE_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.backends.tape') tape_pos = int(storage_object.content_location_value) medium = storage_object.storage_medium ip = storage_object.ip @@ -219,6 +222,7 @@ def prepare_for_write(self, storage_medium, io_lock_key=None): return self.prepare_for_io(storage_medium, io_lock_key) def write(self, src, ip, container, storage_medium, block_size=DEFAULT_TAPE_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.backends.tape') block_size = storage_medium.block_size * 512 last_written_obj = StorageObject.objects.filter( @@ -266,6 +270,7 @@ def delete(self, storage_object): def post_mark_as_full(cls, storage_medium): """Called after a medium has been successfully marked as full""" + logger = logging.getLogger('essarch.storage.backends.tape') drive = str(storage_medium.drive) logger.debug('Release lock for drive {} and storage medium {} ({})'.format( diff --git a/ESSArch_Core/storage/copy.py b/ESSArch_Core/storage/copy.py index 1dca39b4f..bda846653 100644 --- a/ESSArch_Core/storage/copy.py +++ b/ESSArch_Core/storage/copy.py @@ -22,8 +22,6 @@ MB = 1024 * 1024 DEFAULT_BLOCK_SIZE = 10 * MB -logger = logging.getLogger('essarch.storage.copy') - def enough_space_available(dst: str, src: str, raise_exception: bool = False) -> bool: """ @@ -52,8 +50,9 @@ def enough_space_available(dst: str, src: str, raise_exception: bool = False) -> @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.storage.copy'), logging.DEBUG)) def copy_chunk_remotely(src, dst, offset, file_size, requests_session, upload_id=None, block_size=DEFAULT_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.copy') filename = os.path.basename(src) with open(src, 'rb') as srcf: @@ -96,6 +95,7 @@ def copy_chunk_remotely(src, dst, offset, file_size, requests_session, upload_id def copy_file_locally(src, dst): + logger = logging.getLogger('essarch.storage.copy') fsize = os.stat(src).st_size directory = os.path.dirname(dst) @@ -122,13 +122,14 @@ def copy_file_locally(src, dst): @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.storage.copy'), logging.DEBUG)) def _send_completion_request(requests_session, completion_url, data, headers): response = requests_session.post(completion_url, data=data, headers=headers, timeout=60) response.raise_for_status() def copy_file_remotely(src, dst, requests_session, block_size=DEFAULT_BLOCK_SIZE): + logger = logging.getLogger('essarch.storage.copy') fsize = os.stat(src).st_size idx = 0 @@ -188,6 +189,7 @@ def copy_file(src, dst, requests_session=None, block_size=DEFAULT_BLOCK_SIZE): None """ + logger = logging.getLogger('essarch.storage.copy') if os.path.isdir(dst): dst = os.path.join(dst, os.path.basename(src)) diff --git a/ESSArch_Core/storage/models.py b/ESSArch_Core/storage/models.py index ebaec4541..901190881 100644 --- a/ESSArch_Core/storage/models.py +++ b/ESSArch_Core/storage/models.py @@ -46,10 +46,7 @@ from ESSArch_Core.storage.tape import read_tape, set_tape_file_number from ESSArch_Core.util import delete_path -logger = logging.getLogger('essarch.storage.models') - DRIVE_LOCK_PREFIX = 'lock_drive_' - DISK = 200 TAPE = 300 CAS = 400 @@ -612,7 +609,8 @@ class StorageMedium(models.Model): @classmethod @transaction.atomic @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.storage.models'), + logging.DEBUG)) def create_from_remote_copy(cls, host, session, object_id, create_tape_drive=False, create_tape_slot=False): remote_obj_url = urljoin(host, reverse('storagemedium-detail', args=(object_id,))) r = session.get(remote_obj_url, timeout=60) @@ -669,6 +667,7 @@ def deactivate(self) -> None: self.save() def mark_as_full(self): + logger = logging.getLogger('essarch.storage.models') logger.debug('Marking storage medium as full: "{}"'.format(str(self.pk))) objs = self.storage.annotate( content_location_value_int=Cast('content_location_value', models.IntegerField()) @@ -781,7 +780,8 @@ class StorageObject(models.Model): @classmethod @transaction.atomic @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.storage.models'), + logging.DEBUG)) def create_from_remote_copy(cls, host, session, object_id): remote_obj_url = urljoin(host, reverse('storageobject-detail', args=(object_id,))) r = session.get(remote_obj_url, timeout=60) @@ -849,6 +849,7 @@ def open(self, path, *args, **kwargs): return backend.open(self, path, *args, **kwargs) def read(self, dst, task, extract=False): + logger = logging.getLogger('essarch.storage.models') ip = self.ip is_cached_storage_object = self.is_cache_for_ip(ip) @@ -1055,7 +1056,8 @@ def locked_by(self): @classmethod @transaction.atomic @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.storage.models'), + logging.DEBUG)) def create_from_remote_copy(cls, host, session, object_id, create_storage_medium=True): remote_obj_url = urljoin(host, reverse('tapedrive-detail', args=(object_id,))) r = session.get(remote_obj_url, timeout=60) @@ -1104,7 +1106,8 @@ class TapeSlot(models.Model): @classmethod @transaction.atomic @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.storage.models'), + logging.DEBUG)) def create_from_remote_copy(cls, host, session, object_id, create_storage_medium=True): remote_obj_url = urljoin(host, reverse('tapeslot-detail', args=(object_id,))) r = session.get(remote_obj_url, timeout=60) @@ -1144,7 +1147,8 @@ class Robot(models.Model): @classmethod @transaction.atomic @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.storage.models'), + logging.DEBUG)) def create_from_remote_copy(cls, host, session, object_id): remote_obj_url = urljoin(host, reverse('robot-detail', args=(object_id,))) r = session.get(remote_obj_url, timeout=60) diff --git a/ESSArch_Core/storage/serializers.py b/ESSArch_Core/storage/serializers.py index f6b7056bb..d26ef275a 100644 --- a/ESSArch_Core/storage/serializers.py +++ b/ESSArch_Core/storage/serializers.py @@ -34,8 +34,6 @@ ) from ESSArch_Core.WorkflowEngine.models import ProcessStep -logger = logging.getLogger('essarch') - class StorageMediumSerializer(serializers.ModelSerializer): storage_target = StorageTargetSerializer(allow_null=False, required=True) @@ -450,6 +448,7 @@ class StorageMigrationCreateSerializer(serializers.Serializer): export_path = serializers.CharField(write_only=True, required=False, allow_blank=True) def create(self, validated_data): + logger = logging.getLogger('essarch') steps = [] user = None request = self.context.get("request") diff --git a/ESSArch_Core/storage/tape.py b/ESSArch_Core/storage/tape.py index 4088fdc73..1f730e996 100644 --- a/ESSArch_Core/storage/tape.py +++ b/ESSArch_Core/storage/tape.py @@ -28,7 +28,6 @@ MB = 1024 * 1024 DEFAULT_TAPE_BLOCK_SIZE = 20 * 512 -logger = logging.getLogger('essarch.storage.tape') @retry(reraise=True, stop=stop_after_attempt(5), wait=wait_fixed(60)) @@ -42,6 +41,7 @@ def mount_tape(robot, slot, drive): drive: Which drive to load to """ + logger = logging.getLogger('essarch.storage.tape') cmd = 'mtx -f %s load %d %d' % (robot, slot, drive) p = Popen(shlex.split(cmd), stdout=PIPE, stderr=PIPE, universal_newlines=True) logger.debug( @@ -82,6 +82,7 @@ def unmount_tape(robot, slot, drive): drive: Which drive to load from """ + logger = logging.getLogger('essarch.storage.tape') cmd = 'mtx -f %s unload %d %d' % (robot, slot, drive) p = Popen(shlex.split(cmd), stdout=PIPE, stderr=PIPE, universal_newlines=True) logger.debug( @@ -116,6 +117,7 @@ def rewind_tape(drive): Rewinds the tape in the given drive """ + logger = logging.getLogger('essarch.storage.tape') cmd = 'mt -f %s rewind' % (drive) p = Popen(shlex.split(cmd), stdout=PIPE, stderr=PIPE, universal_newlines=True) logger.debug('Rewinding tape in {drive}: {cmd}'.format(drive=drive, cmd=cmd)) @@ -148,6 +150,7 @@ def is_tape_drive_online(drive): True if the drive is online, false otherwise """ + logger = logging.getLogger('essarch.storage.tape') cmd = 'mt -f %s status' % drive p = Popen(shlex.split(cmd), stdout=PIPE, stderr=PIPE, universal_newlines=True) logger.debug('Checking if {drive} is online: {cmd}'.format(drive=drive, cmd=cmd)) @@ -170,6 +173,7 @@ def is_tape_drive_online(drive): def wait_to_come_online(drive, timeout=120): + logger = logging.getLogger('essarch.storage.tape') logger.debug('Waiting for {drive} to come online'.format(drive=drive)) while timeout >= 0: if is_tape_drive_online(drive): @@ -184,6 +188,7 @@ def wait_to_come_online(drive, timeout=120): @retry(reraise=True, stop=stop_after_attempt(5), wait=wait_fixed(60)) def tape_empty(drive): + logger = logging.getLogger('essarch.storage.tape') logger.debug('Checking if tape in {drive} is empty'.format(drive=drive)) try: logger.debug('Opening tape in {drive}'.format(drive=drive)) @@ -228,6 +233,7 @@ def create_tape_label(medium, xmlpath): def verify_tape_label(medium, xmlstring): + logger = logging.getLogger('essarch.storage.tape') logger.debug('Verifying tape label of {medium} against {xml}'.format(medium=medium, xml=xmlstring)) try: root = etree.fromstring(xmlstring) @@ -252,6 +258,7 @@ def verify_tape_label(medium, xmlstring): def read_tape(device, path='.', block_size=DEFAULT_TAPE_BLOCK_SIZE, medium_id=''): + logger = logging.getLogger('essarch.storage.tape') logger.info( 'Extracting content from {device} ({medium_id}) to {path}, with block size {size}'.format( device=device, medium_id=medium_id, path=path, size=block_size @@ -276,6 +283,7 @@ def write_to_tape(device, paths, block_size=DEFAULT_TAPE_BLOCK_SIZE, arcname=Non TypeError: If |`paths`| > 1 and `arcname` is not None """ + logger = logging.getLogger('essarch.storage.tape') if isinstance(paths, str): paths = [paths] @@ -312,6 +320,7 @@ def write_to_tape(device, paths, block_size=DEFAULT_TAPE_BLOCK_SIZE, arcname=Non def get_tape_file_number(drive): + logger = logging.getLogger('essarch.storage.tape') cmd = 'mt -f %s status' % drive p = Popen(shlex.split(cmd), stdout=PIPE, stderr=PIPE, universal_newlines=True) logger.debug('Getting tape file number of {drive}: {cmd}'.format(drive=drive, cmd=cmd)) @@ -336,6 +345,7 @@ def get_tape_file_number(drive): def set_tape_file_number(drive, num=0): + logger = logging.getLogger('essarch.storage.tape') if num == 0: return rewind_tape(drive) @@ -394,6 +404,7 @@ def robot_inventory(robot): TapeSlot, ) + logger = logging.getLogger('essarch.storage.tape') backend_name = settings.ESSARCH_TAPE_IDENTIFICATION_BACKEND backend = get_tape_identification_backend(backend_name) diff --git a/ESSArch_Core/tags/models.py b/ESSArch_Core/tags/models.py index 783d8b9e9..fecb596a5 100644 --- a/ESSArch_Core/tags/models.py +++ b/ESSArch_Core/tags/models.py @@ -31,7 +31,6 @@ from ESSArch_Core.profiles.models import SubmissionAgreement User = get_user_model() -logger = logging.getLogger('essarch.tags') class NodeIdentifier(models.Model): @@ -334,6 +333,7 @@ def is_compatible_with_last_version(self): def publish(self): from ESSArch_Core.tags.documents import StructureUnitDocument + logger = logging.getLogger('essarch.tags') if self.is_new_version(): # TODO: What if multiple users wants to create a new version in parallel? # Use permissions to stop it? @@ -482,6 +482,7 @@ class StructureUnit(MPTTModel): @transaction.atomic def copy_to_structure(self, structure, template_unit=None, old_archive_ts=None): + logger = logging.getLogger('essarch.tags') old_parent_ref_code = getattr(self.parent, 'reference_code', None) parent = None @@ -533,6 +534,7 @@ def copy_to_structure(self, structure, template_unit=None, old_archive_ts=None): return new_unit def create_template_instance(self, structure_instance, old_archive_ts=None): + logger = logging.getLogger('essarch.tags') new_unit = self.copy_to_structure(structure_instance, template_unit=self, old_archive_ts=old_archive_ts) new_archive_structure = new_unit.structure.tagstructure_set.first().get_root() @@ -709,6 +711,7 @@ def relate_to(self, other_unit, relation_type, **kwargs): ) def get_related_in_other_structure(self, other_structure): + logger = logging.getLogger('essarch.tags') structure = self.structure logger.debug('other_structure: {}, other_structure.is_template: {}, other_structure.template: {}, \ other_structure.id: {}'.format(other_structure, other_structure.is_template, other_structure.template, @@ -1314,6 +1317,7 @@ def change_organization(self, organization, force=False): # Problem...get IPs related to "Arkivbildare" with not is related IPs to "Arkiv" def get_organization(self): + logger = logging.getLogger('essarch.tags') group_objs_model = get_group_objs_model(self) try: go_obj = group_objs_model.objects.get_organization(self) @@ -1385,6 +1389,7 @@ class TagStructure(MPTTModel): subtree = MPTTSubtree() def copy_to_new_structure(self, new_structure, new_unit=None): + logger = logging.getLogger('essarch.tags') new_parent_tag = None if self.parent is not None: @@ -1424,6 +1429,7 @@ def copy_to_new_structure(self, new_structure, new_unit=None): @transaction.atomic def copy_descendants_to_new_structure(self, new_structure): + logger = logging.getLogger('essarch.tags') for old_descendant in self.get_descendants(include_self=False): logger.debug('old_descendant: {} copy to new_structure: {}'.format(old_descendant, new_structure)) old_descendant.copy_to_new_structure(new_structure) diff --git a/ESSArch_Core/tags/search.py b/ESSArch_Core/tags/search.py index a83feea16..0be620f46 100644 --- a/ESSArch_Core/tags/search.py +++ b/ESSArch_Core/tags/search.py @@ -55,7 +55,6 @@ remove_prefix, ) -logger = logging.getLogger('essarch.search') EXPORT_FORMATS = ('csv', 'pdf') SORTABLE_FIELDS = ( {'name.keyword': {'unmapped_type': 'keyword'}}, @@ -366,6 +365,7 @@ def get_object(self, index=None): def get_tag_object(self, qs=None): # Perform the lookup filtering. + logger = logging.getLogger('essarch.search') lookup_url_kwarg = self.lookup_url_kwarg or self.lookup_field assert lookup_url_kwarg in self.kwargs, ( @@ -449,6 +449,7 @@ def paginator(self): return super().paginator def list(self, request): + logger = logging.getLogger('essarch.search') params = {key: value[0] for (key, value) in dict(request.query_params).items()} query = params.pop('q', '') export = params.pop('export', None) @@ -553,6 +554,7 @@ def list(self, request): return Response(r, headers={'Count': results.hits.total['value']}) def generate_report(self, hits, format, user): + logger = logging.getLogger('essarch.search') try: tag_versions = [hit.get('_source').get('name') for hit in hits] except Exception: diff --git a/ESSArch_Core/tags/signals.py b/ESSArch_Core/tags/signals.py index 6a5b4c55b..4d01dc3fc 100644 --- a/ESSArch_Core/tags/signals.py +++ b/ESSArch_Core/tags/signals.py @@ -6,11 +6,10 @@ from ESSArch_Core.tags.models import Tag, TagVersion -logger = logging.getLogger('essarch.core') - @receiver(post_save, sender=TagVersion) def set_current_version_after_creation(sender, instance, created, **kwargs): + logger = logging.getLogger('essarch.core') if created and instance.tag.current_version is None: logger.debug(f"TagVersion '{instance}' was created.") tag = instance.tag @@ -22,6 +21,7 @@ def set_current_version_after_creation(sender, instance, created, **kwargs): @receiver(pre_delete, sender=TagVersion) def pre_tag_version_delete(sender, instance, **kwargs): + logger = logging.getLogger('essarch.core') logger.debug(f"Changing current version of TagVersion: '{instance}', before deleting.") if instance.tag.current_version == instance: try: @@ -47,10 +47,12 @@ def post_tag_version_delete(sender, instance, **kwargs): @receiver(post_delete, sender=TagVersion) def log_after_deleting_tag_version(sender, instance, **kwargs): + logger = logging.getLogger('essarch.core') logger.debug(f"TagVersion '{instance}' was deleted.") instance.tagversiongroupobjects_set.all().delete() @receiver(post_delete, sender=Tag) def log_after_deleting_tag(sender, instance, **kwargs): + logger = logging.getLogger('essarch.core') logger.debug(f"Tag '{instance}' was deleted.") diff --git a/ESSArch_Core/tasks.py b/ESSArch_Core/tasks.py index afe11c516..651260ea7 100644 --- a/ESSArch_Core/tasks.py +++ b/ESSArch_Core/tasks.py @@ -93,7 +93,6 @@ User = get_user_model() redis = get_redis_connection() -logger = logging.getLogger('essarch') @app.task(bind=True) @@ -449,7 +448,7 @@ def UpdateIPStatus(self, status, prev=None): except InformationPackage.DoesNotExist: msg = 'exception in UpdateIPStatus for task_id: {}, step_id: {}, DoesNotExist when get ip: {} - return'.format( self.task_id, self.step, self.ip) - logger.warning(msg) + self.logger.warning(msg) return msg if prev is None: diff --git a/ESSArch_Core/util.py b/ESSArch_Core/util.py index 940274566..26f35fe3d 100644 --- a/ESSArch_Core/util.py +++ b/ESSArch_Core/util.py @@ -65,8 +65,6 @@ XSI_NAMESPACE = "http://www.w3.org/2001/XMLSchema-instance" VERSION = get_versions()['version'] -logger = logging.getLogger('essarch') - def make_unicode(text): try: @@ -93,6 +91,7 @@ def remove_prefix(text, prefix): def stable_path(path): + logger = logging.getLogger('essarch') current_size, current_count = get_tree_size_and_count(path) cache_size_key = 'path_size_{}'.format(path) cache_count_key = 'path_count_{}'.format(path) @@ -165,6 +164,7 @@ def get_value_from_path(root, path): path: The path to the text or attribute """ + logger = logging.getLogger('essarch') if path is None: return None @@ -374,6 +374,7 @@ def get_premis_ip_object_element_spec(): def delete_path(path, remote_host=None, remote_credentials=None, task=None): + logger = logging.getLogger('essarch') requests_session = None if remote_credentials: user, passw = decrypt_remote_credentials(remote_credentials) @@ -535,6 +536,7 @@ def get_script_directory(): def convert_file(path, new_format): + logger = logging.getLogger('essarch') if sys.platform == "win32": cmd = ['python.exe', os.path.join(get_script_directory(), 'unoconv.py')] else: @@ -587,6 +589,7 @@ def validate_remote_url(url): def get_charset(byte_str): + logger = logging.getLogger('essarch') decoded_flag = False guess = chardet.detect(byte_str) charsets = [settings.DEFAULT_CHARSET, 'utf-8', 'windows-1252'] @@ -826,6 +829,7 @@ def has_write_access(directory): def open_file(path='', *args, container=None, container_prefix='', **kwargs): + logger = logging.getLogger('essarch') if container is None: return open(path, *args, **kwargs) diff --git a/ESSArch_Core/workflow/tasks.py b/ESSArch_Core/workflow/tasks.py index fb1135c2f..781298f8e 100644 --- a/ESSArch_Core/workflow/tasks.py +++ b/ESSArch_Core/workflow/tasks.py @@ -71,7 +71,6 @@ from ESSArch_Core.WorkflowEngine.models import ProcessTask User = get_user_model() -logger = logging.getLogger('essarch') @app.task(bind=True)