Limit cases where SQL origin is captured (#881)

* Limit backtraces for origin to 20 frames

* Implement threshold for collecting sql origins

* Add tests

* Typo

* Refactor resolving event origin to unify code

Author: stayallive

config/sentry.php

@@ -88,6 +88,9 @@
         // Capture where the SQL query originated from on the SQL query spans
         'sql_origin' => env('SENTRY_TRACE_SQL_ORIGIN_ENABLED', true),
 
+        // Define a threshold in milliseconds for SQL queries to resolve their origin
+        'sql_origin_threshold_ms' => env('SENTRY_TRACE_SQL_ORIGIN_THRESHOLD_MS', 100),
+
         // Capture views rendered as spans
         'views' => env('SENTRY_TRACE_VIEWS_ENABLED', true),
 

src/Sentry/Laravel/Features/CacheIntegration.php

@@ -108,7 +108,7 @@ public function handleRedisCommand(RedisEvents\CommandExecuted $event): void
             $commandOrigin = $this->resolveEventOrigin();
 
             if ($commandOrigin !== null) {
-                $data['db.redis.origin'] = $commandOrigin;
+                $data = array_merge($data, $commandOrigin);
             }
         }
 

src/Sentry/Laravel/Features/Concerns/ResolvesEventOrigin.php

@@ -12,19 +12,35 @@ protected function container(): Container
         return app();
     }
 
-    protected function resolveEventOrigin(): ?string
+    protected function resolveEventOrigin(): ?array
     {
         $backtraceHelper = $this->makeBacktraceHelper();
 
-        $firstAppFrame = $backtraceHelper->findFirstInAppFrameForBacktrace(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS));
+        // We limit the backtrace to 20 frames to prevent too much overhead and we'd reasonable expect the origin to be within the first 20 frames
+        $firstAppFrame = $backtraceHelper->findFirstInAppFrameForBacktrace(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 20));
 
         if ($firstAppFrame === null) {
             return null;
         }
 
         $filePath = $backtraceHelper->getOriginalViewPathForFrameOfCompiledViewPath($firstAppFrame) ?? $firstAppFrame->getFile();
 
-        return "{$filePath}:{$firstAppFrame->getLine()}";
+        return [
+            'code.filepath' => $filePath,
+            'code.function' => $firstAppFrame->getFunctionName(),
+            'code.lineno' => $firstAppFrame->getLine(),
+        ];
+    }
+
+    protected function resolveEventOriginAsString(): ?string
+    {
+        $origin = $this->resolveEventOrigin();
+
+        if ($origin === null) {
+            return null;
+        }
+
+        return "{$origin['code.filepath']}:{$origin['code.lineno']}";
     }
 
     private function makeBacktraceHelper(): BacktraceHelper

src/Sentry/Laravel/Integration.php

@@ -322,7 +322,7 @@ public function __invoke(Model $model, string $relation): void
                     $scope->setContext('violation', [
                         'model'    => get_class($model),
                         'relation' => $relation,
-                        'origin'   => $this->resolveEventOrigin(),
+                        'origin'   => $this->resolveEventOriginAsString(),
                         'kind'     => 'lazy_loading',
                     ]);
 

src/Sentry/Laravel/Tracing/EventHandler.php

@@ -53,7 +53,14 @@ class EventHandler
      *
      * @var bool
      */
-    private $traceSqlQueryOrigins;
+    private $traceSqlQueryOrigin;
+
+    /**
+     * The threshold in milliseconds to consider a SQL query origin.
+     *
+     * @var int
+     */
+    private $traceSqlQueryOriginTreshHoldMs;
 
     /**
      * Indicates if we should trace queue job spans.
@@ -90,7 +97,8 @@ public function __construct(array $config)
     {
         $this->traceSqlQueries = ($config['sql_queries'] ?? true) === true;
         $this->traceSqlBindings = ($config['sql_bindings'] ?? true) === true;
-        $this->traceSqlQueryOrigins = ($config['sql_origin'] ?? true) === true;
+        $this->traceSqlQueryOrigin = ($config['sql_origin'] ?? true) === true;
+        $this->traceSqlQueryOriginTreshHoldMs = $config['sql_origin_threshold_ms'] ?? 100;
 
         $this->traceQueueJobs = ($config['queue_jobs'] ?? false) === true;
         $this->traceQueueJobsAsTransactions = ($config['queue_job_transactions'] ?? false) === true;
@@ -180,8 +188,8 @@ protected function queryExecutedHandler(DatabaseEvents\QueryExecuted $query): vo
             ]));
         }
 
-        if ($this->traceSqlQueryOrigins) {
-            $queryOrigin = $this->resolveQueryOriginFromBacktrace();
+        if ($this->traceSqlQueryOrigin && $query->time >= $this->traceSqlQueryOriginTreshHoldMs) {
+            $queryOrigin = $this->resolveEventOrigin();
 
             if ($queryOrigin !== null) {
                 $context->setData(array_merge($context->getData(), $queryOrigin));
@@ -191,30 +199,6 @@ protected function queryExecutedHandler(DatabaseEvents\QueryExecuted $query): vo
         $parentSpan->startChild($context);
     }
 
-    /**
-     * Try to find the origin of the SQL query that was just executed.
-     *
-     * @return string|null
-     */
-    private function resolveQueryOriginFromBacktrace(): ?array
-    {
-        $backtraceHelper = $this->makeBacktraceHelper();
-
-        $firstAppFrame = $backtraceHelper->findFirstInAppFrameForBacktrace(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS));
-
-        if ($firstAppFrame === null) {
-            return null;
-        }
-
-        $filePath = $backtraceHelper->getOriginalViewPathForFrameOfCompiledViewPath($firstAppFrame) ?? $firstAppFrame->getFile();
-
-        return [
-            'code.filepath' => $filePath,
-            'code.function' => $firstAppFrame->getFunctionName(),
-            'code.lineno' => $firstAppFrame->getLine(),
-        ];
-    }
-
     protected function responsePreparedHandler(RoutingEvents\ResponsePrepared $event): void
     {
         $span = $this->popSpan();

test/Sentry/Features/DatabaseIntegrationTest.php

@@ -115,11 +115,46 @@ public function testSqlBindingsAreRecordedWhenDisabled(): void
         $this->assertFalse(isset($span->getData()['db.sql.bindings']));
     }
 
-    private function executeQueryAndRetrieveSpan(string $query, array $bindings = []): Span
+    public function testSqlOriginIsResolvedWhenEnabledAndOverTreshold(): void
+    {
+        $this->resetApplicationWithConfig([
+            'sentry.tracing.sql_origin' => true,
+            'sentry.tracing.sql_origin_threshold_ms' => 10,
+        ]);
+
+        $span = $this->executeQueryAndRetrieveSpan('SELECT 1', [], 20);
+
+        $this->assertArrayHasKey('code.filepath', $span->getData());
+    }
+
+    public function testSqlOriginIsNotResolvedWhenDisabled(): void
+    {
+        $this->resetApplicationWithConfig([
+            'sentry.tracing.sql_origin' => false,
+        ]);
+
+        $span = $this->executeQueryAndRetrieveSpan('SELECT 1');
+
+        $this->assertArrayNotHasKey('code.filepath', $span->getData());
+    }
+
+    public function testSqlOriginIsNotResolvedWhenUnderThreshold(): void
+    {
+        $this->resetApplicationWithConfig([
+            'sentry.tracing.sql_origin' => true,
+            'sentry.tracing.sql_origin_threshold_ms' => 10,
+        ]);
+
+        $span = $this->executeQueryAndRetrieveSpan('SELECT 1', [], 5);
+
+        $this->assertArrayNotHasKey('code.filepath', $span->getData());
+    }
+
+    private function executeQueryAndRetrieveSpan(string $query, array $bindings = [], int $time = 123): Span
     {
         $transaction = $this->startTransaction();
 
-        $this->dispatchLaravelEvent(new QueryExecuted($query, $bindings, 123, DB::connection()));
+        $this->dispatchLaravelEvent(new QueryExecuted($query, $bindings, $time, DB::connection()));
 
         $spans = $transaction->getSpanRecorder()->getSpans();