diff --git a/opentracing-shim/src/opentracingshim/__init__.py b/opentracing-shim/src/opentracingshim/__init__.py index ca277cccecc..a57b84abe29 100644 --- a/opentracing-shim/src/opentracingshim/__init__.py +++ b/opentracing-shim/src/opentracingshim/__init__.py @@ -68,11 +68,13 @@ def set_tag(self, key, value): return self def log_kv(self, key_values, timestamp=None): - if timestamp is None: - timestamp = util.time_ns() + if timestamp is not None: + event_timestamp = util.time_seconds_to_ns(timestamp) + else: + event_timestamp = util.time_ns() event_name = util.event_name_from_kv(key_values) - event = Event(event_name, timestamp, key_values) + event = Event(event_name, event_timestamp, key_values) self._otel_span.add_lazy_event(event) # Return self for call chaining. diff --git a/opentracing-shim/tests/test_shim.py b/opentracing-shim/tests/test_shim.py index 87e5b4b78cd..d1bcdb79d67 100644 --- a/opentracing-shim/tests/test_shim.py +++ b/opentracing-shim/tests/test_shim.py @@ -118,7 +118,11 @@ def test_explicit_start_time(self): now = time.time() with self.shim.start_active_span("TestSpan", start_time=now) as scope: result = util.time_seconds_from_ns(scope.span.unwrap().start_time) - self.assertEqual(result, now) + # Tolerate inaccuracies of less than a microsecond. + # TODO: Put a link to an explanation in the docs. + # TODO: This seems to work consistently, but we should find out the + # biggest possible loss of precision. + self.assertAlmostEqual(result, now, places=6) def test_explicit_end_time(self): """Test `end_time` argument of `finish()` method.""" @@ -128,7 +132,11 @@ def test_explicit_end_time(self): span.finish(now) end_time = util.time_seconds_from_ns(span.unwrap().end_time) - self.assertEqual(end_time, now) + # Tolerate inaccuracies of less than a microsecond. + # TODO: Put a link to an explanation in the docs. + # TODO: This seems to work consistently, but we should find out the + # biggest possible loss of precision. + self.assertAlmostEqual(end_time, now, places=6) def test_explicit_span_activation(self): """Test manual activation and deactivation of a span.""" @@ -355,9 +363,17 @@ def test_log_kv(self): self.assertIsNotNone(span.unwrap().events[0].timestamp) # Test explicit timestamp. - now = opentracingshim.util.time_ns() + now = time.time() span.log_kv({"foo": "bar"}, now) - self.assertEqual(span.unwrap().events[1].timestamp, now) + result = util.time_seconds_from_ns( + span.unwrap().events[1].timestamp + ) + self.assertEqual(span.unwrap().events[1].attributes["foo"], "bar") + # Tolerate inaccuracies of less than a microsecond. + # TODO: Put a link to an explanation in the docs. + # TODO: This seems to work consistently, but we should find out the + # biggest possible loss of precision. + self.assertAlmostEqual(result, now, places=6) def test_span_context(self): """Test construction of `SpanContextWrapper` objects.""" diff --git a/opentracing-shim/tests/test_util.py b/opentracing-shim/tests/test_util.py index 99e0b61ddce..869164eef1e 100644 --- a/opentracing-shim/tests/test_util.py +++ b/opentracing-shim/tests/test_util.py @@ -48,3 +48,18 @@ def test_time_seconds_from_ns(self): result = util.time_seconds_from_ns(time_nanoseconds) self.assertEqual(result, time_nanoseconds / 1e9) + + def test_time_conversion_precision(self): + """Verify time conversion from seconds to nanoseconds and vice versa is + accurate enough. + """ + + time_seconds = 1570484241.9501917 + time_nanoseconds = util.time_seconds_to_ns(time_seconds) + result = util.time_seconds_from_ns(time_nanoseconds) + + # Tolerate inaccuracies of less than a microsecond. + # TODO: Put a link to an explanation in the docs. + # TODO: This seems to work consistently, but we should find out the + # biggest possible loss of precision. + self.assertAlmostEqual(result, time_seconds, places=6)