Browse Source

feat(trace): Calculate ts more precisely (#66152)

- This uses the start * finish ts and ms from clickhouse instead of
subtracting from the end_ts using duration
- Use a set instead of a list for checking visited orphans
William Mak 1 year ago
parent
commit
9fe8dfd109

+ 17 - 20
src/sentry/api/endpoints/organization_events_trace.py

@@ -49,6 +49,8 @@ SnubaTransaction = TypedDict(
         "transaction.duration": int,
         "transaction": str,
         "timestamp": str,
+        "precise.start_ts": int,
+        "precise.finish_ts": int,
         "trace.span": str,
         "trace.parent_span": str,
         "trace.parent_transaction": Optional[str],
@@ -172,15 +174,8 @@ class TraceEvent:
         self._nodestore_event: Event | None = None
         self.fetched_nodestore: bool = span_serialized
         self.span_serialized = span_serialized
-        if span_serialized:
-            self.fetched_nodestore = True
-            self.timestamp = datetime.fromisoformat(self.event["timestamp"]).timestamp()
-            self.start_timestamp = (
-                datetime.fromisoformat(self.event["timestamp"]).timestamp()
-                # duration is in ms, timestamp is in seconds
-                - self.event["transaction.duration"] / 1000
-            )
-        self.load_performance_issues(light, snuba_params)
+        if len(self.event["issue.ids"]) > 0:
+            self.load_performance_issues(light, snuba_params)
 
     @property
     def nodestore_event(self) -> Event | None:
@@ -343,13 +338,8 @@ class TraceEvent:
                 }
             )
         if self.span_serialized:
-            result["timestamp"] = self.timestamp
-            result["start_timestamp"] = self.start_timestamp
-            (
-                datetime.fromisoformat(self.event["timestamp"]).timestamp()
-                # duration is in ms, timestamp is in seconds
-                - self.event["transaction.duration"] / 1000
-            )
+            result["timestamp"] = self.event["precise.finish_ts"]
+            result["start_timestamp"] = self.event["precise.start_ts"]
         if self.nodestore_event:
             result["timestamp"] = self.nodestore_event.data.get("timestamp")
             result["start_timestamp"] = self.nodestore_event.data.get("start_timestamp")
@@ -413,8 +403,8 @@ def child_sort_key(item: TraceEvent) -> list[int]:
         ]
     elif item.span_serialized:
         return [
-            item.start_timestamp,
-            item.timestamp,
+            item.event["precise.start_ts"],
+            item.event["precise.finish_ts"],
             item.event["transaction"],
             item.event["id"],
         ]
@@ -439,7 +429,9 @@ def count_performance_issues(trace_id: str, params: Mapping[str, str]) -> int:
 
 
 def query_trace_data(
-    trace_id: str, params: Mapping[str, str], limit: int
+    trace_id: str,
+    params: Mapping[str, str],
+    limit: int,
 ) -> tuple[Sequence[SnubaTransaction], Sequence[SnubaError]]:
     transaction_query = QueryBuilder(
         Dataset.Transactions,
@@ -452,6 +444,8 @@ def query_trace_data(
             "transaction.duration",
             "transaction",
             "timestamp",
+            "precise.start_ts",
+            "precise.finish_ts",
             "project",
             "project.id",
             "trace.span",
@@ -1288,6 +1282,7 @@ class OrganizationEventsTraceEndpoint(OrganizationEventsTraceEndpointBase):
     ) -> Sequence[FullResponse]:
         root_traces: list[TraceEvent] = []
         orphans: list[TraceEvent] = []
+        orphan_event_ids: set[str] = set()
         orphan_errors: list[SnubaError] = []
         if not allow_orphan_errors:
             raise ParseError("Must allow orphan errors to useSpans")
@@ -1305,6 +1300,7 @@ class OrganizationEventsTraceEndpoint(OrganizationEventsTraceEndpointBase):
                 if parent_id is None:
                     if transaction["trace.parent_span"]:
                         orphans.append(serialized_transaction)
+                        orphan_event_ids.add(serialized_transaction.event["id"])
                     else:
                         root_traces.append(serialized_transaction)
                 else:
@@ -1335,8 +1331,9 @@ class OrganizationEventsTraceEndpoint(OrganizationEventsTraceEndpointBase):
             }
             for transaction in sorted(serialized_transactions, key=child_sort_key):
                 if transaction.event["id"] not in visited_transactions_ids:
-                    if transaction not in orphans:
+                    if transaction.event["id"] not in orphan_event_ids:
                         orphans.append(transaction)
+                        orphan_event_ids.add(transaction.event["id"])
                     visited_transactions_ids.add(transaction.event["id"])
                     for child in transaction.children:
                         visited_transactions_ids.add(child.event["id"])

+ 2 - 0
src/sentry/search/events/constants.py

@@ -20,6 +20,8 @@ PROJECT_ALIAS = "project"
 PROJECT_NAME_ALIAS = "project.name"
 PROJECT_DOT_ID_ALIAS = "project.id"
 PROJECT_ID_ALIAS = "project_id"
+PRECISE_START_TS = "precise.start_ts"
+PRECISE_FINISH_TS = "precise.finish_ts"
 ISSUE_ALIAS = "issue"
 ISSUE_ID_ALIAS = "issue.id"
 RELEASE_ALIAS = "release"

+ 24 - 0
src/sentry/search/events/datasets/discover.py

@@ -46,6 +46,8 @@ from sentry.search.events.constants import (
     MISERY_ALPHA,
     MISERY_BETA,
     NON_FAILURE_STATUS,
+    PRECISE_FINISH_TS,
+    PRECISE_START_TS,
     PROJECT_ALIAS,
     PROJECT_NAME_ALIAS,
     PROJECT_THRESHOLD_CONFIG_ALIAS,
@@ -156,6 +158,8 @@ class DiscoverDatasetConfig(DatasetConfig):
             TOTAL_COUNT_ALIAS: self._resolve_total_count,
             TOTAL_TRANSACTION_DURATION_ALIAS: self._resolve_total_sum_transaction_duration,
             DEVICE_CLASS_ALIAS: self._resolve_device_class,
+            PRECISE_FINISH_TS: self._resolve_precise_finish_ts,
+            PRECISE_START_TS: self._resolve_precise_start_ts,
         }
 
     @property
@@ -1389,6 +1393,26 @@ class DiscoverDatasetConfig(DatasetConfig):
             DEVICE_CLASS_ALIAS,
         )
 
+    def _resolve_precise_start_ts(self, alias: str) -> SelectType:
+        return Function(
+            "plus",
+            [
+                Function("toUnixTimestamp", [Column("start_ts")]),
+                Function("divide", [Column("start_ms"), 1000]),
+            ],
+            alias,
+        )
+
+    def _resolve_precise_finish_ts(self, alias: str) -> SelectType:
+        return Function(
+            "plus",
+            [
+                Function("toUnixTimestamp", [Column("finish_ts")]),
+                Function("divide", [Column("finish_ms"), 1000]),
+            ],
+            alias,
+        )
+
     # Functions
     def _resolve_apdex_function(self, args: Mapping[str, str], alias: str) -> SelectType:
         if args["satisfaction"]:

+ 2 - 4
tests/snuba/api/endpoints/test_organization_events_trace.py

@@ -797,10 +797,8 @@ class OrganizationEventsTraceEndpointTest(OrganizationEventsTraceEndpointBase):
 
     def assert_event(self, result, event_data, message):
         assert result["transaction"] == event_data.transaction, message
-        assert result["event_id"] == pytest.approx(event_data.event_id), message
-        assert result["start_timestamp"] == pytest.approx(
-            event_data.data["start_timestamp"]
-        ), message
+        assert result["event_id"] == event_data.event_id
+        assert result["start_timestamp"] == event_data.data["start_timestamp"]
 
     def assert_trace_data(self, root, gen2_no_children=True):
         """see the setUp docstring for an idea of what the response structure looks like"""