From 797b5f57b08b54add472caf47bdde1ac51a09164 Mon Sep 17 00:00:00 2001 From: Matthias Mair Date: Fri, 20 Jun 2025 01:47:28 +0200 Subject: [PATCH] feat(backend): improve worker tracing (#9808) * feat(backend): improve worker log * refactor tracing details * add tracing to gunicorn setup * add sqlite tracing * add system metrics * instument wsgi * make dbengine better accessible * fix instruction * instrument worker * track task scheduling * trace common tasks * patch in support for django q * trace various tasks * add trcing for other dbs * ignore coverage on tracing stuff * more ignorance --- contrib/container/gunicorn.conf.py | 15 ++++ src/backend/InvenTree/InvenTree/settings.py | 90 +++++++++++-------- src/backend/InvenTree/InvenTree/tasks.py | 18 +++- src/backend/InvenTree/InvenTree/tracing.py | 43 ++++++++- src/backend/InvenTree/InvenTree/version.py | 3 +- src/backend/InvenTree/InvenTree/wsgi.py | 3 + src/backend/InvenTree/build/tasks.py | 8 ++ src/backend/InvenTree/common/models.py | 18 +++- src/backend/InvenTree/common/tasks.py | 6 ++ src/backend/InvenTree/gunicorn.conf.py | 15 ++++ src/backend/InvenTree/order/tasks.py | 9 ++ src/backend/InvenTree/part/tasks.py | 9 ++ .../InvenTree/plugin/base/event/events.py | 5 ++ src/backend/InvenTree/report/tasks.py | 4 + src/backend/InvenTree/stock/tasks.py | 3 + src/backend/requirements.in | 5 ++ src/backend/requirements.txt | 51 ++++++++++- 17 files changed, 258 insertions(+), 47 deletions(-) diff --git a/contrib/container/gunicorn.conf.py b/contrib/container/gunicorn.conf.py index 564423ef10..e6bd714ea0 100644 --- a/contrib/container/gunicorn.conf.py +++ b/contrib/container/gunicorn.conf.py @@ -40,3 +40,18 @@ max_requests_jitter = 50 # preload app so that the ready functions are only executed once preload_app = True + + +def post_fork(server, worker): + """Post-fork hook to set up logging for each worker.""" + from django.conf import settings + + if not settings.TRACING_ENABLED: + return + + # Instrument gunicorm + from InvenTree.tracing import setup_instruments, setup_tracing + + # Run tracing/logging instrumentation + setup_tracing(**settings.TRACING_DETAILS) + setup_instruments() diff --git a/src/backend/InvenTree/InvenTree/settings.py b/src/backend/InvenTree/InvenTree/settings.py index 508cf84278..16f0a82ec1 100644 --- a/src/backend/InvenTree/InvenTree/settings.py +++ b/src/backend/InvenTree/InvenTree/settings.py @@ -13,6 +13,7 @@ import logging import os import sys from pathlib import Path +from typing import Optional from zoneinfo import ZoneInfo, ZoneInfoNotFoundError import django.conf.locale @@ -33,7 +34,11 @@ from InvenTree.config import ( ) from InvenTree.ready import isInMainThread from InvenTree.sentry import default_sentry_dsn, init_sentry -from InvenTree.version import checkMinPythonVersion, inventreeApiVersion +from InvenTree.version import ( + checkMinPythonVersion, + inventreeApiVersion, + inventreeCommitHash, +) from users.oauth2_scopes import oauth2_scopes from . import config, locales @@ -636,25 +641,25 @@ It can be specified in config.yaml (or envvar) as either (for example): - django.db.backends.postgresql """ -db_engine = db_config['ENGINE'].lower() +DB_ENGINE = db_config['ENGINE'].lower() # Correct common misspelling -if db_engine == 'sqlite': - db_engine = 'sqlite3' # pragma: no cover +if DB_ENGINE == 'sqlite': + DB_ENGINE = 'sqlite3' # pragma: no cover -if db_engine in ['sqlite3', 'postgresql', 'mysql']: +if DB_ENGINE in ['sqlite3', 'postgresql', 'mysql']: # Prepend the required python module string - db_engine = f'django.db.backends.{db_engine}' - db_config['ENGINE'] = db_engine + DB_ENGINE = f'django.db.backends.{DB_ENGINE}' + db_config['ENGINE'] = DB_ENGINE db_name = db_config['NAME'] db_host = db_config.get('HOST', "''") -if 'sqlite' in db_engine: +if 'sqlite' in DB_ENGINE: db_name = str(Path(db_name).resolve()) db_config['NAME'] = db_name -logger.info('DB_ENGINE: %s', db_engine) +logger.info('DB_ENGINE: %s', DB_ENGINE) logger.info('DB_NAME: %s', db_name) logger.info('DB_HOST: %s', db_host) @@ -675,7 +680,7 @@ if db_options is None: db_options = {} # Specific options for postgres backend -if 'postgres' in db_engine: # pragma: no cover +if 'postgres' in DB_ENGINE: # pragma: no cover from django.db.backends.postgresql.psycopg_any import IsolationLevel # Connection timeout @@ -748,7 +753,7 @@ if 'postgres' in db_engine: # pragma: no cover ) # Specific options for MySql / MariaDB backend -elif 'mysql' in db_engine: # pragma: no cover +elif 'mysql' in DB_ENGINE: # pragma: no cover # TODO TCP time outs and keepalives # MariaDB's default isolation level is Repeatable Read which is @@ -766,7 +771,7 @@ elif 'mysql' in db_engine: # pragma: no cover ) # Specific options for sqlite backend -elif 'sqlite' in db_engine: +elif 'sqlite' in DB_ENGINE: # TODO: Verify timeouts are not an issue because no network is involved for SQLite # SQLite's default isolation level is Serializable due to SQLite's @@ -782,7 +787,7 @@ db_config['OPTIONS'] = db_options db_config['TEST'] = {'CHARSET': 'utf8'} # Set collation option for mysql test database -if 'mysql' in db_engine: +if 'mysql' in DB_ENGINE: db_config['TEST']['COLLATION'] = 'utf8_general_ci' # pragma: no cover DATABASES = {'default': db_config} @@ -801,6 +806,7 @@ inventree_tags = { 'docker': DOCKER, 'debug': DEBUG, 'remote': REMOTE_LOGIN, + 'commit': inventreeCommitHash(), } # sentry.io integration for error reporting @@ -821,6 +827,7 @@ if SENTRY_ENABLED and SENTRY_DSN and not TESTING: # pragma: no cover TRACING_ENABLED = get_boolean_setting( 'INVENTREE_TRACING_ENABLED', 'tracing.enabled', False ) +TRACING_DETAILS: Optional[dict] = None if TRACING_ENABLED: # pragma: no cover from InvenTree.tracing import setup_instruments, setup_tracing @@ -834,34 +841,41 @@ if TRACING_ENABLED: # pragma: no cover if _t_endpoint: logger.info('OpenTelemetry tracing enabled') - _t_resources = get_setting( - 'INVENTREE_TRACING_RESOURCES', - 'tracing.resources', - default_value=None, - typecast=dict, + TRACING_DETAILS = ( + TRACING_DETAILS + if TRACING_DETAILS + else { + 'endpoint': _t_endpoint, + 'headers': _t_headers, + 'resources_input': { + **{'inventree.env.' + k: v for k, v in inventree_tags.items()}, + **get_setting( + 'INVENTREE_TRACING_RESOURCES', + 'tracing.resources', + default_value=None, + typecast=dict, + ), + }, + 'console': get_boolean_setting( + 'INVENTREE_TRACING_CONSOLE', 'tracing.console', False + ), + 'auth': get_setting( + 'INVENTREE_TRACING_AUTH', + 'tracing.auth', + default_value=None, + typecast=dict, + ), + 'is_http': get_setting( + 'INVENTREE_TRACING_IS_HTTP', 'tracing.is_http', True + ), + 'append_http': get_boolean_setting( + 'INVENTREE_TRACING_APPEND_HTTP', 'tracing.append_http', True + ), + } ) - cstm_tags = {'inventree.env.' + k: v for k, v in inventree_tags.items()} - tracing_resources = {**cstm_tags, **_t_resources} - setup_tracing( - _t_endpoint, - _t_headers, - resources_input=tracing_resources, - console=get_boolean_setting( - 'INVENTREE_TRACING_CONSOLE', 'tracing.console', False - ), - auth=get_setting( - 'INVENTREE_TRACING_AUTH', - 'tracing.auth', - default_value=None, - typecast=dict, - ), - is_http=get_setting('INVENTREE_TRACING_IS_HTTP', 'tracing.is_http', True), - append_http=get_boolean_setting( - 'INVENTREE_TRACING_APPEND_HTTP', 'tracing.append_http', True - ), - ) # Run tracing/logging instrumentation + setup_tracing(**TRACING_DETAILS) setup_instruments() else: logger.warning('OpenTelemetry tracing not enabled because endpoint is not set') diff --git a/src/backend/InvenTree/InvenTree/tasks.py b/src/backend/InvenTree/InvenTree/tasks.py index bcde964fff..5da465b4a1 100644 --- a/src/backend/InvenTree/InvenTree/tasks.py +++ b/src/backend/InvenTree/InvenTree/tasks.py @@ -26,6 +26,7 @@ from maintenance_mode.core import ( maintenance_mode_on, set_maintenance_mode, ) +from opentelemetry import trace from common.settings import get_global_setting, set_global_setting from InvenTree.config import get_setting @@ -34,6 +35,7 @@ from plugin import registry from .version import isInvenTreeUpToDate logger = structlog.get_logger('inventree') +tracer = trace.get_tracer(__name__) def schedule_task(taskname, **kwargs): @@ -205,7 +207,8 @@ def offload_task( # Running as asynchronous task try: task = AsyncTask(taskname, *args, group=group, **kwargs) - task.run() + with tracer.start_as_current_span(f'async worker: {taskname}'): + task.run() except ImportError: raise_warning(f"WARNING: '{taskname}' not offloaded - Function not found") return False @@ -257,7 +260,8 @@ def offload_task( # Workers are not running: run it as synchronous task try: - _func(*args, **kwargs) + with tracer.start_as_current_span(f'sync worker: {taskname}'): + _func(*args, **kwargs) except Exception as exc: log_error('InvenTree.offload_task') raise_warning(f"WARNING: '{taskname}' failed due to {exc!s}") @@ -345,6 +349,7 @@ def scheduled_task( return _task_wrapper +@tracer.start_as_current_span('heartbeat') @scheduled_task(ScheduledTask.MINUTES, 5) def heartbeat(): """Simple task which runs at 5 minute intervals, so we can determine that the background worker is actually running. @@ -373,6 +378,7 @@ def heartbeat(): task.delete() +@tracer.start_as_current_span('delete_successful_tasks') @scheduled_task(ScheduledTask.DAILY) def delete_successful_tasks(): """Delete successful task logs which are older than a specified period.""" @@ -395,6 +401,7 @@ def delete_successful_tasks(): ) +@tracer.start_as_current_span('delete_failed_tasks') @scheduled_task(ScheduledTask.DAILY) def delete_failed_tasks(): """Delete failed task logs which are older than a specified period.""" @@ -415,6 +422,7 @@ def delete_failed_tasks(): logger.info("Could not perform 'delete_failed_tasks' - App registry not ready") +@tracer.start_as_current_span('delete_old_error_logs') @scheduled_task(ScheduledTask.DAILY) def delete_old_error_logs(): """Delete old error logs from the server.""" @@ -437,6 +445,7 @@ def delete_old_error_logs(): ) +@tracer.start_as_current_span('delete_old_notifications') @scheduled_task(ScheduledTask.DAILY) def delete_old_notifications(): """Delete old notification logs.""" @@ -464,6 +473,7 @@ def delete_old_notifications(): ) +@tracer.start_as_current_span('check_for_updates') @scheduled_task(ScheduledTask.DAILY) def check_for_updates(): """Check if there is an update for InvenTree.""" @@ -547,6 +557,7 @@ def check_for_updates(): ) +@tracer.start_as_current_span('update_exchange_rates') @scheduled_task(ScheduledTask.DAILY) def update_exchange_rates(force: bool = False): """Update currency exchange rates. @@ -597,6 +608,7 @@ def update_exchange_rates(force: bool = False): logger.exception('Error updating exchange rates: %s', str(type(e))) +@tracer.start_as_current_span('run_backup') @scheduled_task(ScheduledTask.DAILY) def run_backup(): """Run the backup command.""" @@ -628,6 +640,7 @@ def get_migration_plan(): return plan +@tracer.start_as_current_span('check_for_migrations') @scheduled_task(ScheduledTask.DAILY) def check_for_migrations(force: bool = False, reload_registry: bool = True) -> bool: """Checks if migrations are needed. @@ -720,6 +733,7 @@ def email_user(user_id: int, subject: str, message: str) -> None: send_email(subject, message, [email]) +@tracer.start_as_current_span('run_oauth_maintenance') @scheduled_task(ScheduledTask.DAILY) def run_oauth_maintenance(): """Run the OAuth maintenance task(s).""" diff --git a/src/backend/InvenTree/InvenTree/tracing.py b/src/backend/InvenTree/InvenTree/tracing.py index a04a71c9e2..e9c66060e6 100644 --- a/src/backend/InvenTree/InvenTree/tracing.py +++ b/src/backend/InvenTree/InvenTree/tracing.py @@ -4,10 +4,14 @@ import base64 import logging from typing import Optional +from django.conf import settings + from opentelemetry import metrics, trace from opentelemetry.instrumentation.django import DjangoInstrumentor from opentelemetry.instrumentation.redis import RedisInstrumentor from opentelemetry.instrumentation.requests import RequestsInstrumentor +from opentelemetry.instrumentation.sqlite3 import SQLite3Instrumentor +from opentelemetry.instrumentation.system_metrics import SystemMetricsInstrumentor from opentelemetry.sdk import _logs as logs from opentelemetry.sdk import resources from opentelemetry.sdk._logs import export as logs_export @@ -22,6 +26,9 @@ from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExport import InvenTree.ready from InvenTree.version import inventreeVersion +TRACE_PROC = None +TRACE_PROV = None + def setup_tracing( endpoint: str, @@ -31,7 +38,7 @@ def setup_tracing( auth: Optional[dict] = None, is_http: bool = False, append_http: bool = True, -): +): # pragma: no cover """Set up tracing for the application in the current context. Args: @@ -68,9 +75,14 @@ def setup_tracing( headers = {k: v for k, v in headers.items() if v is not None} # Initialize the OTLP Resource + service_name = 'Unkown' + if InvenTree.ready.isInServerThread(): + service_name = 'BACKEND' + elif InvenTree.ready.isInWorkerThread(): + service_name = 'WORKER' resource = resources.Resource( attributes={ - resources.SERVICE_NAME: 'BACKEND', + resources.SERVICE_NAME: service_name, resources.SERVICE_NAMESPACE: 'INVENTREE', resources.SERVICE_VERSION: inventreeVersion(), **resources_input, @@ -141,9 +153,34 @@ def setup_tracing( logger = logging.getLogger('inventree') logger.addHandler(handler) + global TRACE_PROC, TRACE_PROV + TRACE_PROC = trace_processor + TRACE_PROV = trace_provider -def setup_instruments(): + +def setup_instruments(): # pragma: no cover """Run auto-insturmentation for OpenTelemetry tracing.""" DjangoInstrumentor().instrument() RedisInstrumentor().instrument() RequestsInstrumentor().instrument() + SystemMetricsInstrumentor().instrument() + + # DBs + if settings.DB_ENGINE == 'sqlite': + SQLite3Instrumentor().instrument() + elif settings.DB_ENGINE == 'postgresql': + try: + from opentelemetry.instrumentation.psycopg import PsycopgInstrumentor + + PsycopgInstrumentor().instrument( + enable_commenter=False, commenter_options={} + ) + except ModuleNotFoundError: + pass + elif settings.DB_ENGINE == 'mysql': + try: + from opentelemetry.instrumentation.pymysql import PyMySQLInstrumentor + + PyMySQLInstrumentor().instrument() + except ModuleNotFoundError: + pass diff --git a/src/backend/InvenTree/InvenTree/version.py b/src/backend/InvenTree/InvenTree/version.py index 5ee6f1af66..c77203b39f 100644 --- a/src/backend/InvenTree/InvenTree/version.py +++ b/src/backend/InvenTree/InvenTree/version.py @@ -306,8 +306,7 @@ def inventreePlatform(): def inventreeDatabase(): """Return the InvenTree database backend e.g. 'postgresql'.""" - db = settings.DATABASES['default'] - return db.get('ENGINE', None).replace('django.db.backends.', '') + return settings.DB_ENGINE def inventree_identifier(override_announce: bool = False): diff --git a/src/backend/InvenTree/InvenTree/wsgi.py b/src/backend/InvenTree/InvenTree/wsgi.py index 4630c31182..e4b937cbe7 100644 --- a/src/backend/InvenTree/InvenTree/wsgi.py +++ b/src/backend/InvenTree/InvenTree/wsgi.py @@ -10,8 +10,11 @@ import os # pragma: no cover from django.core.wsgi import get_wsgi_application # pragma: no cover +from opentelemetry.instrumentation.wsgi import OpenTelemetryMiddleware + os.environ.setdefault( 'DJANGO_SETTINGS_MODULE', 'InvenTree.settings' ) # pragma: no cover application = get_wsgi_application() # pragma: no cover +application = OpenTelemetryMiddleware(application) diff --git a/src/backend/InvenTree/build/tasks.py b/src/backend/InvenTree/build/tasks.py index d06c9804ee..02ab1ae07a 100644 --- a/src/backend/InvenTree/build/tasks.py +++ b/src/backend/InvenTree/build/tasks.py @@ -9,6 +9,7 @@ from django.utils.translation import gettext_lazy as _ import structlog from allauth.account.models import EmailAddress +from opentelemetry import trace import build.models as build_models import common.notifications @@ -22,9 +23,11 @@ from build.status_codes import BuildStatusGroups from InvenTree.ready import isImportingData from plugin.events import trigger_event +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('auto_allocate_build') 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() @@ -39,6 +42,7 @@ def auto_allocate_build(build_id: int, **kwargs): build_order.auto_allocate_stock(**kwargs) +@tracer.start_as_current_span('complete_build_allocations') 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() @@ -65,6 +69,7 @@ def complete_build_allocations(build_id: int, user_id: int): build_order.complete_allocations(user) +@tracer.start_as_current_span('update_build_order_lines') def update_build_order_lines(bom_item_pk: int): """Update all BuildOrderLineItem objects which reference a particular BomItem. @@ -111,6 +116,7 @@ def update_build_order_lines(bom_item_pk: int): ) +@tracer.start_as_current_span('check_build_stock') def check_build_stock(build: build_models.Build): """Check the required stock for a newly created build order. @@ -196,6 +202,7 @@ def check_build_stock(build: build_models.Build): ) +@tracer.start_as_current_span('notify_overdue_build_order') def notify_overdue_build_order(bo: build_models.Build): """Notify appropriate users that a Build has just become 'overdue'.""" targets = [] @@ -229,6 +236,7 @@ def notify_overdue_build_order(bo: build_models.Build): trigger_event(event_name, build_order=bo.pk) +@tracer.start_as_current_span('check_overdue_build_orders') @InvenTree.tasks.scheduled_task(InvenTree.tasks.ScheduledTask.DAILY) def check_overdue_build_orders(): """Check if any outstanding BuildOrders have just become overdue. diff --git a/src/backend/InvenTree/common/models.py b/src/backend/InvenTree/common/models.py index 4eaa8094cc..2a4365759b 100644 --- a/src/backend/InvenTree/common/models.py +++ b/src/backend/InvenTree/common/models.py @@ -28,14 +28,16 @@ from django.core.validators import MinValueValidator from django.db import models, transaction from django.db.models.signals import post_delete, post_save from django.db.utils import IntegrityError, OperationalError, ProgrammingError -from django.dispatch.dispatcher import receiver +from django.dispatch import receiver from django.urls import reverse from django.utils.timezone import now from django.utils.translation import gettext_lazy as _ import structlog +from django_q.signals import post_spawn from djmoney.contrib.exchange.exceptions import MissingRate from djmoney.contrib.exchange.models import convert_money +from opentelemetry import trace from rest_framework.exceptions import PermissionDenied from taggit.managers import TaggableManager @@ -52,6 +54,7 @@ from generic.states import ColorEnum from generic.states.custom import state_color_mappings from InvenTree.cache import get_session_cache, set_session_cache from InvenTree.sanitizer import sanitize_svg +from InvenTree.tracing import TRACE_PROC, TRACE_PROV logger = structlog.get_logger('inventree') @@ -2414,3 +2417,16 @@ class DataOutput(models.Model): output = models.FileField(upload_to='data_output', blank=True, null=True) errors = models.JSONField(blank=True, null=True) + + +# region tracing for django q +if TRACE_PROC: # pragma: no cover + + @receiver(post_spawn) + def spwan_callback(sender, proc_name, **kwargs): + """Callback to patch in tracing support.""" + TRACE_PROV.add_span_processor(TRACE_PROC) + trace.set_tracer_provider(TRACE_PROV) + trace.get_tracer(__name__) + +# endregion diff --git a/src/backend/InvenTree/common/tasks.py b/src/backend/InvenTree/common/tasks.py index 69487d5c6d..a718c2e201 100644 --- a/src/backend/InvenTree/common/tasks.py +++ b/src/backend/InvenTree/common/tasks.py @@ -11,6 +11,7 @@ from django.utils import timezone import feedparser import requests import structlog +from opentelemetry import trace import common.models import InvenTree.helpers @@ -18,9 +19,11 @@ from InvenTree.helpers_model import getModelsWithMixin from InvenTree.models import InvenTreeNotesMixin from InvenTree.tasks import ScheduledTask, scheduled_task +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('cleanup_old_data_outputs') @scheduled_task(ScheduledTask.DAILY) def cleanup_old_data_outputs(): """Remove old data outputs from the database.""" @@ -32,6 +35,7 @@ def cleanup_old_data_outputs(): output.delete() +@tracer.start_as_current_span('delete_old_notifications') @scheduled_task(ScheduledTask.DAILY) def delete_old_notifications(): """Remove old notifications from the database. @@ -52,6 +56,7 @@ def delete_old_notifications(): NotificationEntry.objects.filter(updated__lte=before).delete() +@tracer.start_as_current_span('update_news_feed') @scheduled_task(ScheduledTask.DAILY) def update_news_feed(): """Update the newsfeed.""" @@ -105,6 +110,7 @@ def update_news_feed(): logger.info('update_news_feed: Sync done') +@tracer.start_as_current_span('delete_old_notes_images') @scheduled_task(ScheduledTask.DAILY) def delete_old_notes_images(): """Remove old notes images from the database. diff --git a/src/backend/InvenTree/gunicorn.conf.py b/src/backend/InvenTree/gunicorn.conf.py index 9fdcb4dfee..aa58d6e525 100644 --- a/src/backend/InvenTree/gunicorn.conf.py +++ b/src/backend/InvenTree/gunicorn.conf.py @@ -11,3 +11,18 @@ max_requests_jitter = 50 # preload app so that the ready functions are only executed once preload_app = True + + +def post_fork(server, worker): + """Post-fork hook to set up logging for each worker.""" + from django.conf import settings + + if not settings.TRACING_ENABLED: + return + + # Instrument gunicorm + from InvenTree.tracing import setup_instruments, setup_tracing + + # Run tracing/logging instrumentation + setup_tracing(**settings.TRACING_DETAILS) + setup_instruments() diff --git a/src/backend/InvenTree/order/tasks.py b/src/backend/InvenTree/order/tasks.py index 21babfe2c1..7d2b3845eb 100644 --- a/src/backend/InvenTree/order/tasks.py +++ b/src/backend/InvenTree/order/tasks.py @@ -8,6 +8,7 @@ from django.db.models import F from django.utils.translation import gettext_lazy as _ import structlog +from opentelemetry import trace import common.notifications import InvenTree.helpers_model @@ -22,9 +23,11 @@ from order.status_codes import ( from plugin.events import trigger_event from users.models import Owner +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('notify_overdue_purchase_order') def notify_overdue_purchase_order(po: order.models.PurchaseOrder) -> None: """Notify users that a PurchaseOrder has just become 'overdue'. @@ -62,6 +65,7 @@ def notify_overdue_purchase_order(po: order.models.PurchaseOrder) -> None: trigger_event(event_name, purchase_order=po.pk) +@tracer.start_as_current_span('scheduled_task') @scheduled_task(ScheduledTask.DAILY) def check_overdue_purchase_orders(): """Check if any outstanding PurchaseOrders have just become overdue. @@ -97,6 +101,7 @@ def check_overdue_purchase_orders(): notified_orders.add(line.order.pk) +@tracer.start_as_current_span('notify_overdue_sales_order') def notify_overdue_sales_order(so: order.models.SalesOrder) -> None: """Notify appropriate users that a SalesOrder has just become 'overdue'.""" targets: list[User, Group, Owner] = [] @@ -130,6 +135,7 @@ def notify_overdue_sales_order(so: order.models.SalesOrder) -> None: trigger_event(event_name, sales_order=so.pk) +@tracer.start_as_current_span('scheduled_task') @scheduled_task(ScheduledTask.DAILY) def check_overdue_sales_orders(): """Check if any outstanding SalesOrders have just become overdue. @@ -162,6 +168,7 @@ def check_overdue_sales_orders(): notified_orders.add(line.order.pk) +@tracer.start_as_current_span('notify_overdue_return_order') def notify_overdue_return_order(ro: order.models.ReturnOrder) -> None: """Notify appropriate users that a ReturnOrder has just become 'overdue'.""" targets: list[User, Group, Owner] = [] @@ -195,6 +202,7 @@ def notify_overdue_return_order(ro: order.models.ReturnOrder) -> None: trigger_event(event_name, return_order=ro.pk) +@tracer.start_as_current_span('check_overdue_return_orders') @scheduled_task(ScheduledTask.DAILY) def check_overdue_return_orders(): """Check if any outstanding return orders have just become overdue. @@ -227,6 +235,7 @@ def check_overdue_return_orders(): notified_orders.add(line.order.pk) +@tracer.start_as_current_span('complete_sales_order_shipment') def complete_sales_order_shipment(shipment_id: int, user_id: int) -> None: """Complete allocations for a pending shipment against a SalesOrder. diff --git a/src/backend/InvenTree/part/tasks.py b/src/backend/InvenTree/part/tasks.py index 8d70537fb3..87f3f888c8 100644 --- a/src/backend/InvenTree/part/tasks.py +++ b/src/backend/InvenTree/part/tasks.py @@ -8,6 +8,7 @@ from django.core.exceptions import ValidationError from django.utils.translation import gettext_lazy as _ import structlog +from opentelemetry import trace import common.currency import common.notifications @@ -25,9 +26,11 @@ from InvenTree.tasks import ( scheduled_task, ) +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('notify_low_stock') def notify_low_stock(part: part_models.Part): """Notify interested users that a part is 'low stock'. @@ -52,6 +55,7 @@ def notify_low_stock(part: part_models.Part): ) +@tracer.start_as_current_span('notify_low_stock_if_required') def notify_low_stock_if_required(part_id: int): """Check if the stock quantity has fallen below the minimum threshold of part. @@ -73,6 +77,7 @@ def notify_low_stock_if_required(part_id: int): InvenTree.tasks.offload_task(notify_low_stock, p, group='notification') +@tracer.start_as_current_span('update_part_pricing') def update_part_pricing(pricing: part_models.PartPricing, counter: int = 0): """Update cached pricing data for the specified PartPricing instance. @@ -89,6 +94,7 @@ def update_part_pricing(pricing: part_models.PartPricing, counter: int = 0): ) +@tracer.start_as_current_span('check_missing_pricing') @scheduled_task(ScheduledTask.DAILY) def check_missing_pricing(limit=250): """Check for parts with missing or outdated pricing information. @@ -144,6 +150,7 @@ def check_missing_pricing(limit=250): pricing.schedule_for_update() +@tracer.start_as_current_span('scheduled_stocktake_reports') @scheduled_task(ScheduledTask.DAILY) def scheduled_stocktake_reports(): """Scheduled tasks for creating automated stocktake reports. @@ -189,6 +196,7 @@ def scheduled_stocktake_reports(): record_task_success('STOCKTAKE_RECENT_REPORT') +@tracer.start_as_current_span('rebuild_parameters') def rebuild_parameters(template_id): """Rebuild all parameters for a given template. @@ -218,6 +226,7 @@ def rebuild_parameters(template_id): logger.info("Rebuilt %s parameters for template '%s'", n, template.name) +@tracer.start_as_current_span('rebuild_supplier_parts') def rebuild_supplier_parts(part_id): """Rebuild all SupplierPart objects for a given part. diff --git a/src/backend/InvenTree/plugin/base/event/events.py b/src/backend/InvenTree/plugin/base/event/events.py index ec36a1928d..4508f72e73 100644 --- a/src/backend/InvenTree/plugin/base/event/events.py +++ b/src/backend/InvenTree/plugin/base/event/events.py @@ -6,6 +6,7 @@ from django.db.models.signals import post_delete, post_save from django.dispatch.dispatcher import receiver import structlog +from opentelemetry import trace import InvenTree.exceptions from common.settings import get_global_setting @@ -13,9 +14,11 @@ from InvenTree.ready import canAppAccessDatabase, isImportingData from InvenTree.tasks import offload_task from plugin.registry import registry +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('trigger_event') def trigger_event(event: str, *args, **kwargs) -> None: """Trigger an event with optional arguments. @@ -54,6 +57,7 @@ def trigger_event(event: str, *args, **kwargs) -> None: offload_task(register_event, event, *args, group='plugin', **kwargs) +@tracer.start_as_current_span('register_event') def register_event(event, *args, **kwargs): """Register the event with any interested plugins. @@ -93,6 +97,7 @@ def register_event(event, *args, **kwargs): ) +@tracer.start_as_current_span('process_event') def process_event(plugin_slug, event, *args, **kwargs): """Respond to a triggered event. diff --git a/src/backend/InvenTree/report/tasks.py b/src/backend/InvenTree/report/tasks.py index 615f648aa6..f39762e952 100644 --- a/src/backend/InvenTree/report/tasks.py +++ b/src/backend/InvenTree/report/tasks.py @@ -1,12 +1,15 @@ """Background tasks for the report app.""" import structlog +from opentelemetry import trace from InvenTree.exceptions import log_error +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('print_reports') def print_reports(template_id: int, item_ids: list[int], output_id: int, **kwargs): """Print multiple reports against the provided template. @@ -35,6 +38,7 @@ def print_reports(template_id: int, item_ids: list[int], output_id: int, **kwarg template.print(items, output=output) +@tracer.start_as_current_span('print_labels') def print_labels( template_id: int, item_ids: list[int], output_id: int, plugin_slug: str, **kwargs ): diff --git a/src/backend/InvenTree/stock/tasks.py b/src/backend/InvenTree/stock/tasks.py index fd0e4c5df2..735f5feaff 100644 --- a/src/backend/InvenTree/stock/tasks.py +++ b/src/backend/InvenTree/stock/tasks.py @@ -1,10 +1,13 @@ """Background tasks for the stock app.""" import structlog +from opentelemetry import trace +tracer = trace.get_tracer(__name__) logger = structlog.get_logger('inventree') +@tracer.start_as_current_span('rebuild_stock_item_tree') def rebuild_stock_item_tree(tree_id=None): """Rebuild the stock tree structure. diff --git a/src/backend/requirements.in b/src/backend/requirements.in index 72e8cdb628..7b4b38e6a8 100644 --- a/src/backend/requirements.in +++ b/src/backend/requirements.in @@ -61,6 +61,11 @@ opentelemetry-exporter-otlp opentelemetry-instrumentation-django opentelemetry-instrumentation-requests opentelemetry-instrumentation-redis +opentelemetry-instrumentation-sqlite3 +opentelemetry-instrumentation-system_metrics +opentelemetry-instrumentation-wsgi +opentelemetry-instrumentation-psycopg +opentelemetry-instrumentation-pymysql # Pins xmlsec==1.3.14 # 2025-06-02 pinned to avoid issues with builds - see https://github.com/inventree/InvenTree/pull/9713 diff --git a/src/backend/requirements.txt b/src/backend/requirements.txt index f4af753d1f..89aefe8d60 100644 --- a/src/backend/requirements.txt +++ b/src/backend/requirements.txt @@ -988,9 +988,14 @@ opentelemetry-api==1.34.0 \ # opentelemetry-exporter-otlp-proto-grpc # opentelemetry-exporter-otlp-proto-http # opentelemetry-instrumentation + # opentelemetry-instrumentation-dbapi # opentelemetry-instrumentation-django + # opentelemetry-instrumentation-psycopg + # opentelemetry-instrumentation-pymysql # opentelemetry-instrumentation-redis # opentelemetry-instrumentation-requests + # opentelemetry-instrumentation-sqlite3 + # opentelemetry-instrumentation-system-metrics # opentelemetry-instrumentation-wsgi # opentelemetry-sdk # opentelemetry-semantic-conventions @@ -1016,14 +1021,34 @@ opentelemetry-instrumentation==0.55b0 \ --hash=sha256:9669f19a561f7eacd9974823e48949bc12506d34cb2dd277e9d7b70987c7cc66 \ --hash=sha256:c0c64c16d2abae80a0f43906d3c68de10a700a4fc11d22b1c31f32d628e95e31 # via + # opentelemetry-instrumentation-dbapi # opentelemetry-instrumentation-django + # opentelemetry-instrumentation-psycopg + # opentelemetry-instrumentation-pymysql # opentelemetry-instrumentation-redis # opentelemetry-instrumentation-requests + # opentelemetry-instrumentation-sqlite3 + # opentelemetry-instrumentation-system-metrics # opentelemetry-instrumentation-wsgi +opentelemetry-instrumentation-dbapi==0.55b0 \ + --hash=sha256:dca1344a5d7303d0c225631262458835f80a2ed00d6e0a4053d9c47bbca41cb5 \ + --hash=sha256:ebfe8b5506cd77ec37a94e59491537c5d4b38aeb4ad942c9a68aac73bc3d3d31 + # via + # opentelemetry-instrumentation-psycopg + # opentelemetry-instrumentation-pymysql + # opentelemetry-instrumentation-sqlite3 opentelemetry-instrumentation-django==0.55b0 \ --hash=sha256:5421e0e6a8d2847e5296714affce239150e3ac27defdbd0d22f9842c4f3b1ca8 \ --hash=sha256:9c50ab2f9e359d0f96a1516cc25b3e515045c858a3994cf04e21ef602905158b # via -r src/backend/requirements.in +opentelemetry-instrumentation-psycopg==0.55b0 \ + --hash=sha256:1edac6fa90a49e81b1f847d3ebf2746a38170885215b75b02cf6faf71e2d402d \ + --hash=sha256:c44d689eb50666341c8e9077cf1079f81003f4e679a666424b338bbe4ebbcbf3 + # via -r src/backend/requirements.in +opentelemetry-instrumentation-pymysql==0.55b0 \ + --hash=sha256:7438aeeca9e28590a681f71648b94b5ddf094f4fed77bf28ec81fee5aa329a84 \ + --hash=sha256:91bb628b79809cb00d4276150e933e25bb5defe02e80ef7f97e49d4bf76e4861 + # via -r src/backend/requirements.in opentelemetry-instrumentation-redis==0.55b0 \ --hash=sha256:4366a06e16ae42a36c1fc2a30c880a12cdce8c0f9a2796abbf46f43c84788b95 \ --hash=sha256:88ca82ceb950ef1ec71b7b9eb7584b5030cb78200b6c628c34c783d6b888f628 @@ -1032,10 +1057,20 @@ opentelemetry-instrumentation-requests==0.55b0 \ --hash=sha256:018c6e5550f10a116f101b619a3e330d309ae3438e6c7ad1541c77e56d6f3b49 \ --hash=sha256:9299303c5b23ea0c825f6bda346f585171471e19e6c1313c19a3facddf1e2a42 # via -r src/backend/requirements.in +opentelemetry-instrumentation-sqlite3==0.55b0 \ + --hash=sha256:9c1c9bd3409f2f6494f314c72c89785f45f94117562009d9fcae05f9862a4d9a \ + --hash=sha256:bfb5a8a6b5d545a5187a1d427417e92e7be47d9d28b315998d01dbc73b89402d + # via -r src/backend/requirements.in +opentelemetry-instrumentation-system-metrics==0.55b0 \ + --hash=sha256:23050f289e7c2062672781646deb9c39283fc35a1d1ba3f60856b8ecf45efd32 \ + --hash=sha256:392b558b6d193ce3eb51a29be984badc5dd2c5a44c8716850d7624045d68cbc4 + # via -r src/backend/requirements.in opentelemetry-instrumentation-wsgi==0.55b0 \ --hash=sha256:63d1851bf98dd2a119f41b8f9c5fd469e63e6e6e042be04196609f05df01b32e \ --hash=sha256:b1903bcc609cc1e7ee7d55a4969eb9107cb2773a4b981e3ad73c6aeb03d8da1e - # via opentelemetry-instrumentation-django + # via + # -r src/backend/requirements.in + # opentelemetry-instrumentation-django opentelemetry-proto==1.34.0 \ --hash=sha256:73e40509b692630a47192888424f7e0b8fb19d9ecf2f04e6f708170cd3346dfe \ --hash=sha256:ffb1f1b27552fda5a1cd581e34243cc0b6f134fb14c1c2a33cc3b4b208c9bf97 @@ -1055,6 +1090,7 @@ opentelemetry-semantic-conventions==0.55b0 \ --hash=sha256:933d2e20c2dbc0f9b2f4f52138282875b4b14c66c491f5273bcdef1781368e9c # via # opentelemetry-instrumentation + # opentelemetry-instrumentation-dbapi # opentelemetry-instrumentation-django # opentelemetry-instrumentation-redis # opentelemetry-instrumentation-requests @@ -1201,6 +1237,18 @@ protobuf==5.29.5 \ # via # googleapis-common-protos # opentelemetry-proto +psutil==7.0.0 \ + --hash=sha256:101d71dc322e3cffd7cea0650b09b3d08b8e7c4109dd6809fe452dfd00e58b25 \ + --hash=sha256:1e744154a6580bc968a0195fd25e80432d3afec619daf145b9e5ba16cc1d688e \ + --hash=sha256:1fcee592b4c6f146991ca55919ea3d1f8926497a713ed7faaf8225e174581e91 \ + --hash=sha256:39db632f6bb862eeccf56660871433e111b6ea58f2caea825571951d4b6aa3da \ + --hash=sha256:4b1388a4f6875d7e2aff5c4ca1cc16c545ed41dd8bb596cefea80111db353a34 \ + --hash=sha256:4cf3d4eb1aa9b348dec30105c55cd9b7d4629285735a102beb4441e38db90553 \ + --hash=sha256:7be9c3eba38beccb6495ea33afd982a44074b78f28c434a1f51cc07fd315c456 \ + --hash=sha256:84df4eb63e16849689f76b1ffcb36db7b8de703d1bc1fe41773db487621b6c17 \ + --hash=sha256:a5f098451abc2828f7dc6b58d44b532b22f2088f4999a937557b603ce72b1993 \ + --hash=sha256:ba3fcef7523064a6c9da440fc4d6bd07da93ac726b5733c29027d7dc95b39d99 + # via opentelemetry-instrumentation-system-metrics py-moneyed==3.0 \ --hash=sha256:4906f0f02cf2b91edba2e156f2d4e9a78f224059ab8c8fa2ff26230c75d894e8 \ --hash=sha256:9583a14f99c05b46196193d8185206e9b73c8439fc8a5eee9cfc7e733676d9bb @@ -1784,6 +1832,7 @@ wrapt==1.17.2 \ --hash=sha256:ff04ef6eec3eee8a5efef2401495967a916feaa353643defcc03fc74fe213b58 # via # opentelemetry-instrumentation + # opentelemetry-instrumentation-dbapi # opentelemetry-instrumentation-redis xlrd==2.0.1 \ --hash=sha256:6a33ee89877bd9abc1158129f6e94be74e2679636b8a205b43b85206c3f0bbdd \