From 662cf7da3b99d9bb09a8d0c6469558c69c151842 Mon Sep 17 00:00:00 2001 From: Oliver Date: Thu, 24 Oct 2024 22:15:01 +1100 Subject: [PATCH] Log failed task (#8333) * Bug fix for build models * Notify staff users when a background task fails * Improve object lookup for notification * Handle url reversal error case * Add unit testing --- src/backend/InvenTree/InvenTree/models.py | 107 +++++++++++++----- src/backend/InvenTree/InvenTree/test_tasks.py | 39 ++++++- src/backend/InvenTree/build/tasks.py | 24 ++-- src/backend/InvenTree/common/notifications.py | 16 ++- src/backend/InvenTree/common/serializers.py | 15 ++- 5 files changed, 147 insertions(+), 54 deletions(-) diff --git a/src/backend/InvenTree/InvenTree/models.py b/src/backend/InvenTree/InvenTree/models.py index 2d2b558b4e..8b465222b2 100644 --- a/src/backend/InvenTree/InvenTree/models.py +++ b/src/backend/InvenTree/InvenTree/models.py @@ -10,8 +10,10 @@ from django.db import models from django.db.models.signals import post_save from django.dispatch import receiver from django.urls import reverse +from django.urls.exceptions import NoReverseMatch from django.utils.translation import gettext_lazy as _ +from django_q.models import Task from error_report.models import Error from mptt.exceptions import InvalidMove from mptt.models import MPTTModel, TreeForeignKey @@ -1051,6 +1053,71 @@ class InvenTreeBarcodeMixin(models.Model): self.save() +def notify_staff_users_of_error(instance, label: str, context: dict): + """Helper function to notify staff users of an error.""" + import common.models + import common.notifications + + try: + # Get all staff users + staff_users = get_user_model().objects.filter(is_staff=True) + + target_users = [] + + # Send a notification to each staff user (unless they have disabled error notifications) + for user in staff_users: + if common.models.InvenTreeUserSetting.get_setting( + 'NOTIFICATION_ERROR_REPORT', True, user=user + ): + target_users.append(user) + + if len(target_users) > 0: + common.notifications.trigger_notification( + instance, + label, + context=context, + targets=target_users, + delivery_methods={common.notifications.UIMessageNotification}, + ) + + except Exception as exc: + # We do not want to throw an exception while reporting an exception! + logger.error(exc) + + +@receiver(post_save, sender=Task, dispatch_uid='failure_post_save_notification') +def after_failed_task(sender, instance: Task, created: bool, **kwargs): + """Callback when a new task failure log is generated.""" + from django.conf import settings + + max_attempts = int(settings.Q_CLUSTER.get('max_attempts', 5)) + n = instance.attempt_count + + # Only notify once the maximum number of attempts has been reached + if not instance.success and n >= max_attempts: + try: + url = InvenTree.helpers_model.construct_absolute_url( + reverse( + 'admin:django_q_failure_change', kwargs={'object_id': instance.pk} + ) + ) + except (ValueError, NoReverseMatch): + url = '' + + notify_staff_users_of_error( + instance, + 'inventree.task_failure', + { + 'failure': instance, + 'name': _('Task Failure'), + 'message': _( + f"Background worker task '{instance.func}' failed after {n} attempts" + ), + 'link': url, + }, + ) + + @receiver(post_save, sender=Error, dispatch_uid='error_post_save_notification') def after_error_logged(sender, instance: Error, created: bool, **kwargs): """Callback when a server error is logged. @@ -1059,41 +1126,21 @@ def after_error_logged(sender, instance: Error, created: bool, **kwargs): """ if created: try: - import common.models - import common.notifications - - users = get_user_model().objects.filter(is_staff=True) - - link = InvenTree.helpers_model.construct_absolute_url( + url = InvenTree.helpers_model.construct_absolute_url( reverse( 'admin:error_report_error_change', kwargs={'object_id': instance.pk} ) ) + except NoReverseMatch: + url = '' - context = { + notify_staff_users_of_error( + instance, + 'inventree.error_log', + { 'error': instance, 'name': _('Server Error'), 'message': _('An error has been logged by the server.'), - 'link': link, - } - - target_users = [] - - for user in users: - if common.models.InvenTreeUserSetting.get_setting( - 'NOTIFICATION_ERROR_REPORT', True, user=user - ): - target_users.append(user) - - if len(target_users) > 0: - common.notifications.trigger_notification( - instance, - 'inventree.error_log', - context=context, - targets=target_users, - delivery_methods={common.notifications.UIMessageNotification}, - ) - - except Exception as exc: - """We do not want to throw an exception while reporting an exception""" - logger.error(exc) + 'link': url, + }, + ) diff --git a/src/backend/InvenTree/InvenTree/test_tasks.py b/src/backend/InvenTree/InvenTree/test_tasks.py index 2cb1ae6f51..03e4d6ee0e 100644 --- a/src/backend/InvenTree/InvenTree/test_tasks.py +++ b/src/backend/InvenTree/InvenTree/test_tasks.py @@ -4,12 +4,13 @@ import os from datetime import timedelta from django.conf import settings +from django.contrib.auth.models import User from django.core.management import call_command from django.db.utils import NotSupportedError from django.test import TestCase from django.utils import timezone -from django_q.models import Schedule +from django_q.models import Schedule, Task from error_report.models import Error import InvenTree.tasks @@ -163,3 +164,39 @@ class InvenTreeTaskTests(TestCase): migration_path.unlink() except IndexError: # pragma: no cover pass + + def test_failed_task_notification(self): + """Test that a failed task will generate a notification.""" + from common.models import NotificationEntry, NotificationMessage + + # Create a staff user (to ensure notifications are sent) + User.objects.create_user(username='staff', password='staffpass', is_staff=True) + + n_tasks = Task.objects.count() + n_entries = NotificationEntry.objects.count() + n_messages = NotificationMessage.objects.count() + + # Create a 'failed' task in the database + # Note: The 'attempt count' is set to 10 to ensure that the task is properly marked as 'failed' + Task.objects.create( + id=n_tasks + 1, + name='failed_task', + func='InvenTree.tasks.failed_task', + group='test', + success=False, + started=timezone.now(), + stopped=timezone.now(), + attempt_count=10, + ) + + # A new notification entry should be created + self.assertEqual(NotificationEntry.objects.count(), n_entries + 1) + self.assertEqual(NotificationMessage.objects.count(), n_messages + 1) + + msg = NotificationMessage.objects.last() + + self.assertEqual(msg.name, 'Task Failure') + self.assertEqual( + msg.message, + "Background worker task 'InvenTree.tasks.failed_task' failed after 10 attempts", + ) diff --git a/src/backend/InvenTree/build/tasks.py b/src/backend/InvenTree/build/tasks.py index d8db2db882..fbdf4f39c3 100644 --- a/src/backend/InvenTree/build/tasks.py +++ b/src/backend/InvenTree/build/tasks.py @@ -10,7 +10,7 @@ from django.utils.translation import gettext_lazy as _ from allauth.account.models import EmailAddress -import build.models +import build.models as build_models import common.notifications import InvenTree.helpers import InvenTree.helpers_email @@ -26,7 +26,7 @@ logger = logging.getLogger('inventree') def auto_allocate_build(build_id: int, **kwargs): """Run auto-allocation for a specified BuildOrder.""" - build_order = build.models.Build.objects.filter(pk=build_id).first() + build_order = build_models.Build.objects.filter(pk=build_id).first() if not build_order: logger.warning("Could not auto-allocate BuildOrder <%s> - BuildOrder does not exist", build_id) @@ -37,7 +37,7 @@ def auto_allocate_build(build_id: int, **kwargs): def complete_build_allocations(build_id: int, user_id: int): """Complete build allocations for a specified BuildOrder.""" - build_order = build.models.Build.objects.filter(pk=build_id).first() + build_order = build_models.Build.objects.filter(pk=build_id).first() if user_id: try: @@ -71,7 +71,7 @@ def update_build_order_lines(bom_item_pk: int): assemblies = bom_item.get_assemblies() # Find all active builds which reference any of the parts - builds = build.models.Build.objects.filter( + builds = build_models.Build.objects.filter( part__in=list(assemblies), status__in=BuildStatusGroups.ACTIVE_CODES ) @@ -79,7 +79,7 @@ def update_build_order_lines(bom_item_pk: int): # Iterate through each build, and update the relevant line items for bo in builds: # Try to find a matching build order line - line = build.models.BuildLine.objects.filter( + line = build_models.BuildLine.objects.filter( build=bo, bom_item=bom_item, ).first() @@ -93,7 +93,7 @@ def update_build_order_lines(bom_item_pk: int): line.save() else: # Create a new line item - build.models.BuildLine.objects.create( + build_models.BuildLine.objects.create( build=bo, bom_item=bom_item, quantity=q, @@ -103,7 +103,7 @@ def update_build_order_lines(bom_item_pk: int): logger.info("Updated %s build orders for part %s", builds.count(), bom_item.part) -def check_build_stock(build: build.models.Build): +def check_build_stock(build: build_models.Build): """Check the required stock for a newly created build order. Send an email out to any subscribed users if stock is low. @@ -192,8 +192,8 @@ def create_child_builds(build_id: int) -> None: """ try: - build_order = build.models.Build.objects.get(pk=build_id) - except (Build.DoesNotExist, ValueError): + build_order = build_models.Build.objects.get(pk=build_id) + except (build_models.Build.DoesNotExist, ValueError): return assembly_items = build_order.part.get_bom_items().filter(sub_part__assembly=True) @@ -201,7 +201,7 @@ def create_child_builds(build_id: int) -> None: for item in assembly_items: quantity = item.quantity * build_order.quantity - sub_order = build.models.Build.objects.create( + sub_order = build_models.Build.objects.create( part=item.sub_part, quantity=quantity, title=build_order.title, @@ -221,7 +221,7 @@ def create_child_builds(build_id: int) -> None: ) -def notify_overdue_build_order(bo: build.models.Build): +def notify_overdue_build_order(bo: build_models.Build): """Notify appropriate users that a Build has just become 'overdue'.""" targets = [] @@ -270,7 +270,7 @@ def check_overdue_build_orders(): """ yesterday = InvenTree.helpers.current_date() - timedelta(days=1) - overdue_orders = build.models.Build.objects.filter( + overdue_orders = build_models.Build.objects.filter( target_date=yesterday, status__in=BuildStatusGroups.ACTIVE_CODES ) diff --git a/src/backend/InvenTree/common/notifications.py b/src/backend/InvenTree/common/notifications.py index f12075a730..21f227722e 100644 --- a/src/backend/InvenTree/common/notifications.py +++ b/src/backend/InvenTree/common/notifications.py @@ -352,16 +352,20 @@ def trigger_notification(obj, category=None, obj_ref='pk', **kwargs): return # Resolve object reference - obj_ref_value = getattr(obj, obj_ref) + refs = [obj_ref, 'pk', 'id', 'uid'] + + obj_ref_value = None + + # Find the first reference that is available + for ref in refs: + if hasattr(obj, ref): + obj_ref_value = getattr(obj, ref) + break # Try with some defaults - if not obj_ref_value: - obj_ref_value = getattr(obj, 'pk', None) - if not obj_ref_value: - obj_ref_value = getattr(obj, 'id', None) if not obj_ref_value: raise KeyError( - f"Could not resolve an object reference for '{obj!s}' with {obj_ref}, pk, id" + f"Could not resolve an object reference for '{obj!s}' with {','.join(set(refs))}" ) # Check if we have notified recently... diff --git a/src/backend/InvenTree/common/serializers.py b/src/backend/InvenTree/common/serializers.py index 991254a1e2..ed134d2707 100644 --- a/src/backend/InvenTree/common/serializers.py +++ b/src/backend/InvenTree/common/serializers.py @@ -234,12 +234,17 @@ class NotificationMessageSerializer(InvenTreeModelSerializer): request = self.context['request'] if request.user and request.user.is_staff: meta = obj.target_object._meta - target['link'] = construct_absolute_url( - reverse( - f'admin:{meta.db_table}_change', - kwargs={'object_id': obj.target_object_id}, + + try: + target['link'] = construct_absolute_url( + reverse( + f'admin:{meta.db_table}_change', + kwargs={'object_id': obj.target_object_id}, + ) ) - ) + except Exception: + # Do not crash if the reverse lookup fails + pass return target