Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
27 commits
Select commit Hold shift + click to select a range
dcc55bd
feat(profiling): Convert profile output to the sample format
phacops Sep 13, 2022
3aeb1bf
Lint code
phacops Sep 13, 2022
aa11361
Optimize stack lookups
phacops Sep 13, 2022
f40cab8
Use a tuple instead of list so we can use it as a key to a dict
phacops Sep 13, 2022
74c5626
Merge branch 'master' into pierre/profiling-convert-to-sample-format
phacops Sep 15, 2022
80b3e53
Fix a type and a variable initialization misplaced
phacops Sep 15, 2022
5426c5b
Record the thread_id on which the transaction was started
phacops Sep 15, 2022
9dbce16
Fix relative start/end of the transaction
phacops Sep 15, 2022
e627109
Calculate more accurate times depending on Python versions
phacops Sep 15, 2022
359c337
Format code
phacops Sep 15, 2022
006f0aa
Use a more compatible way to get the identifier
phacops Sep 15, 2022
894b939
Disable profiling for Python < 3.3
phacops Sep 15, 2022
b41508e
Use time.perf_counter_ns() when appropriate
phacops Sep 15, 2022
21fa1e7
Add a comment to indicate where thread_id is used
phacops Sep 15, 2022
6cf951e
Check first if profiling is enabled by the user because showing a war…
phacops Sep 15, 2022
173eace
Move the warning to the setup method
phacops Sep 15, 2022
15ec738
Disable profiling tests for Python < 3.3
phacops Sep 15, 2022
f94b1ac
Rename timestamp field to match format change
phacops Sep 26, 2022
527b388
Merge branch 'master' into pierre/profiling-convert-to-sample-format
phacops Sep 26, 2022
9f03a2d
Remove the file that shouldn't be
phacops Sep 26, 2022
415d330
Fix a key name
phacops Sep 26, 2022
d7cb75a
Fix timestamp calculation
phacops Sep 26, 2022
b4bded8
Lint code
phacops Sep 26, 2022
c03d3f3
Fix transaction relative start time
phacops Sep 26, 2022
a7516e3
Fix relative_end_ns as well
phacops Sep 26, 2022
5745c24
Revert _start_timestamp_monotonic change since we're not using it any…
phacops Sep 26, 2022
100bc08
Use the duration of the profile since we end the transaction after th…
phacops Sep 26, 2022
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions sentry_sdk/_compat.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
7 changes: 5 additions & 2 deletions sentry_sdk/client.py
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
86 changes: 53 additions & 33 deletions sentry_sdk/profiler.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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]

Expand All @@ -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

Expand Down Expand Up @@ -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),
}
],
}


Expand Down Expand Up @@ -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]

Expand All @@ -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:
Expand All @@ -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):
Expand Down
7 changes: 7 additions & 0 deletions sentry_sdk/tracing.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import uuid
import random
import threading
import time

from datetime import datetime, timedelta
Expand Down Expand Up @@ -544,6 +545,7 @@ class Transaction(Span):
"_measurements",
"_profile",
"_baggage",
"_active_thread_id",
)

def __init__(
Expand Down Expand Up @@ -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
Expand Down
24 changes: 23 additions & 1 deletion sentry_sdk/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down Expand Up @@ -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
66 changes: 34 additions & 32 deletions tests/integrations/wsgi/test_wsgi.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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