Rework logging processor a bit

composer · Jul 8, 2024 · ae0760e · ae0760e
1 parent f514661
commit ae0760e
Show file tree

Hide file tree

Showing 3 changed files with 53 additions and 17 deletions.
diff --git a/src/EventListener/RequestStatsListener.php b/src/EventListener/RequestStatsListener.php
@@ -12,6 +12,7 @@
 
 namespace App\EventListener;
 
+use App\Logger\LogIdProcessor;
 use Graze\DogStatsD\Client;
 use Monolog\Logger;
 use Monolog\LogRecord;
@@ -26,26 +27,25 @@ class RequestStatsListener
     public function __construct(
         private Client $statsd,
         private Logger $logger,
+        private LogIdProcessor $logIdProcessor,
     ) {
     }
 
-    #[AsEventListener]
+    #[AsEventListener(priority: 1000)]
     public function onRequest(RequestEvent $e): void
     {
         if (!$e->isMainRequest()) {
             return;
         }
         $this->pageTiming = microtime(true);
 
-        $reqId = bin2hex(random_bytes(6));
-        $this->logger->pushProcessor(static function (LogRecord $record) use ($reqId) {
-            $record->extra['req_id'] = $reqId;
-
-            return $record;
-        });
+        $this->logIdProcessor->startRequest();
+        if ($e->getRequest()->getContent() !== null) {
+            $this->logger->debug('Request content received', ['content' => substr($e->getRequest()->getContent(), 0, 10_000)]);
+        }
     }
 
-    #[AsEventListener]
+    #[AsEventListener(priority: -1000)]
     public function onResponse(ResponseEvent $e): void
     {
         if (!$e->isMainRequest()) {
@@ -56,7 +56,6 @@ public function onResponse(ResponseEvent $e): void
             return;
         }
 
-        $this->logger->popProcessor();
         $this->statsd->timing('app.response_time', (int) ((microtime(true) - $this->pageTiming) * 1000));
         $this->pageTiming = null;
 

diff --git a/src/Logger/LogIdProcessor.php b/src/Logger/LogIdProcessor.php
@@ -0,0 +1,41 @@
+<?php
+
+namespace App\Logger;
+
+use Monolog\LogRecord;
+use Monolog\Processor\ProcessorInterface;
+use Monolog\ResettableInterface;
+
+class LogIdProcessor implements ProcessorInterface, ResettableInterface
+{
+    private ?string $reqId = null;
+    private ?string $jobId = null;
+
+    public function startRequest(): void
+    {
+        $this->reqId = bin2hex(random_bytes(6));
+    }
+
+    public function startJob(string $id): void
+    {
+        $this->jobId = $id;
+    }
+
+    public function reset(): void
+    {
+        $this->reqId = null;
+        $this->jobId = null;
+    }
+
+    public function __invoke(LogRecord $record)
+    {
+        if ($this->jobId !== null) {
+            $record->extra['job_id'] = $this->jobId;
+        }
+        if ($this->reqId !== null) {
+            $record->extra['req_id'] = $this->reqId;
+        }
+
+        return $record;
+    }
+}
diff --git a/src/Service/QueueWorker.php b/src/Service/QueueWorker.php
@@ -12,6 +12,7 @@
 
 namespace App\Service;
 
+use App\Logger\LogIdProcessor;
 use Monolog\LogRecord;
 use Predis\Client as Redis;
 use Monolog\Logger;
@@ -34,7 +35,8 @@ public function __construct(
         private Logger $logger,
         /** @var array<string, UpdaterWorker|GitHubUserMigrationWorker|SecurityAdvisoryWorker> */
         private array $jobWorkers,
-        private StatsDClient $statsd
+        private StatsDClient $statsd,
+        private readonly LogIdProcessor $logIdProcessor,
     ) {
     }
 
@@ -112,11 +114,7 @@ private function process(string $jobId, SignalHandler $signal): bool
             throw new \LogicException('At this point a job should always be found');
         }
 
-        $this->logger->pushProcessor(static function (LogRecord $record) use ($job) {
-            $record->extra['job_id'] = $job->getId();
-
-            return $record;
-        });
+        $this->logIdProcessor->startJob($job->getId());
 
         $expectedStart = $job->getExecuteAfter() ?: $job->getCreatedAt();
         $start = microtime(true);
@@ -177,7 +175,6 @@ private function process(string $jobId, SignalHandler $signal): bool
             $em->flush();
 
             $this->logger->reset();
-            $this->logger->popProcessor();
 
             return true;
         }
@@ -206,7 +203,6 @@ private function process(string $jobId, SignalHandler $signal): bool
         }
 
         $this->logger->reset();
-        $this->logger->popProcessor();
 
         return true;
     }