Merge pull request #515 from opensafely-core/fix-tick-span-parent

fix tick span parent

jobrunner/record_stats.py

@@ -92,7 +92,7 @@ def record_tick_trace(last_run):
     Not that this will emit number of active jobs + 1 events every call, so we
     don't want to call it on too tight a loop.
     """
-    now = int(time.time() * 10e9)
+    now = time.time_ns()
 
     if last_run is None:
         return now
@@ -105,15 +105,12 @@ def record_tick_trace(last_run):
         models.Job, state__in=[models.State.PENDING, models.State.RUNNING]
     )
 
-    root = tracer.start_span("TICK", start_time=start_time)
-
-    for job in active_jobs:
-        span = tracer.start_span(job.status_code.name, start_time=start_time)
-        # TODO add cpu/memory as attributes?
-        tracing.set_span_metadata(span, job, tick=True)
-        span.end(end_time)
-
-    root.end(end_time)
+    with tracer.start_as_current_span("TICK", start_time=start_time):
+        for job in active_jobs:
+            span = tracer.start_span(job.status_code.name, start_time=start_time)
+            # TODO add cpu/memory as attributes?
+            tracing.set_span_metadata(span, job, tick=True)
+            span.end(end_time)
 
     return end_time
 

tests/test_record_stats.py

@@ -1,12 +1,10 @@
-import time
-
 from jobrunner import record_stats
 from jobrunner.models import State, StatusCode
 from tests.conftest import get_trace
 from tests.factories import job_factory
 
 
-def test_record_tick_trace(db):
+def test_record_tick_trace(db, freezer):
 
     jobs = []
     jobs.append(job_factory(status_code=StatusCode.CREATED))
@@ -18,29 +16,27 @@ def test_record_tick_trace(db):
     # this should not be tick'd
     job_factory(state=State.SUCCEEDED, status_code=StatusCode.SUCCEEDED)
 
-    last_run = int((time.time() - 10) * 1e9)
-    record_stats.record_tick_trace(last_run)
+    last_run1 = record_stats.record_tick_trace(None)
+    assert len(get_trace()) == 0
+
+    freezer.tick(10)
+
+    last_run2 = record_stats.record_tick_trace(last_run1)
+    assert last_run2 == last_run1 + 10 * 1e9
 
     spans = get_trace()
 
-    end_time = spans[0].end_time
+    root = spans[-1]
+    assert root.name == "TICK"
+    assert root.start_time == last_run1
+    assert root.end_time == last_run2
 
     for job, span in zip(jobs, spans):
         assert span.name == job.status_code.name
-        assert span.start_time == last_run
-        assert span.end_time == end_time
+        assert span.start_time == last_run1
+        assert span.end_time == last_run2
         assert span.attributes["tick"] is True
         assert span.attributes["job"] == job.id
+        assert span.parent.span_id == root.context.span_id
 
     assert "SUCCEEDED" not in [s.name for s in spans]
-
-    assert spans[-1].name == "TICK"
-    assert spans[-1].start_time == last_run
-    assert spans[-1].end_time == end_time
-
-
-def test_record_tick_trace_last_run_is_none(db):
-    now = int((time.time() - 10) * 1e9)
-    last_run = record_stats.record_tick_trace(None)
-    assert last_run > now
-    assert len(get_trace()) == 0