diff --git a/edx_filters_pipelines/management/__init__.py b/edx_filters_pipelines/management/__init__.py new file mode 100644 index 0000000..4a0678a --- /dev/null +++ b/edx_filters_pipelines/management/__init__.py @@ -0,0 +1 @@ +"""Management command filter pipeline integrations.""" diff --git a/edx_filters_pipelines/management/pipelines/__init__.py b/edx_filters_pipelines/management/pipelines/__init__.py new file mode 100644 index 0000000..911ea4c --- /dev/null +++ b/edx_filters_pipelines/management/pipelines/__init__.py @@ -0,0 +1 @@ +"""Pipeline steps for management command integrations.""" diff --git a/edx_filters_pipelines/management/pipelines/monitoring.py b/edx_filters_pipelines/management/pipelines/monitoring.py new file mode 100644 index 0000000..0cc0890 --- /dev/null +++ b/edx_filters_pipelines/management/pipelines/monitoring.py @@ -0,0 +1,153 @@ +"""Pipeline steps for management command observability.""" + +import logging +import os +import time +from contextlib import contextmanager, nullcontext + +from edx_django_utils.monitoring import ( + function_trace, + set_custom_attribute, + set_monitoring_transaction_name, +) +from openedx_filters import PipelineStep + +from edx_filters_pipelines.waffle import ENABLE_MANAGEMENT_COMMAND_MONITORING + +log = logging.getLogger(__name__) + +DEFAULT_OPERATION_NAME = 'django.management.command' + + +@contextmanager +def monitor_management_command( + command_name, + service_variant, + operation_name=DEFAULT_OPERATION_NAME, +): + """ + Wrap a management command execution with monitoring metadata and logging. + + The operation name identifies the type of operation, while the resource + name identifies the specific management command being executed. + """ + resource_name = command_name + + set_monitoring_transaction_name(resource_name) + set_custom_attribute('management_command.service_variant', service_variant) + + github_run_url = os.getenv('EDX_MC_GITHUB_RUN_URL', '').strip() + if github_run_url: + set_custom_attribute('management_command.github_run_url', github_run_url) + + log.info( + 'Starting management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s', + command_name, + service_variant, + operation_name, + resource_name, + ) + + start_time = time.monotonic() + status = 'failure' + + try: + with function_trace(resource_name, operation_name=operation_name): + yield + + status = 'success' + + except SystemExit as exc: + if exc.code in (0, None): + status = 'success' + else: + set_custom_attribute('management_command.exception_class', exc.__class__.__name__) + set_custom_attribute('management_command.exit_code', exc.code) + set_custom_attribute('management_command.exception_message', str(exc)) + log.exception( + 'Management command failed: %s service_variant=%s ' + 'operation_name=%s resource_name=%s exit_code=%s error=%s', + command_name, + service_variant, + operation_name, + resource_name, + exc.code, + exc, + ) + raise + + except Exception as exc: + set_custom_attribute('management_command.exception_class', exc.__class__.__name__) + set_custom_attribute('management_command.exception_message', str(exc)) + log.exception( + 'Management command failed: %s service_variant=%s ' + 'operation_name=%s resource_name=%s exception_class=%s error=%s', + command_name, + service_variant, + operation_name, + resource_name, + exc.__class__.__name__, + exc, + ) + raise + + finally: + duration = time.monotonic() - start_time + set_custom_attribute('management_command.status', status) + set_custom_attribute('management_command.duration_seconds', duration) + log.info( + 'Finished management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s status=%s duration_seconds=%s', + command_name, + service_variant, + operation_name, + resource_name, + status, + duration, + ) + + +class ManagementCommandMonitoringPipelineStep(PipelineStep): + """ + Add monitoring around Django management command execution. + """ + + def run_filter( + self, + command_contextmanager, + command_name, + service_variant, + ): # pylint: disable=arguments-differ + """ + Return a wrapped context manager that applies monitoring when enabled. + """ + operation_name = self.extra_config.get('operation_name', DEFAULT_OPERATION_NAME) + + @contextmanager + def wrapped_contextmanager(): + monitor_contextmanager = nullcontext() + + try: + if ENABLE_MANAGEMENT_COMMAND_MONITORING.is_enabled(): + monitor_contextmanager = monitor_management_command( + command_name, + service_variant, + operation_name, + ) + except Exception: # pylint: disable=broad-except + log.exception( + 'Failed to initialize management command monitoring ' + 'for %s; continuing without monitoring.', + command_name, + ) + + with monitor_contextmanager: + with command_contextmanager: + yield + + return { + 'command_contextmanager': wrapped_contextmanager(), + 'command_name': command_name, + 'service_variant': service_variant, + } diff --git a/edx_filters_pipelines/waffle.py b/edx_filters_pipelines/waffle.py index ebdf6f2..a1e6376 100644 --- a/edx_filters_pipelines/waffle.py +++ b/edx_filters_pipelines/waffle.py @@ -1,7 +1,7 @@ """ -waffle flags used in the filters_pipelines app. +Feature toggles used in the filters_pipelines app. """ -from edx_toggles.toggles import WaffleFlag +from edx_toggles.toggles import SettingToggle, WaffleFlag WAFFLE_NAMESPACE = 'filters_pipelines' @@ -14,3 +14,16 @@ # .. toggle_target_removal_date: None because this is a long-term feature # .. toggle_warning: When the flag is ON, recaptcha validation is enabled on registration. ENABLE_RECAPTCHA_VALIDATION = WaffleFlag(f'{WAFFLE_NAMESPACE}.enable_registration_recaptcha_validation', __name__) + +# .. toggle_name: FILTERS_PIPELINES_ENABLE_MANAGEMENT_COMMAND_MONITORING +# .. toggle_implementation: SettingToggle +# .. toggle_default: False +# .. toggle_description: Settings toggle to enable Datadog monitoring for Django management commands. +# .. toggle_use_cases: opt_in +# .. toggle_creation_date: 2026-03-26 +# .. toggle_target_removal_date: None because this is a long-term feature +# .. toggle_warning: When the setting is True, management command execution is wrapped with Datadog monitoring. +ENABLE_MANAGEMENT_COMMAND_MONITORING = SettingToggle( + 'FILTERS_PIPELINES_ENABLE_MANAGEMENT_COMMAND_MONITORING', + default=False, +) diff --git a/requirements/test.in b/requirements/test.in index 39d2ac4..14f5041 100644 --- a/requirements/test.in +++ b/requirements/test.in @@ -5,6 +5,7 @@ pytest pytest-cov # pytest extension for code coverage statistics +pytest-mock # pytest plugin providing mocker fixture edx-lint pylint-celery setuptools diff --git a/requirements/test.txt b/requirements/test.txt index 125f1ac..bfe9989 100644 --- a/requirements/test.txt +++ b/requirements/test.txt @@ -196,6 +196,8 @@ pytest-cov==6.2.1 # via # -r requirements/base.txt # -r requirements/test.in +pytest-mock + # via -r requirements/test.in python-slugify==8.0.4 # via # -r requirements/base.txt diff --git a/tests/test_edx-filters-pipelines.py b/tests/test_edx-filters-pipelines.py index 14f0696..da13526 100644 --- a/tests/test_edx-filters-pipelines.py +++ b/tests/test_edx-filters-pipelines.py @@ -2,9 +2,16 @@ Tests for edx-filters-pipelines.py. """ +from contextlib import nullcontext + import pytest from openedx_filters.learning.filters import StudentRegistrationRequested + from edx_filters_pipelines.auth.pipelines.registration import PreventForbiddenUsernameRegistration +from edx_filters_pipelines.management.pipelines.monitoring import ( + ManagementCommandMonitoringPipelineStep, + monitor_management_command, +) def test_username_blocked(): @@ -20,3 +27,263 @@ def test_username_blocked(): step.run_filter(form_data=form_data) assert "Usernames can't include words that could be mistaken for course roles." in str(exc_info.value) + + +def test_management_command_monitoring_step_disabled(mocker): + step = ManagementCommandMonitoringPipelineStep( + 'org.openedx.platform.management.command.contextmanager.requested.v1', + 'edx_filters_pipelines.management.pipelines.monitoring.ManagementCommandMonitoringPipelineStep', + ) + command_execution = mocker.Mock() + toggle = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.ENABLE_MANAGEMENT_COMMAND_MONITORING.is_enabled', + return_value=False, + ) + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.function_trace') + + result = step.run_filter(nullcontext(), 'migrate', 'lms') + + assert result['command_name'] == 'migrate' + assert result['service_variant'] == 'lms' + with result['command_contextmanager']: + command_execution() + toggle.assert_called_once() + command_execution.assert_called_once() + + +def test_management_command_monitoring_step_enabled(mocker): + step = ManagementCommandMonitoringPipelineStep( + 'org.openedx.platform.management.command.contextmanager.requested.v1', + 'edx_filters_pipelines.management.pipelines.monitoring.ManagementCommandMonitoringPipelineStep', + ) + command_execution = mocker.Mock() + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.ENABLE_MANAGEMENT_COMMAND_MONITORING.is_enabled', + return_value=True, + ) + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.time.monotonic', + side_effect=[10.0, 15.0], + ) + function_trace = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + set_transaction_name = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name' + ) + set_custom_attribute = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute' + ) + log = mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.log') + + wrapped = step.run_filter(nullcontext(), 'migrate', 'lms')['command_contextmanager'] + + with wrapped: + command_execution() + + command_execution.assert_called_once() + function_trace.assert_called_once_with('migrate', operation_name='django.management.command') + set_transaction_name.assert_called_once_with('migrate') + set_custom_attribute.assert_any_call('management_command.service_variant', 'lms') + set_custom_attribute.assert_any_call('management_command.duration_seconds', 5.0) + set_custom_attribute.assert_any_call('management_command.status', 'success') + log.info.assert_any_call( + 'Starting management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s', + 'migrate', + 'lms', + 'django.management.command', + 'migrate', + ) + log.info.assert_any_call( + 'Finished management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s status=%s duration_seconds=%s', + 'migrate', + 'lms', + 'django.management.command', + 'migrate', + 'success', + 5.0, + ) + + +def test_management_command_monitoring_step_uses_configured_operation_name(mocker): + step = ManagementCommandMonitoringPipelineStep( + 'org.openedx.platform.management.command.contextmanager.requested.v1', + 'edx_filters_pipelines.management.pipelines.monitoring.ManagementCommandMonitoringPipelineStep', + operation_name='custom.management.operation', + ) + command_execution = mocker.Mock() + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.ENABLE_MANAGEMENT_COMMAND_MONITORING.is_enabled', + return_value=True, + ) + function_trace = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name') + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute') + + with step.run_filter(nullcontext(), 'collectstatic', 'cms')['command_contextmanager']: + command_execution() + + command_execution.assert_called_once() + function_trace.assert_called_once_with('collectstatic', operation_name='custom.management.operation') + + +def test_monitor_management_command_logs_failure(mocker): + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.time.monotonic', + side_effect=[10.0, 15.0], + ) + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + set_custom_attribute = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute' + ) + log = mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.log') + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name') + + with pytest.raises(RuntimeError): + with monitor_management_command('migrate', 'lms'): + raise RuntimeError('boom') + + log.info.assert_any_call( + 'Starting management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s', + 'migrate', + 'lms', + 'django.management.command', + 'migrate', + ) + assert log.exception.call_count == 1 + assert log.exception.call_args.args[:6] == ( + 'Management command failed: %s service_variant=%s ' + 'operation_name=%s resource_name=%s exception_class=%s error=%s', + 'migrate', + 'lms', + 'django.management.command', + 'migrate', + 'RuntimeError', + ) + assert str(log.exception.call_args.args[6]) == 'boom' + set_custom_attribute.assert_any_call('management_command.status', 'failure') + set_custom_attribute.assert_any_call('management_command.duration_seconds', 5.0) + set_custom_attribute.assert_any_call('management_command.exception_message', 'boom') + log.info.assert_any_call( + 'Finished management command: %s service_variant=%s ' + 'operation_name=%s resource_name=%s status=%s duration_seconds=%s', + 'migrate', + 'lms', + 'django.management.command', + 'migrate', + 'failure', + 5.0, + ) + + +@pytest.mark.parametrize( + 'run_url', + [ + 'https://github.com/edx/edx-internal/actions/runs/123', + 'https://github.com/edx/edx-internal/actions/runs/999', + ], +) +def test_monitor_management_command_sets_github_run_url_attribute(mocker, run_url): + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + set_custom_attribute = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute' + ) + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name') + mocker.patch.dict( + 'os.environ', + { + 'EDX_MC_GITHUB_RUN_URL': run_url, + }, + clear=False, + ) + + with monitor_management_command('migrate', 'lms'): + pass + + set_custom_attribute.assert_any_call( + 'management_command.github_run_url', + run_url, + ) + + +def test_monitor_management_command_ignores_blank_github_run_url(mocker): + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + set_custom_attribute = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute' + ) + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name') + + mocker.patch.dict('os.environ', {'EDX_MC_GITHUB_RUN_URL': ' '}, clear=False) + + with monitor_management_command('migrate', 'lms'): + pass + + metadata_calls = [ + call.args[0] + for call in set_custom_attribute.call_args_list + if call.args[0].startswith('management_command.') + ] + assert 'management_command.github_run_url' not in metadata_calls + + +@pytest.mark.parametrize( + 'raised_exception, expected_status, expected_exit_code, exception_class_recorded', + [ + pytest.param(SystemExit(0), 'success', None, False, id='system-exit-zero'), + pytest.param(SystemExit(1), 'failure', 1, True, id='system-exit-nonzero'), + pytest.param(KeyboardInterrupt(), 'failure', None, False, id='keyboard-interrupt'), + ], +) +def test_monitor_management_command_exception_handling( + mocker, + raised_exception, + expected_status, + expected_exit_code, + exception_class_recorded, +): + mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.function_trace', + return_value=nullcontext(), + ) + set_custom_attribute = mocker.patch( + 'edx_filters_pipelines.management.pipelines.monitoring.set_custom_attribute' + ) + mocker.patch('edx_filters_pipelines.management.pipelines.monitoring.set_monitoring_transaction_name') + + with pytest.raises(type(raised_exception)) as exc_info: + with monitor_management_command('migrate', 'lms'): + raise raised_exception + + if expected_exit_code is not None: + assert exc_info.value.code == expected_exit_code + set_custom_attribute.assert_any_call('management_command.exit_code', expected_exit_code) + else: + assert ('management_command.exit_code',) not in [ + call.args[:1] for call in set_custom_attribute.call_args_list + ] + + if exception_class_recorded: + set_custom_attribute.assert_any_call('management_command.exception_message', str(raised_exception)) + + if not exception_class_recorded: + assert ('management_command.exception_class', raised_exception.__class__.__name__) not in [ + call.args for call in set_custom_attribute.call_args_list + ] + + set_custom_attribute.assert_any_call('management_command.status', expected_status) diff --git a/tox.ini b/tox.ini index a4ade48..22e67ba 100644 --- a/tox.ini +++ b/tox.ini @@ -31,7 +31,7 @@ ignore = D101,D200,D203,D212,D215,D404,D405,D406,D407,D408,D409,D410,D411,D412,D [pytest] -addopts = --cov edx-filters-pipelines --cov-report term-missing --cov-report xml +addopts = --cov edx_filters_pipelines --cov-report term-missing --cov-report xml norecursedirs = .* docs requirements site-packages [testenv]