diff --git a/netbox/core/models/jobs.py b/netbox/core/models/jobs.py index 36e412c54..3d7dd08b7 100644 --- a/netbox/core/models/jobs.py +++ b/netbox/core/models/jobs.py @@ -182,18 +182,24 @@ class Job(models.Model): _("Jobs cannot be assigned to this object type ({type}).").format(type=self.object_type) ) + @property + def elapsed_time(self): + """ + The job's recorded execution time, or the time elapsed so far if it is still running. + Returns None for a job which has not yet started. + """ + if self.execution_time is not None: + return self.execution_time + if self.started and not self.completed: + return timezone.now() - self.started + return None + @property def duration(self): - if not self.completed: + if self.execution_time is None: return None - start_time = self.started or self.created - - if not start_time: - return None - - duration = self.completed - start_time - minutes, seconds = divmod(duration.total_seconds(), 60) + minutes, seconds = divmod(self.execution_time.total_seconds(), 60) return f"{int(minutes)} minutes, {seconds:.2f} seconds" diff --git a/netbox/core/tables/jobs.py b/netbox/core/tables/jobs.py index caf4903e0..bf1504739 100644 --- a/netbox/core/tables/jobs.py +++ b/netbox/core/tables/jobs.py @@ -1,5 +1,6 @@ import django_tables2 as tables -from django.utils.html import conditional_escape +from django.db.models import F +from django.utils.html import conditional_escape, format_html from django.utils.safestring import mark_safe from django.utils.translation import gettext_lazy as _ @@ -45,8 +46,10 @@ class JobTable(NetBoxTable): completed = columns.DateTimeColumn( verbose_name=_('Completed'), ) - execution_time = tables.Column( + execution_time = columns.DurationColumn( verbose_name=_('Execution Time'), + # Render running jobs (which have no recorded execution time yet) rather than the placeholder + empty_values=(), ) queue_name = tables.Column( verbose_name=_('Queue'), @@ -62,17 +65,39 @@ class JobTable(NetBoxTable): model = Job fields = ( 'pk', 'id', 'object_type', 'object', 'name', 'status', 'created', 'scheduled', 'interval', 'started', - 'completed', 'user', 'queue_name', 'log_entries', 'error', 'job_id', 'execution_time' + 'completed', 'execution_time', 'user', 'queue_name', 'log_entries', 'error', 'job_id', ) default_columns = ( - 'pk', 'id', 'object_type', 'object', 'name', 'status', 'created', 'started', 'completed', 'user', + 'pk', 'id', 'object_type', 'object', 'name', 'status', 'created', 'started', 'execution_time', 'user', ) def render_log_entries(self, value): return len(value) - def render_execution_time(self, value): - return humanize_duration(value) + def render_execution_time(self, record): + if (duration := record.elapsed_time) is None: + return self.default + + value = humanize_duration(duration) + if record.execution_time is None: + # The job is still running, so distinguish its (provisional) elapsed time from a final one + return format_html( + '{}', _('Still running'), value + ) + + return value + + def value_execution_time(self, record): + # Export the raw number of seconds rather than the humanized rendering + if (duration := record.elapsed_time) is None: + return None + return max(duration.total_seconds(), 0) + + def order_execution_time(self, queryset, is_descending): + # Jobs with no recorded execution time are sorted last irrespective of the sort direction + field = F('execution_time') + ordering = field.desc(nulls_last=True) if is_descending else field.asc(nulls_last=True) + return queryset.order_by(ordering), True class JobLogEntryTable(BaseTable): diff --git a/netbox/core/tests/test_models.py b/netbox/core/tests/test_models.py index d4465c436..e19fbdb3f 100644 --- a/netbox/core/tests/test_models.py +++ b/netbox/core/tests/test_models.py @@ -381,3 +381,54 @@ class JobTestCase(TestCase): job.terminate(status=JobStatusChoices.STATUS_COMPLETED) self.assertIsNone(job.execution_time) + + @patch('core.models.jobs.job_end') + def test_elapsed_time_returns_execution_time_once_completed(self, mock_job_end): + """ + For a completed job, elapsed_time should return the recorded execution_time. + """ + job = self._make_job(None, JobNotificationChoices.NOTIFICATION_NEVER) + job.started = timezone.now() - timedelta(seconds=90) + job.save() + + job.terminate(status=JobStatusChoices.STATUS_COMPLETED) + + self.assertEqual(job.elapsed_time, job.execution_time) + + def test_elapsed_time_of_running_job(self): + """ + A running job has no execution_time yet, so elapsed_time should report the time elapsed + since it started. + """ + job = self._make_job(None, JobNotificationChoices.NOTIFICATION_NEVER) + job.started = timezone.now() - timedelta(seconds=90) + job.save() + + self.assertEqual(job.status, JobStatusChoices.STATUS_RUNNING) + self.assertIsNone(job.execution_time) + self.assertGreaterEqual(job.elapsed_time, timedelta(seconds=90)) + self.assertLess(job.elapsed_time, timedelta(seconds=120)) + + def test_elapsed_time_none_when_never_started(self): + """ + A job which has not started has no elapsed time to report. + """ + job = self._make_job(None, JobNotificationChoices.NOTIFICATION_NEVER) + + self.assertIsNone(job.started) + self.assertIsNone(job.elapsed_time) + + @patch('core.models.jobs.job_end') + def test_duration_derives_from_execution_time(self, mock_job_end): + """ + The duration property should be rendered from the recorded execution_time, and should be + null for a job which never started. + """ + job = self._make_job(None, JobNotificationChoices.NOTIFICATION_NEVER) + job.execution_time = timedelta(seconds=90) + self.assertEqual(job.duration, '1 minutes, 30.00 seconds') + + # A job terminated without ever starting has no execution time, and thus no duration + unstarted = self._make_job(None, JobNotificationChoices.NOTIFICATION_NEVER) + unstarted.terminate(status=JobStatusChoices.STATUS_ERRORED) + self.assertIsNone(unstarted.duration) diff --git a/netbox/core/tests/test_tables.py b/netbox/core/tests/test_tables.py index c938fd057..5727d1a76 100644 --- a/netbox/core/tests/test_tables.py +++ b/netbox/core/tests/test_tables.py @@ -1,4 +1,11 @@ -from core.models import ObjectChange +import uuid +from datetime import timedelta + +from django.test import TestCase +from django.utils import timezone + +from core.choices import JobStatusChoices +from core.models import Job, ObjectChange from core.tables import * from utilities.testing import TableTestCases @@ -15,6 +22,105 @@ class JobTableTestCase(TableTestCases.StandardTableTestCase): table = JobTable +class JobExecutionTimeColumnTestCase(TestCase): + """ + Test the rendering, export, and ordering behavior of JobTable's execution_time column. + """ + @classmethod + def setUpTestData(cls): + now = timezone.now() + Job.objects.bulk_create(( + Job( + name='completed-90s', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_COMPLETED, + started=now - timedelta(seconds=90), completed=now, execution_time=timedelta(seconds=90), + ), + Job( + name='completed-subsecond', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_COMPLETED, + started=now - timedelta(milliseconds=430), completed=now, + execution_time=timedelta(milliseconds=430), + ), + Job( + name='completed-long', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_COMPLETED, + started=now - timedelta(days=2, hours=3), completed=now, + execution_time=timedelta(days=2, hours=3), + ), + Job( + name='negative', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_COMPLETED, + started=now, completed=now, execution_time=timedelta(seconds=-5), + ), + Job( + name='running', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_RUNNING, + started=now - timedelta(minutes=5), + ), + Job(name='pending', job_id=uuid.uuid4(), status=JobStatusChoices.STATUS_PENDING), + )) + + def _render(self, name): + table = JobTable(Job.objects.filter(name=name)) + table.columns.show('execution_time') + return str(next(iter(table.rows)).get_cell('execution_time')) + + def test_render_completed_job(self): + self.assertEqual(self._render('completed-90s'), '1m 30s') + self.assertEqual(self._render('completed-long'), '2d 3h') + + def test_render_subsecond_job(self): + # Sub-second jobs report millisecond precision rather than reading as zero + self.assertEqual(self._render('completed-subsecond'), '0.43s') + + def test_render_negative_execution_time(self): + # A negative stored value (e.g. from clock skew) never renders as negative + self.assertEqual(self._render('negative'), '0s') + + def test_render_running_job(self): + """ + A running job has no recorded execution time, so the column shows the time elapsed so far, + visually distinguished from a completed job's final value. + """ + rendered = self._render('running') + self.assertIn('5m', rendered) + self.assertIn('text-primary', rendered) + + def test_render_job_never_started(self): + table = JobTable(Job.objects.filter(name='pending')) + table.columns.show('execution_time') + row = next(iter(table.rows)) + self.assertEqual(str(row.get_cell('execution_time')), table.default) + + def test_export_value_is_raw_seconds(self): + table = JobTable(Job.objects.filter(name='completed-90s')) + table.columns.show('execution_time') + rows = list(table.as_values()) + index = rows[0].index('Execution Time') + self.assertEqual(rows[1][index], 90.0) + + def test_export_value_of_job_never_started(self): + table = JobTable(Job.objects.filter(name='pending')) + table.columns.show('execution_time') + rows = list(table.as_values()) + index = rows[0].index('Execution Time') + self.assertIsNone(rows[1][index]) + + def test_ordering_sorts_nulls_last(self): + """ + Jobs with no recorded execution time must sort last in both directions, so that sorting by + execution time does not bury the longest-running jobs behind pending ones. + """ + recorded = ['negative', 'completed-subsecond', 'completed-90s', 'completed-long'] + unrecorded = {'running', 'pending'} + + for descending, expected in ( + (False, recorded), + (True, list(reversed(recorded))), + ): + with self.subTest(descending=descending): + table = JobTable(Job.objects.all()) + queryset, _modified = table.columns['execution_time'].order(Job.objects.all(), descending) + names = list(queryset.values_list('name', flat=True)) + self.assertEqual(names[:len(recorded)], expected) + self.assertEqual(set(names[len(recorded):]), unrecorded) + + class ObjectChangeTableTestCase(TableTestCases.StandardTableTestCase): table = ObjectChangeTable queryset_sources = [ diff --git a/netbox/netbox/tables/columns.py b/netbox/netbox/tables/columns.py index 359c79c6d..bde929776 100644 --- a/netbox/netbox/tables/columns.py +++ b/netbox/netbox/tables/columns.py @@ -1,5 +1,6 @@ import zoneinfo from dataclasses import dataclass +from datetime import timedelta from urllib.parse import quote import django_tables2 as tables @@ -22,6 +23,7 @@ from extras.choices import CustomFieldTypeChoices from utilities.object_types import object_type_identifier, object_type_name from utilities.permissions import get_permission_for_model from utilities.request import get_safe_request_context +from utilities.string import humanize_duration from utilities.templatetags.builtins.filters import render_markdown from utilities.validators import url_scheme_is_allowed from utilities.views import get_action_url @@ -112,17 +114,13 @@ class DateTimeColumn(tables.Column): class DurationColumn(tables.Column): """ - Express a duration of time (in minutes) in a human-friendly format. Example: 437 minutes becomes "7h 17m" + Express a duration of time in a human-friendly format. Accepts either a timedelta or a count of + minutes. Example: 437 minutes becomes "7h 17m" """ def render(self, value): - ret = '' - if days := value // 1440: - ret += f'{days}d ' - if hours := value % 1440 // 60: - ret += f'{hours}h ' - if minutes := value % 60: - ret += f'{minutes}m' - return ret.strip() + if not isinstance(value, timedelta): + value = timedelta(minutes=value) + return humanize_duration(value) def value(self, value): return value