Improve tracing

CHANGELOG.md

@@ -2,6 +2,8 @@
 
 ## Unreleased
 
+- Improve performance tracing by nesting `view.render` spans and adding a `app.handle` span showing how long the actual application code runs after Laravel bootstrapping (#387)
+
 ## 2.0.0
 
 **Breaking Change**: This version uses the [envelope endpoint](https://develop.sentry.dev/sdk/envelopes/). If you are

composer.json

@@ -29,7 +29,8 @@
     "phpunit/phpunit": "^8.0",
     "laravel/framework": "^7.0",
     "orchestra/testbench": "^5.0",
-    "friendsofphp/php-cs-fixer": "2.16.*"
+    "friendsofphp/php-cs-fixer": "2.16.*",
+    "mockery/mockery": "1.3.*"
   },
   "autoload": {
     "psr-0": {

src/Sentry/Laravel/BaseServiceProvider.php

@@ -0,0 +1,39 @@
+<?php
+
+namespace Sentry\Laravel;
+
+use Illuminate\Support\ServiceProvider;
+
+abstract class BaseServiceProvider extends ServiceProvider
+{
+    /**
+     * Abstract type to bind Sentry as in the Service Container.
+     *
+     * @var string
+     */
+    public static $abstract = 'sentry';
+
+    /**
+     * Check if a DSN was set in the config.
+     *
+     * @return bool
+     */
+    protected function hasDsnSet(): bool
+    {
+        $config = $this->getUserConfig();
+
+        return !empty($config['dsn']);
+    }
+
+    /**
+     * Retrieve the user configuration.
+     *
+     * @return array
+     */
+    protected function getUserConfig(): array
+    {
+        $config = $this->app['config'][static::$abstract];
+
+        return empty($config) ? [] : $config;
+    }
+}

src/Sentry/Laravel/EventHandler.php

@@ -20,8 +20,6 @@
 use Sentry\Breadcrumb;
 use Sentry\SentrySdk;
 use Sentry\State\Scope;
-use Sentry\Tracing\SpanContext;
-use Sentry\Tracing\Transaction;
 
 class EventHandler
 {
@@ -197,16 +195,6 @@ protected function routerMatchedHandler(Route $route)
     {
         $routeName = Integration::extractNameForRoute($route) ?? '<unlabeled transaction>';
 
-        $transaction = SentrySdk::getCurrentHub()->getTransaction();
-
-        if ($transaction instanceof Transaction) {
-            $transaction->setName($routeName);
-            $transaction->setData([
-                'action' => $route->getActionName(),
-                'name' => $route->getName()
-            ]);
-        }
-
         Integration::addBreadcrumb(new Breadcrumb(
             Breadcrumb::LEVEL_INFO,
             Breadcrumb::TYPE_NAVIGATION,
@@ -278,16 +266,6 @@ private function addQueryBreadcrumb($query, $bindings, $time, $connectionName)
             $data['bindings'] = $bindings;
         }
 
-        $transaction = SentrySdk::getCurrentHub()->getTransaction();
-        if (null !== $transaction) {
-            $context = new SpanContext();
-            $context->setOp('sql.query');
-            $context->setDescription($query);
-            $context->setStartTimestamp(microtime(true) - $time / 1000);
-            $context->setEndTimestamp($context->getStartTimestamp() + $time / 1000);
-            $transaction->startChild($context);
-        }
-
         Integration::addBreadcrumb(new Breadcrumb(
             Breadcrumb::LEVEL_INFO,
             Breadcrumb::TYPE_DEFAULT,

src/Sentry/Laravel/PublishConfigCommand.php

@@ -63,7 +63,6 @@ public function setEnvironmentValue(array $values)
 
         if (count($values) > 0) {
             foreach ($values as $envKey => $envValue) {
-
                 $str .= "\n"; // In case the searched variable is in the last line without \n
                 $keyPosition = strpos($str, "{$envKey}=");
                 $endOfLinePosition = strpos($str, "\n", $keyPosition);
@@ -75,12 +74,13 @@ public function setEnvironmentValue(array $values)
                 } else {
                     $str = str_replace($oldLine, "{$envKey}={$envValue}", $str);
                 }
-
             }
         }
 
         $str = substr($str, 0, -1);
-        if (!file_put_contents($envFile, $str)) return false;
+        if (!file_put_contents($envFile, $str)) {
+            return false;
+        }
         return true;
     }
 }

src/Sentry/Laravel/ServiceProvider.php

@@ -2,7 +2,6 @@
 
 namespace Sentry\Laravel;
 
-use Illuminate\Contracts\Http\Kernel as HttpKernelInterface;
 use Sentry\SentrySdk;
 use Sentry\State\Hub;
 use Sentry\ClientBuilder;
@@ -12,18 +11,9 @@
 use Laravel\Lumen\Application as Lumen;
 use Sentry\Integration as SdkIntegration;
 use Illuminate\Foundation\Application as Laravel;
-use Illuminate\Support\ServiceProvider as IlluminateServiceProvider;
-use Illuminate\Support\Facades\Storage;
 
-class ServiceProvider extends IlluminateServiceProvider
+class ServiceProvider extends BaseServiceProvider
 {
-    /**
-     * Abstract type to bind Sentry as in the Service Container.
-     *
-     * @var string
-     */
-    public static $abstract = 'sentry';
-
     /**
      * Boot the service provider.
      */
@@ -182,18 +172,6 @@ protected function configureAndRegisterClient(): void
         $this->app->alias(static::$abstract, HubInterface::class);
     }
 
-    /**
-     * Check if a DSN was set in the config.
-     *
-     * @return bool
-     */
-    protected function hasDsnSet(): bool
-    {
-        $config = $this->getUserConfig();
-
-        return !empty($config['dsn']);
-    }
-
     /**
      * Resolve the integrations from the user configuration with the container.
      *
@@ -224,18 +202,6 @@ private function resolveIntegrationsFromUserConfig(): array
         return $integrations;
     }
 
-    /**
-     * Retrieve the user configuration.
-     *
-     * @return array
-     */
-    private function getUserConfig(): array
-    {
-        $config = $this->app['config'][static::$abstract];
-
-        return empty($config) ? [] : $config;
-    }
-
     /**
      * Get the services provided by the provider.
      *

src/Sentry/Laravel/Tracing/EventHandler.php

@@ -0,0 +1,157 @@
+<?php
+
+namespace Sentry\Laravel\Tracing;
+
+use Exception;
+use Illuminate\Contracts\Events\Dispatcher;
+use Illuminate\Database\Events\QueryExecuted;
+use Illuminate\Routing\Events\RouteMatched;
+use Illuminate\Routing\Route;
+use RuntimeException;
+use Sentry\Laravel\Integration;
+use Sentry\SentrySdk;
+use Sentry\Tracing\SpanContext;
+use Sentry\Tracing\Transaction;
+
+class EventHandler
+{
+    /**
+     * Map event handlers to events.
+     *
+     * @var array
+     */
+    protected static $eventHandlerMap = [
+        'router.matched'    => 'routerMatched',  // Until Laravel 5.1
+        RouteMatched::class => 'routeMatched',   // Since Laravel 5.2
+
+        'illuminate.query'   => 'query',         // Until Laravel 5.1
+        QueryExecuted::class => 'queryExecuted', // Since Laravel 5.2
+    ];
+
+    /**
+     * The Laravel event dispatcher.
+     *
+     * @var \Illuminate\Contracts\Events\Dispatcher
+     */
+    private $events;
+
+    /**
+     * EventHandler constructor.
+     *
+     * @param \Illuminate\Contracts\Events\Dispatcher $events
+     */
+    public function __construct(Dispatcher $events)
+    {
+        $this->events = $events;
+    }
+
+    /**
+     * Attach all event handlers.
+     */
+    public function subscribe(): void
+    {
+        foreach (static::$eventHandlerMap as $eventName => $handler) {
+            $this->events->listen($eventName, [$this, $handler]);
+        }
+    }
+
+    /**
+     * Pass through the event and capture any errors.
+     *
+     * @param string $method
+     * @param array  $arguments
+     */
+    public function __call($method, $arguments)
+    {
+        $handlerMethod = $handlerMethod = "{$method}Handler";
+
+        if (!method_exists($this, $handlerMethod)) {
+            throw new RuntimeException("Missing tracing event handler: {$handlerMethod}");
+        }
+
+        $parentSpan = Integration::currentTracingSpan();
+
+        // If there is no tracing span active there is no need to handle the event
+        if ($parentSpan === null) {
+            return;
+        }
+
+        try {
+            call_user_func_array([$this, $handlerMethod], $arguments);
+        } catch (Exception $exception) {
+            // Ignore
+        }
+    }
+
+    /**
+     * Until Laravel 5.1
+     *
+     * @param \Illuminate\Routing\Route $route
+     */
+    protected function routerMatchedHandler(Route $route): void
+    {
+        $transaction = SentrySdk::getCurrentHub()->getTransaction();
+
+        if ($transaction instanceof Transaction) {
+            $routeName = Integration::extractNameForRoute($route) ?? '<unlabeled transaction>';
+
+            $transaction->setName($routeName);
+            $transaction->setData([
+                'action' => $route->getActionName(),
+                'name'   => $route->getName(),
+            ]);
+        }
+    }
+
+    /**
+     * Since Laravel 5.2
+     *
+     * @param \Illuminate\Routing\Events\RouteMatched $match
+     */
+    protected function routeMatchedHandler(RouteMatched $match): void
+    {
+        $this->routerMatchedHandler($match->route);
+    }
+
+    /**
+     * Until Laravel 5.1
+     *
+     * @param string $query
+     * @param array  $bindings
+     * @param int    $time
+     * @param string $connectionName
+     */
+    protected function queryHandler($query, $bindings, $time, $connectionName): void
+    {
+        $this->recordQuerySpan($query, $time);
+    }
+
+    /**
+     * Since Laravel 5.2
+     *
+     * @param \Illuminate\Database\Events\QueryExecuted $query
+     */
+    protected function queryExecutedHandler(QueryExecuted $query): void
+    {
+        $this->recordQuerySpan($query->sql, $query->time);
+    }
+
+    /**
+     * Helper to add an query breadcrumb.
+     *
+     * @param string     $query
+     * @param float|null $time
+     */
+    private function recordQuerySpan($query, $time): void
+    {
+        $parentSpan = Integration::currentTracingSpan();
+
+        $context = new SpanContext();
+        $context->setOp('sql.query');
+        $context->setDescription($query);
+        $context->setStartTimestamp(microtime(true) - $time / 1000);
+        $context->setEndTimestamp($context->getStartTimestamp() + $time / 1000);
+
+        $parentSpan->startChild($context);
+    }
+}