Add Laravel Octane support, fixes #479 (#495)

Co-authored-by: Alex Bouma <[email protected]>

Author: tm1000

CHANGELOG.md

@@ -2,6 +2,7 @@
 
 ## Unreleased
 
+- Add support for Laravel Octane (#495)
 - Fix bug in Sentry log channel handler checking an undefined variable resulting in an error (#515)
 - Add `action_level` configuration option for Sentry log channel which configures a Monolog `FingersCrossedHandler` (#516)
 

src/Sentry/Laravel/EventHandler.php

@@ -17,6 +17,7 @@
 use Illuminate\Queue\Events\JobProcessing;
 use Illuminate\Queue\Events\WorkerStopping;
 use Illuminate\Queue\QueueManager;
+use Laravel\Octane\Events as Octane;
 use Illuminate\Routing\Events\RouteMatched;
 use Illuminate\Routing\Route;
 use RuntimeException;
@@ -32,13 +33,13 @@ class EventHandler
      * @var array
      */
     protected static $eventHandlerMap = [
-        'router.matched' => 'routerMatched',                         // Until Laravel 5.1
+        'router.matched'                         => 'routerMatched',                         // Until Laravel 5.1
         'Illuminate\Routing\Events\RouteMatched' => 'routeMatched',  // Since Laravel 5.2
 
-        'illuminate.query' => 'query',                                 // Until Laravel 5.1
+        'illuminate.query'                         => 'query',                                 // Until Laravel 5.1
         'Illuminate\Database\Events\QueryExecuted' => 'queryExecuted', // Since Laravel 5.2
 
-        'illuminate.log' => 'log',                                // Until Laravel 5.3
+        'illuminate.log'                      => 'log',                                // Until Laravel 5.3
         'Illuminate\Log\Events\MessageLogged' => 'messageLogged', // Since Laravel 5.4
 
         'Illuminate\Console\Events\CommandStarting' => 'commandStarting', // Since Laravel 5.5
@@ -60,10 +61,29 @@ class EventHandler
      * @var array
      */
     protected static $queueEventHandlerMap = [
-        'Illuminate\Queue\Events\JobProcessing' => 'queueJobProcessing', // Since Laravel 5.2
-        'Illuminate\Queue\Events\JobProcessed' => 'queueJobProcessed', // Since Laravel 5.2
+        'Illuminate\Queue\Events\JobProcessing'        => 'queueJobProcessing',        // Since Laravel 5.2
+        'Illuminate\Queue\Events\JobProcessed'         => 'queueJobProcessed',         // Since Laravel 5.2
         'Illuminate\Queue\Events\JobExceptionOccurred' => 'queueJobExceptionOccurred', // Since Laravel 5.2
-        'Illuminate\Queue\Events\WorkerStopping' => 'queueWorkerStopping', // Since Laravel 5.2
+        'Illuminate\Queue\Events\WorkerStopping'       => 'queueWorkerStopping',       // Since Laravel 5.2
+    ];
+
+    /**
+     * Map Octane event handlers to events.
+     *
+     * @var array
+     */
+    protected static $octaneEventHandlerMap = [
+        'Laravel\Octane\Events\RequestReceived'   => 'octaneRequestReceived',
+        'Laravel\Octane\Events\RequestTerminated' => 'octaneRequestTerminated',
+
+        'Laravel\Octane\Events\TaskReceived'   => 'octaneTaskReceived',
+        'Laravel\Octane\Events\TaskTerminated' => 'octaneTaskTerminated',
+
+        'Laravel\Octane\Events\TickReceived'   => 'octaneTickReceived',
+        'Laravel\Octane\Events\TickTerminated' => 'octaneTickTerminated',
+
+        'Laravel\Octane\Events\WorkerErrorOccurred' => 'octaneWorkerErrorOccurred',
+        'Laravel\Octane\Events\WorkerStopping'      => 'octaneWorkerStopping',
     ];
 
     /**
@@ -108,13 +128,34 @@ class EventHandler
      */
     private $recordCommandInfo;
 
+    /**
+     * Indicates if we should we add tick info to the breadcrumbs.
+     *
+     * @var bool
+     */
+    private $recordOctaneTickInfo;
+
+    /**
+     * Indicates if we should we add task info to the breadcrumbs.
+     *
+     * @var bool
+     */
+    private $recordOctaneTaskInfo;
+
     /**
      * Indicates if we pushed a scope for the queue.
      *
      * @var bool
      */
     private $pushedQueueScope = false;
 
+    /**
+     * Indicates if we pushed a scope for Octane.
+     *
+     * @var bool
+     */
+    private $pushedOctaneScope = false;
+
     /**
      * EventHandler constructor.
      *
@@ -125,11 +166,13 @@ public function __construct(Container $container, array $config)
     {
         $this->container = $container;
 
-        $this->recordSqlQueries = ($config['breadcrumbs.sql_queries'] ?? $config['breadcrumbs']['sql_queries'] ?? true) === true;
-        $this->recordSqlBindings = ($config['breadcrumbs.sql_bindings'] ?? $config['breadcrumbs']['sql_bindings'] ?? false) === true;
-        $this->recordLaravelLogs = ($config['breadcrumbs.logs'] ?? $config['breadcrumbs']['logs'] ?? true) === true;
-        $this->recordQueueInfo = ($config['breadcrumbs.queue_info'] ?? $config['breadcrumbs']['queue_info'] ?? true) === true;
-        $this->recordCommandInfo = ($config['breadcrumbs.command_info'] ?? $config['breadcrumbs']['command_info'] ?? true) === true;
+        $this->recordSqlQueries     = ($config['breadcrumbs.sql_queries'] ?? $config['breadcrumbs']['sql_queries'] ?? true) === true;
+        $this->recordSqlBindings    = ($config['breadcrumbs.sql_bindings'] ?? $config['breadcrumbs']['sql_bindings'] ?? false) === true;
+        $this->recordLaravelLogs    = ($config['breadcrumbs.logs'] ?? $config['breadcrumbs']['logs'] ?? true) === true;
+        $this->recordQueueInfo      = ($config['breadcrumbs.queue_info'] ?? $config['breadcrumbs']['queue_info'] ?? true) === true;
+        $this->recordCommandInfo    = ($config['breadcrumbs.command_info'] ?? $config['breadcrumbs']['command_info'] ?? true) === true;
+        $this->recordOctaneTickInfo = ($config['breadcrumbs.octane_tick_info'] ?? $config['breadcrumbs']['octane_tick_info'] ?? true) === true;
+        $this->recordOctaneTaskInfo = ($config['breadcrumbs.octane_task_info'] ?? $config['breadcrumbs']['octane_task_info'] ?? true) === true;
     }
 
     /**
@@ -166,6 +209,23 @@ public function subscribeAuthEvents(): void
         }
     }
 
+    /**
+     * Attach all queue event handlers.
+     */
+    public function subscribeOctaneEvents(): void
+    {
+        /** @var \Illuminate\Contracts\Events\Dispatcher $dispatcher */
+        try {
+            $dispatcher = $this->container->make(Dispatcher::class);
+
+            foreach (static::$octaneEventHandlerMap as $eventName => $handler) {
+                $dispatcher->listen($eventName, [$this, $handler]);
+            }
+        } catch (BindingResolutionException $e) {
+            // If we cannot resolve the event dispatcher we also cannot listen to events
+        }
+    }
+
     /**
      * Attach all queue event handlers.
      *
@@ -174,8 +234,9 @@ public function subscribeAuthEvents(): void
     public function subscribeQueueEvents(QueueManager $queue): void
     {
         $queue->looping(function () {
-            $this->cleanupScopeForQueuedJob();
-            $this->afterQueuedJob();
+            $this->cleanupScopeForTaskWithinLongRunningProcessWhen($this->pushedQueueScope);
+
+            $this->pushedQueueScope = false;
         });
 
         /** @var \Illuminate\Contracts\Events\Dispatcher $dispatcher */
@@ -351,33 +412,6 @@ private function addLogBreadcrumb(string $level, ?string $message, array $contex
         ));
     }
 
-    /**
-     * Translates common log levels to Sentry breadcrumb levels.
-     *
-     * @param string $level Log level. Maybe any standard.
-     *
-     * @return string Breadcrumb level.
-     */
-    protected function logLevelToBreadcrumbLevel(string $level): string
-    {
-        switch (strtolower($level)) {
-            case 'debug':
-                return Breadcrumb::LEVEL_DEBUG;
-            case 'warning':
-                return Breadcrumb::LEVEL_WARNING;
-            case 'error':
-                return Breadcrumb::LEVEL_ERROR;
-            case 'critical':
-            case 'alert':
-            case 'emergency':
-                return Breadcrumb::LEVEL_FATAL;
-            case 'info':
-            case 'notice':
-            default:
-                return Breadcrumb::LEVEL_INFO;
-        }
-    }
-
     /**
      * Since Laravel 5.3
      *
@@ -416,16 +450,20 @@ protected function authenticatedHandler(Authenticated $event)
      */
     protected function queueJobProcessingHandler(JobProcessing $event)
     {
-        $this->prepareScopeForQueuedJob();
+        $this->cleanupScopeForTaskWithinLongRunningProcessWhen($this->pushedQueueScope);
+
+        $this->prepareScopeForTaskWithinLongRunningProcess();
+
+        $this->pushedQueueScope = true;
 
         if (!$this->recordQueueInfo) {
             return;
         }
 
         $job = [
-            'job' => $event->job->getName(),
-            'queue' => $event->job->getQueue(),
-            'attempts' => $event->job->attempts(),
+            'job'        => $event->job->getName(),
+            'queue'      => $event->job->getQueue(),
+            'attempts'   => $event->job->attempts(),
             'connection' => $event->connectionName,
         ];
 
@@ -450,7 +488,7 @@ protected function queueJobProcessingHandler(JobProcessing $event)
      */
     protected function queueJobExceptionOccurredHandler(JobExceptionOccurred $event)
     {
-        $this->afterQueuedJob();
+        $this->afterTaskWithinLongRunningProcess();
     }
 
     /**
@@ -460,7 +498,7 @@ protected function queueJobExceptionOccurredHandler(JobExceptionOccurred $event)
      */
     protected function queueJobProcessedHandler(JobProcessed $event)
     {
-        $this->afterQueuedJob();
+        $this->afterTaskWithinLongRunningProcess();
     }
 
     /**
@@ -531,34 +569,149 @@ protected function commandFinishedHandler(CommandFinished $event)
         Integration::flushEvents();
     }
 
-    private function afterQueuedJob(): void
+    protected function octaneRequestReceivedHandler(Octane\RequestReceived $event): void
+    {
+        $this->prepareScopeForOctane();
+    }
+
+    protected function octaneRequestTerminatedHandler(Octane\RequestTerminated $event): void
+    {
+        $this->cleanupScopeForOctane();
+    }
+
+    protected function octaneTaskReceivedHandler(Octane\TaskReceived $event): void
+    {
+        $this->prepareScopeForOctane();
+
+        if (!$this->recordOctaneTaskInfo) {
+            return;
+        }
+
+        Integration::addBreadcrumb(new Breadcrumb(
+            Breadcrumb::LEVEL_INFO,
+            Breadcrumb::TYPE_DEFAULT,
+            'octane.task',
+            'Processing Octane task'
+        ));
+    }
+
+    protected function octaneTaskTerminatedHandler(Octane\TaskTerminated $event): void
+    {
+        $this->cleanupScopeForOctane();
+    }
+
+    protected function octaneTickReceivedHandler(Octane\TickReceived $event): void
+    {
+        $this->prepareScopeForOctane();
+
+        if (!$this->recordOctaneTickInfo) {
+            return;
+        }
+
+        Integration::addBreadcrumb(new Breadcrumb(
+            Breadcrumb::LEVEL_INFO,
+            Breadcrumb::TYPE_DEFAULT,
+            'octane.tick',
+            'Processing Octane tick'
+        ));
+    }
+
+    protected function octaneTickTerminatedHandler(Octane\TickTerminated $event): void
+    {
+        $this->cleanupScopeForOctane();
+    }
+
+    protected function octaneWorkerErrorOccurredHandler(Octane\WorkerErrorOccurred $event): void
+    {
+        $this->afterTaskWithinLongRunningProcess();
+    }
+
+    protected function octaneWorkerStoppingHandler(Octane\WorkerStopping $event): void
+    {
+        $this->afterTaskWithinLongRunningProcess();
+    }
+
+    private function prepareScopeForOctane(): void
+    {
+        $this->cleanupScopeForOctane();
+
+        $this->prepareScopeForTaskWithinLongRunningProcess();
+
+        $this->pushedOctaneScope = true;
+    }
+
+    private function cleanupScopeForOctane(): void
+    {
+        $this->cleanupScopeForTaskWithinLongRunningProcessWhen($this->pushedOctaneScope);
+
+        $this->pushedOctaneScope = false;
+    }
+
+    /**
+     * Translates common log levels to Sentry breadcrumb levels.
+     *
+     * @param string $level Log level. Maybe any standard.
+     *
+     * @return string Breadcrumb level.
+     */
+    private function logLevelToBreadcrumbLevel(string $level): string
+    {
+        switch (strtolower($level)) {
+            case 'debug':
+                return Breadcrumb::LEVEL_DEBUG;
+            case 'warning':
+                return Breadcrumb::LEVEL_WARNING;
+            case 'error':
+                return Breadcrumb::LEVEL_ERROR;
+            case 'critical':
+            case 'alert':
+            case 'emergency':
+                return Breadcrumb::LEVEL_FATAL;
+            case 'info':
+            case 'notice':
+            default:
+                return Breadcrumb::LEVEL_INFO;
+        }
+    }
+
+    /**
+     * Should be called after a task within a long running process has ended so events can be flushed.
+     */
+    private function afterTaskWithinLongRunningProcess(): void
     {
         // Flush any and all events that were possibly generated by queue jobs
         Integration::flushEvents();
     }
 
-    private function prepareScopeForQueuedJob(): void
+    /**
+     * Should be called before starting a task within a long running process, this is done to prevent
+     * the task to have effect on the scope for the next task to run within the long running process.
+     */
+    private function prepareScopeForTaskWithinLongRunningProcess(): void
     {
-        $this->cleanupScopeForQueuedJob();
-
         SentrySdk::getCurrentHub()->pushScope();
 
-        $this->pushedQueueScope = true;
-
         // When a job starts, we want to make sure the scope is cleared of breadcrumbs
         SentrySdk::getCurrentHub()->configureScope(static function (Scope $scope) {
             $scope->clearBreadcrumbs();
         });
     }
 
-    private function cleanupScopeForQueuedJob(): void
+    /**
+     * Cleanup a previously prepared scope.
+     *
+     * @param bool $when Only cleanup the scope when this is true.
+     *
+     * @see prepareScopeForTaskWithinLongRunningProcess
+     */
+    private function cleanupScopeForTaskWithinLongRunningProcessWhen(bool $when): void
     {
-        if (!$this->pushedQueueScope) {
+        if (!$when) {
             return;
         }
 
-        SentrySdk::getCurrentHub()->popScope();
+        $this->afterTaskWithinLongRunningProcess();
 
-        $this->pushedQueueScope = false;
+        SentrySdk::getCurrentHub()->popScope();
     }
 }