ref(profiling): Add debug logs to profiling (#1883)

Author: Zylphrex

sentry_sdk/profiler.py

@@ -150,11 +150,11 @@ def setup_profiler(options):
     global _scheduler
 
     if _scheduler is not None:
-        logger.debug("profiling is already setup")
+        logger.debug("[Profiling] Profiler is already setup")
         return False
 
     if not PY33:
-        logger.warn("profiling is only supported on Python >= 3.3")
+        logger.warn("[Profiling] Profiler requires Python >= 3.3")
         return False
 
     frequency = DEFAULT_SAMPLING_FREQUENCY
@@ -184,6 +184,9 @@ def setup_profiler(options):
     else:
         raise ValueError("Unknown profiler mode: {}".format(profiler_mode))
 
+    logger.debug(
+        "[Profiling] Setting up profiler in {mode} mode".format(mode=_scheduler.mode)
+    )
     _scheduler.setup()
 
     atexit.register(teardown_profiler)
@@ -440,6 +443,11 @@ def __init__(
     def update_active_thread_id(self):
         # type: () -> None
         self.active_thread_id = get_current_thread_id()
+        logger.debug(
+            "[Profiling] updating active thread id to {tid}".format(
+                tid=self.active_thread_id
+            )
+        )
 
     def _set_initial_sampling_decision(self, sampling_context):
         # type: (SamplingContext) -> None
@@ -456,11 +464,17 @@ def _set_initial_sampling_decision(self, sampling_context):
         # The corresponding transaction was not sampled,
         # so don't generate a profile for it.
         if not self.sampled:
+            logger.debug(
+                "[Profiling] Discarding profile because transaction is discarded."
+            )
             self.sampled = False
             return
 
         # The profiler hasn't been properly initialized.
         if self.scheduler is None:
+            logger.debug(
+                "[Profiling] Discarding profile because profiler was not started."
+            )
             self.sampled = False
             return
 
@@ -478,6 +492,9 @@ def _set_initial_sampling_decision(self, sampling_context):
         # The profiles_sample_rate option was not set, so profiling
         # was never enabled.
         if sample_rate is None:
+            logger.debug(
+                "[Profiling] Discarding profile because profiling was not enabled."
+            )
             self.sampled = False
             return
 
@@ -486,6 +503,15 @@ def _set_initial_sampling_decision(self, sampling_context):
         # to a float (True becomes 1.0 and False becomes 0.0)
         self.sampled = random.random() < float(sample_rate)
 
+        if self.sampled:
+            logger.debug("[Profiling] Initializing profile")
+        else:
+            logger.debug(
+                "[Profiling] Discarding profile because it's not included in the random sample (sample rate = {sample_rate})".format(
+                    sample_rate=float(sample_rate)
+                )
+            )
+
     def get_profile_context(self):
         # type: () -> ProfileContext
         return {"profile_id": self.event_id}
@@ -496,6 +522,7 @@ def start(self):
             return
 
         assert self.scheduler, "No scheduler specified"
+        logger.debug("[Profiling] Starting profile")
         self.active = True
         self.start_ns = nanosecond_time()
         self.scheduler.start_profiling(self)
@@ -506,6 +533,7 @@ def stop(self):
             return
 
         assert self.scheduler, "No scheduler specified"
+        logger.debug("[Profiling] Stopping profile")
         self.active = False
         self.scheduler.stop_profiling(self)
         self.stop_ns = nanosecond_time()
@@ -651,11 +679,14 @@ def to_json(self, event_opt, options):
 
     def valid(self):
         # type: () -> bool
-        return (
-            self.sampled is not None
-            and self.sampled
-            and self.unique_samples >= PROFILE_MINIMUM_SAMPLES
-        )
+        if self.sampled is None or not self.sampled:
+            return False
+
+        if self.unique_samples < PROFILE_MINIMUM_SAMPLES:
+            logger.debug("[Profiling] Discarding profile because insufficient samples.")
+            return False
+
+        return True
 
 
 class Scheduler(object):