feat(profiling): Convert profile output to the sample format (#1611)

Author: Pierre Massat

sentry_sdk/_compat.py

@@ -13,6 +13,8 @@
 
 
 PY2 = sys.version_info[0] == 2
+PY33 = sys.version_info[0] == 3 and sys.version_info[1] >= 3
+PY37 = sys.version_info[0] == 3 and sys.version_info[1] >= 7
 
 if PY2:
     import urlparse

sentry_sdk/client.py

@@ -410,9 +410,12 @@ def capture_event(
 
             if is_transaction:
                 if "profile" in event_opt:
-                    event_opt["profile"]["transaction_id"] = event_opt["event_id"]
                     event_opt["profile"]["environment"] = event_opt.get("environment")
-                    event_opt["profile"]["version_name"] = event_opt.get("release", "")
+                    event_opt["profile"]["release"] = event_opt.get("release", "")
+                    event_opt["profile"]["timestamp"] = event_opt.get("timestamp", "")
+                    event_opt["profile"]["transactions"][0]["id"] = event_opt[
+                        "event_id"
+                    ]
                     envelope.add_profile(event_opt.pop("profile"))
                 envelope.add_transaction(event_opt)
             else:

sentry_sdk/profiler.py

@@ -25,8 +25,10 @@
 from contextlib import contextmanager
 
 import sentry_sdk
-from sentry_sdk._compat import PY2
+from sentry_sdk._compat import PY33
+
 from sentry_sdk._types import MYPY
+from sentry_sdk.utils import nanosecond_time
 
 if MYPY:
     from typing import Any
@@ -43,22 +45,6 @@
     FrameData = Tuple[str, str, int]
 
 
-if PY2:
-
-    def nanosecond_time():
-        # type: () -> int
-        return int(time.clock() * 1e9)
-
-else:
-
-    def nanosecond_time():
-        # type: () -> int
-
-        # In python3.7+, there is a time.perf_counter_ns()
-        # that we may want to switch to for more precision
-        return int(time.perf_counter() * 1e9)
-
-
 _sample_buffer = None  # type: Optional[_SampleBuffer]
 _scheduler = None  # type: Optional[_Scheduler]
 
@@ -73,6 +59,12 @@ def setup_profiler(options):
     buffer_secs = 60
     frequency = 101
 
+    if not PY33:
+        from sentry_sdk.utils import logger
+
+        logger.warn("profiling is only supported on Python >= 3.3")
+        return
+
     global _sample_buffer
     global _scheduler
 
@@ -194,19 +186,39 @@ def to_json(self):
         assert self._stop_ns is not None
 
         return {
-            "device_os_name": platform.system(),
-            "device_os_version": platform.release(),
-            "duration_ns": str(self._stop_ns - self._start_ns),
             "environment": None,  # Gets added in client.py
+            "event_id": uuid.uuid4().hex,
             "platform": "python",
-            "platform_version": platform.python_version(),
-            "profile_id": uuid.uuid4().hex,
             "profile": _sample_buffer.slice_profile(self._start_ns, self._stop_ns),
-            "trace_id": self.transaction.trace_id,
-            "transaction_id": None,  # Gets added in client.py
-            "transaction_name": self.transaction.name,
-            "version_code": "",  # TODO: Determine appropriate value. Currently set to empty string so profile will not get rejected.
-            "version_name": None,  # Gets added in client.py
+            "release": None,  # Gets added in client.py
+            "timestamp": None,  # Gets added in client.py
+            "version": "1",
+            "device": {
+                "architecture": platform.machine(),
+            },
+            "os": {
+                "name": platform.system(),
+                "version": platform.release(),
+            },
+            "runtime": {
+                "name": platform.python_implementation(),
+                "version": platform.python_version(),
+            },
+            "transactions": [
+                {
+                    "id": None,  # Gets added in client.py
+                    "name": self.transaction.name,
+                    # we start the transaction before the profile and this is
+                    # the transaction start time relative to the profile, so we
+                    # hardcode it to 0 until we can start the profile before
+                    "relative_start_ns": "0",
+                    # use the duration of the profile instead of the transaction
+                    # because we end the transaction after the profile
+                    "relative_end_ns": str(self._stop_ns - self._start_ns),
+                    "trace_id": self.transaction.trace_id,
+                    "active_thread_id": str(self.transaction._active_thread_id),
+                }
+            ],
         }
 
 
@@ -245,8 +257,10 @@ def write(self, sample):
         self.idx = (idx + 1) % self.capacity
 
     def slice_profile(self, start_ns, stop_ns):
-        # type: (int, int) -> Dict[str, List[Any]]
+        # type: (int, int) -> Dict[str, Any]
         samples = []  # type: List[Any]
+        stacks = dict()  # type: Dict[Any, int]
+        stacks_list = list()  # type: List[Any]
         frames = dict()  # type: Dict[FrameData, int]
         frames_list = list()  # type: List[Any]
 
@@ -265,10 +279,10 @@ def slice_profile(self, start_ns, stop_ns):
 
             for tid, stack in raw_sample[1]:
                 sample = {
-                    "frames": [],
-                    "relative_timestamp_ns": ts - start_ns,
-                    "thread_id": tid,
+                    "elapsed_since_start_ns": str(ts - start_ns),
+                    "thread_id": str(tid),
                 }
+                current_stack = []
 
                 for frame in stack:
                     if frame not in frames:
@@ -280,11 +294,17 @@ def slice_profile(self, start_ns, stop_ns):
                                 "line": frame[2],
                             }
                         )
-                    sample["frames"].append(frames[frame])
+                    current_stack.append(frames[frame])
+
+                current_stack = tuple(current_stack)
+                if current_stack not in stacks:
+                    stacks[current_stack] = len(stacks)
+                    stacks_list.append(current_stack)
 
+                sample["stack_id"] = stacks[current_stack]
                 samples.append(sample)
 
-        return {"frames": frames_list, "samples": samples}
+        return {"stacks": stacks_list, "frames": frames_list, "samples": samples}
 
 
 class _Scheduler(object):

sentry_sdk/tracing.py

@@ -1,5 +1,6 @@
 import uuid
 import random
+import threading
 import time
 
 from datetime import datetime, timedelta
@@ -544,6 +545,7 @@ class Transaction(Span):
         "_measurements",
         "_profile",
         "_baggage",
+        "_active_thread_id",
     )
 
     def __init__(
@@ -579,6 +581,11 @@ def __init__(
         self._measurements = {}  # type: Dict[str, Any]
         self._profile = None  # type: Optional[Dict[str, Any]]
         self._baggage = baggage
+        # for profiling, we want to know on which thread a transaction is started
+        # to accurately show the active thread in the UI
+        self._active_thread_id = (
+            threading.current_thread().ident
+        )  # used by profiling.py
 
     def __repr__(self):
         # type: () -> str

sentry_sdk/utils.py

@@ -7,11 +7,12 @@
 import threading
 import subprocess
 import re
+import time
 
 from datetime import datetime
 
 import sentry_sdk
-from sentry_sdk._compat import urlparse, text_type, implements_str, PY2
+from sentry_sdk._compat import urlparse, text_type, implements_str, PY2, PY33, PY37
 
 from sentry_sdk._types import MYPY
 
@@ -1010,3 +1011,24 @@ def from_base64(base64_string):
         )
 
     return utf8_string
+
+
+if PY37:
+
+    def nanosecond_time():
+        # type: () -> int
+        return time.perf_counter_ns()
+
+elif PY33:
+
+    def nanosecond_time():
+        # type: () -> int
+
+        return int(time.perf_counter() * 1e9)
+
+else:
+
+    def nanosecond_time():
+        # type: () -> int
+
+        raise AttributeError

tests/integrations/wsgi/test_wsgi.py

@@ -6,6 +6,7 @@
 from sentry_sdk.integrations.wsgi import SentryWsgiMiddleware
 from sentry_sdk.profiler import teardown_profiler
 from collections import Counter
+from sentry_sdk.utils import PY33
 
 try:
     from unittest import mock  # python 3.3 and above
@@ -21,12 +22,6 @@ def app(environ, start_response):
     return app
 
 
-@pytest.fixture
-def profiling():
-    yield
-    teardown_profiler()
-
-
 class IterableApp(object):
     def __init__(self, iterable):
         self.iterable = iterable
@@ -289,31 +284,38 @@ def sample_app(environ, start_response):
     assert len(session_aggregates) == 1
 
 
-@pytest.mark.parametrize(
-    "profiles_sample_rate,should_send",
-    [(1.0, True), (0.75, True), (0.25, False), (None, False)],
-)
-def test_profile_sent_when_profiling_enabled(
-    capture_envelopes, sentry_init, profiling, profiles_sample_rate, should_send
-):
-    def test_app(environ, start_response):
-        start_response("200 OK", [])
-        return ["Go get the ball! Good dog!"]
-
-    sentry_init(
-        traces_sample_rate=1.0,
-        _experiments={"profiles_sample_rate": profiles_sample_rate},
-    )
-    app = SentryWsgiMiddleware(test_app)
-    envelopes = capture_envelopes()
+if PY33:
 
-    with mock.patch("sentry_sdk.profiler.random.random", return_value=0.5):
-        client = Client(app)
-        client.get("/")
+    @pytest.fixture
+    def profiling():
+        yield
+        teardown_profiler()
 
-    profile_sent = False
-    for item in envelopes[0].items:
-        if item.headers["type"] == "profile":
-            profile_sent = True
-            break
-    assert profile_sent == should_send
+    @pytest.mark.parametrize(
+        "profiles_sample_rate,should_send",
+        [(1.0, True), (0.75, True), (0.25, False), (None, False)],
+    )
+    def test_profile_sent_when_profiling_enabled(
+        capture_envelopes, sentry_init, profiling, profiles_sample_rate, should_send
+    ):
+        def test_app(environ, start_response):
+            start_response("200 OK", [])
+            return ["Go get the ball! Good dog!"]
+
+        sentry_init(
+            traces_sample_rate=1.0,
+            _experiments={"profiles_sample_rate": profiles_sample_rate},
+        )
+        app = SentryWsgiMiddleware(test_app)
+        envelopes = capture_envelopes()
+
+        with mock.patch("sentry_sdk.profiler.random.random", return_value=0.5):
+            client = Client(app)
+            client.get("/")
+
+        profile_sent = False
+        for item in envelopes[0].items:
+            if item.headers["type"] == "profile":
+                profile_sent = True
+                break
+        assert profile_sent == should_send