diff --git a/sentry_sdk/hub.py b/sentry_sdk/hub.py index df9de10fe4..6d731276d6 100644 --- a/sentry_sdk/hub.py +++ b/sentry_sdk/hub.py @@ -547,6 +547,7 @@ def start_transaction( } sampling_context.update(custom_sampling_context) transaction._set_initial_sampling_decision(sampling_context=sampling_context) + transaction._set_profiling_decision() # we don't bother to keep spans if we already know we're not going to # send the transaction diff --git a/sentry_sdk/integrations/wsgi.py b/sentry_sdk/integrations/wsgi.py index 03ce665489..f8b41dc12c 100644 --- a/sentry_sdk/integrations/wsgi.py +++ b/sentry_sdk/integrations/wsgi.py @@ -12,7 +12,6 @@ from sentry_sdk.tracing import Transaction, TRANSACTION_SOURCE_ROUTE from sentry_sdk.sessions import auto_session_tracking from sentry_sdk.integrations._wsgi_common import _filter_headers -from sentry_sdk.profiler import start_profiling from sentry_sdk._types import MYPY @@ -132,7 +131,7 @@ def __call__(self, environ, start_response): with hub.start_transaction( transaction, custom_sampling_context={"wsgi_environ": environ} - ), start_profiling(transaction, hub): + ): try: rv = self.app( environ, diff --git a/sentry_sdk/profiler.py b/sentry_sdk/profiler.py index 21313c9f73..e666411471 100644 --- a/sentry_sdk/profiler.py +++ b/sentry_sdk/profiler.py @@ -26,7 +26,6 @@ import sentry_sdk from sentry_sdk._compat import PY33 -from sentry_sdk._queue import Queue from sentry_sdk._types import MYPY from sentry_sdk.utils import ( filename_for_module, @@ -247,27 +246,33 @@ def __init__( self, scheduler, # type: Scheduler transaction, # type: sentry_sdk.tracing.Transaction - hub=None, # type: Optional[sentry_sdk.Hub] ): # type: (...) -> None self.scheduler = scheduler self.transaction = transaction - self.hub = hub self._start_ns = None # type: Optional[int] self._stop_ns = None # type: Optional[int] transaction._profile = self - def __enter__(self): + def start(self): # type: () -> None self._start_ns = nanosecond_time() self.scheduler.start_profiling() - def __exit__(self, ty, value, tb): - # type: (Optional[Any], Optional[Any], Optional[Any]) -> None + def stop(self): + # type: () -> None self.scheduler.stop_profiling() self._stop_ns = nanosecond_time() + def __enter__(self): + # type: () -> None + self.start() + + def __exit__(self, ty, value, tb): + # type: (Optional[Any], Optional[Any], Optional[Any]) -> None + self.stop() + def to_json(self, event_opt, options, scope): # type: (Any, Dict[str, Any], Optional[sentry_sdk.scope.Scope]) -> Dict[str, Any] assert self._start_ns is not None @@ -324,6 +329,16 @@ def to_json(self, event_opt, options, scope): ], } + @classmethod + def from_transaction(cls, transaction): + # type: (sentry_sdk.tracing.Transaction) -> Optional[Profile] + + if not should_profile(transaction): + return None + + assert _scheduler is not None + return Profile(_scheduler, transaction) + class SampleBuffer(object): """ @@ -465,8 +480,8 @@ def __init__(self, sample_buffer, frequency): # type: (SampleBuffer, int) -> None self.sample_buffer = sample_buffer self.sampler = sample_buffer.make_sampler() + self.active_profiles = 0 self._lock = threading.Lock() - self._count = 0 self._interval = 1.0 / frequency def setup(self): @@ -477,17 +492,26 @@ def teardown(self): # type: () -> None raise NotImplementedError + def __enter__(self): + # type: () -> Scheduler + self.setup() + return self + + def __exit__(self, ty, value, tb): + # type: (Optional[Any], Optional[Any], Optional[Any]) -> None + self.teardown() + def start_profiling(self): # type: () -> bool with self._lock: - self._count += 1 - return self._count == 1 + self.active_profiles += 1 + return self.active_profiles == 1 def stop_profiling(self): # type: () -> bool with self._lock: - self._count -= 1 - return self._count == 0 + self.active_profiles -= 1 + return self.active_profiles == 0 class ThreadScheduler(Scheduler): @@ -499,50 +523,23 @@ class ThreadScheduler(Scheduler): mode = "thread" name = None # type: Optional[str] - def __init__(self, sample_buffer, frequency): - # type: (SampleBuffer, int) -> None - super(ThreadScheduler, self).__init__( - sample_buffer=sample_buffer, frequency=frequency - ) - self.stop_events = Queue() - def setup(self): # type: () -> None - pass + self.event = threading.Event() + + # make sure the thread is a daemon here otherwise this + # can keep the application running after other threads + # have exited + self.thread = threading.Thread(name=self.name, target=self.run, daemon=True) + self.thread.start() def teardown(self): # type: () -> None - pass - - def start_profiling(self): - # type: () -> bool - if super(ThreadScheduler, self).start_profiling(): - # make sure to clear the event as we reuse the same event - # over the lifetime of the scheduler - event = threading.Event() - self.stop_events.put_nowait(event) - run = self.make_run(event) - - # make sure the thread is a daemon here otherwise this - # can keep the application running after other threads - # have exited - thread = threading.Thread(name=self.name, target=run, daemon=True) - thread.start() - return True - return False + self.event.set() + self.thread.join() - def stop_profiling(self): - # type: () -> bool - if super(ThreadScheduler, self).stop_profiling(): - # make sure the set the event here so that the thread - # can check to see if it should keep running - event = self.stop_events.get_nowait() - event.set() - return True - return False - - def make_run(self, event): - # type: (threading.Event) -> Callable[..., None] + def run(self): + # type: () -> None raise NotImplementedError @@ -555,34 +552,28 @@ class SleepScheduler(ThreadScheduler): mode = "sleep" name = "sentry.profiler.SleepScheduler" - def make_run(self, event): - # type: (threading.Event) -> Callable[..., None] - - def run(): - # type: () -> None - self.sampler() - - last = time.perf_counter() + def run(self): + # type: () -> None + last = time.perf_counter() - while True: - # some time may have elapsed since the last time - # we sampled, so we need to account for that and - # not sleep for too long - now = time.perf_counter() - elapsed = max(now - last, 0) + while True: + # some time may have elapsed since the last time + # we sampled, so we need to account for that and + # not sleep for too long + now = time.perf_counter() + elapsed = max(now - last, 0) - if elapsed < self._interval: - time.sleep(self._interval - elapsed) + if elapsed < self._interval: + time.sleep(self._interval - elapsed) - last = time.perf_counter() + last = time.perf_counter() - if event.is_set(): - break + if self.event.is_set(): + break + if self.active_profiles: self.sampler() - return run - class EventScheduler(ThreadScheduler): """ @@ -593,23 +584,17 @@ class EventScheduler(ThreadScheduler): mode = "event" name = "sentry.profiler.EventScheduler" - def make_run(self, event): - # type: (threading.Event) -> Callable[..., None] - - def run(): - # type: () -> None - self.sampler() - - while True: - event.wait(timeout=self._interval) + def run(self): + # type: () -> None + while True: + self.event.wait(timeout=self._interval) - if event.is_set(): - break + if self.event.is_set(): + break + if self.active_profiles: self.sampler() - return run - class SignalScheduler(Scheduler): """ @@ -734,8 +719,8 @@ def signal_timer(self): return signal.ITIMER_REAL -def _should_profile(transaction, hub): - # type: (sentry_sdk.tracing.Transaction, Optional[sentry_sdk.Hub]) -> bool +def should_profile(transaction): + # type: (sentry_sdk.tracing.Transaction) -> bool # The corresponding transaction was not sampled, # so don't generate a profile for it. @@ -746,7 +731,7 @@ def _should_profile(transaction, hub): if _scheduler is None: return False - hub = hub or sentry_sdk.Hub.current + hub = transaction.hub or sentry_sdk.Hub.current client = hub.client # The client is None, so we can't get the sample rate. @@ -765,13 +750,15 @@ def _should_profile(transaction, hub): @contextmanager -def start_profiling(transaction, hub=None): - # type: (sentry_sdk.tracing.Transaction, Optional[sentry_sdk.Hub]) -> Generator[None, None, None] +def start_profiling(transaction, _hub=None): + # type: (sentry_sdk.tracing.Transaction, Any) -> Generator[None, None, None] + # TODO: remove `_hub` from the arguments since it's not used anymore + + transaction._profile = Profile.from_transaction(transaction) # if profiling was not enabled, this should be a noop - if _should_profile(transaction, hub): - assert _scheduler is not None - with Profile(_scheduler, transaction, hub=hub): + if transaction._profile is not None: + with transaction._profile: yield else: yield diff --git a/sentry_sdk/tracing.py b/sentry_sdk/tracing.py index dc65ea5fd7..a0f6c4ff7c 100644 --- a/sentry_sdk/tracing.py +++ b/sentry_sdk/tracing.py @@ -7,6 +7,7 @@ import sentry_sdk from sentry_sdk.consts import INSTRUMENTER +from sentry_sdk.profiler import Profile from sentry_sdk.utils import logger from sentry_sdk._types import MYPY @@ -637,6 +638,12 @@ def containing_transaction(self): # reference. return self + def _set_profiling_decision(self): + # type: () -> None + self._profile = Profile.from_transaction(self) + if self._profile is not None: + self._profile.start() + def finish(self, hub=None, end_timestamp=None): # type: (Optional[sentry_sdk.Hub], Optional[datetime]) -> Optional[str] if self.timestamp is not None: @@ -707,7 +714,8 @@ def finish(self, hub=None, end_timestamp=None): "spans": finished_spans, } # type: Event - if hub.client is not None and self._profile is not None: + if self._profile is not None: + self._profile.stop() event["profile"] = self._profile if has_custom_measurements_enabled(): diff --git a/tests/test_profiler.py b/tests/test_profiler.py index 9a268713c8..f05c723243 100644 --- a/tests/test_profiler.py +++ b/tests/test_profiler.py @@ -238,10 +238,6 @@ def test_extract_stack_with_max_depth(depth, max_stack_depth, actual_depth): assert stack[actual_depth].function == "", actual_depth -def get_scheduler_threads(scheduler): - return [thread for thread in threading.enumerate() if thread.name == scheduler.name] - - class DummySampleBuffer(SampleBuffer): def __init__(self, capacity, sample_data=None): super(DummySampleBuffer, self).__init__(capacity) @@ -249,8 +245,11 @@ def __init__(self, capacity, sample_data=None): def make_sampler(self): def _sample_stack(*args, **kwargs): - ts, sample = self.sample_data.pop(0) - self.write(ts, sample) + try: + ts, sample = self.sample_data.pop(0) + self.write(ts, sample) + except IndexError: + pass return _sample_stack @@ -263,47 +262,7 @@ def _sample_stack(*args, **kwargs): pytest.param(EventScheduler, id="event scheduler"), ], ) -def test_thread_scheduler_takes_first_samples(scheduler_class): - sample_buffer = DummySampleBuffer( - capacity=1, - sample_data=[ - ( - 0, - [ - ( - 0, - ( - RawFrameData( - "/path/to/file.py", "file.py", "name", 1, "file" - ), - ), - ) - ], - ) - ], - ) - scheduler = scheduler_class(sample_buffer=sample_buffer, frequency=1000) - assert scheduler.start_profiling() - # immediately stopping means by the time the sampling thread will exit - # before it samples at the end of the first iteration - assert scheduler.stop_profiling() - time.sleep(0.002) - assert len(get_scheduler_threads(scheduler)) == 0 - - # there should be exactly 1 sample because we always sample once immediately - profile = sample_buffer.slice_profile(0, 1) - assert len(profile["samples"]) == 1 - - -@minimum_python_33 -@pytest.mark.parametrize( - ("scheduler_class",), - [ - pytest.param(SleepScheduler, id="sleep scheduler"), - pytest.param(EventScheduler, id="event scheduler"), - ], -) -def test_thread_scheduler_takes_more_samples(scheduler_class): +def test_thread_scheduler_takes_samples(scheduler_class): sample_buffer = DummySampleBuffer( capacity=10, sample_data=[ @@ -323,67 +282,18 @@ def test_thread_scheduler_takes_more_samples(scheduler_class): for i in range(3) ], ) - scheduler = scheduler_class(sample_buffer=sample_buffer, frequency=1000) - assert scheduler.start_profiling() - # waiting a little before stopping the scheduler means the profiling - # thread will get a chance to take a few samples before exiting - time.sleep(0.002) - assert scheduler.stop_profiling() - time.sleep(0.002) - assert len(get_scheduler_threads(scheduler)) == 0 - - # there should be more than 1 sample because we always sample once immediately - # plus any samples take afterwards - profile = sample_buffer.slice_profile(0, 3) - assert len(profile["samples"]) > 1 - - -@minimum_python_33 -@pytest.mark.parametrize( - ("scheduler_class",), - [ - pytest.param(SleepScheduler, id="sleep scheduler"), - pytest.param(EventScheduler, id="event scheduler"), - ], -) -def test_thread_scheduler_single_background_thread(scheduler_class): - sample_buffer = SampleBuffer(1) - scheduler = scheduler_class(sample_buffer=sample_buffer, frequency=1000) - - assert scheduler.start_profiling() - - # the scheduler thread does not immediately exit - # but it should exit after the next time it samples - assert scheduler.stop_profiling() - - assert scheduler.start_profiling() - - # because the scheduler thread does not immediately exit - # after stop_profiling is called, we have to wait a little - # otherwise, we'll see an extra scheduler thread in the - # following assertion - # - # one iteration of the scheduler takes 1.0 / frequency seconds - # so make sure this sleeps for longer than that to avoid flakes - time.sleep(0.002) - - # there should be 1 scheduler thread now because the first - # one should be stopped and a new one started - assert len(get_scheduler_threads(scheduler)) == 1 - - assert scheduler.stop_profiling() - - # because the scheduler thread does not immediately exit - # after stop_profiling is called, we have to wait a little - # otherwise, we'll see an extra scheduler thread in the - # following assertion - # - # one iteration of the scheduler takes 1.0 / frequency seconds - # so make sure this sleeps for longer than that to avoid flakes - time.sleep(0.002) - - # there should be 0 scheduler threads now because they stopped - assert len(get_scheduler_threads(scheduler)) == 0 + with scheduler_class(sample_buffer=sample_buffer, frequency=1000) as scheduler: + assert scheduler.start_profiling() + # waiting a little before stopping the scheduler means the profiling + # thread will get a chance to take a few samples before exiting + time.sleep(0.002) + assert scheduler.stop_profiling() + time.sleep(0.002) + + # there should be at least 1 sample because we gave it some time + # before stopping the profiler to take a sample + profile = sample_buffer.slice_profile(0, 3) + assert len(profile["samples"]) > 0 current_thread = threading.current_thread()