Merge pull request #91 from scoutapp/90-fix-missing-request-stop-time…

…stamp Fix missing request stop timestamp
scoutapp · Oct 10, 2019 · 76268bd · 76268bd
2 parents 6f48abd + 378b2c0
commit 76268bd
Show file tree

Hide file tree

Showing 4 changed files with 73 additions and 3 deletions.
diff --git a/src/Agent.php b/src/Agent.php
@@ -280,6 +280,8 @@ public function send() : bool
                 return false;
             }
 
+            $this->request->stopIfRunning();
+
             return $this->connector->sendCommand($this->request);
         } catch (NotConnected $notConnected) {
             $this->logger->error($notConnected->getMessage());

diff --git a/src/Events/Request/Request.php b/src/Events/Request/Request.php
@@ -39,6 +39,15 @@ public function __construct()
         $this->currentCommand = $this;
     }
 
+    public function stopIfRunning() : void
+    {
+        if ($this->timer->getStop() !== null) {
+            return;
+        }
+
+        $this->stop();
+    }
+
     public function stop(?float $overrideTimestamp = null) : void
     {
         $this->timer->stop($overrideTimestamp);

diff --git a/tests/Integration/AgentTest.php b/tests/Integration/AgentTest.php
@@ -4,6 +4,7 @@
 
 namespace Scoutapm\IntegrationTests;
 
+use DateTimeImmutable;
 use Exception;
 use PHPUnit\Framework\TestCase;
 use Psr\Log\Test\TestLogger;
@@ -12,6 +13,7 @@
 use Scoutapm\Config\ConfigKey;
 use Scoutapm\Connector\SocketConnector;
 use Scoutapm\Extension\PotentiallyAvailableExtensionCapabilities;
+use Scoutapm\Helper\Timer;
 use function file_get_contents;
 use function getenv;
 use function gethostname;
@@ -127,7 +129,14 @@ public function testLoggingIsSent() : void
             'BatchCommand',
             [
                 'commands' => function (array $commands) : bool {
-                    $requestId = $this->assertUnserializedCommandContainsPayload('StartRequest', [], reset($commands), 'request_id');
+                    $requestId = $this->assertUnserializedCommandContainsPayload(
+                        'StartRequest',
+                        [
+                            'timestamp' => [$this, 'assertValidTimestamp'],
+                        ],
+                        reset($commands),
+                        'request_id'
+                    );
 
                     $controllerSpanId = $this->assertUnserializedCommandContainsPayload('StartSpan', ['operation' => 'Controller/Yay'], next($commands), 'span_id');
 
@@ -176,7 +185,15 @@ public function testLoggingIsSent() : void
                     $quxSpanId = $this->assertUnserializedCommandContainsPayload('StartSpan', ['operation' => 'Test/qux'], next($commands), 'span_id');
                     $this->assertUnserializedCommandContainsPayload('StopSpan', ['span_id' => $quxSpanId], next($commands), null);
 
-                    $this->assertUnserializedCommandContainsPayload('FinishRequest', ['request_id' => $requestId], next($commands), null);
+                    $this->assertUnserializedCommandContainsPayload(
+                        'FinishRequest',
+                        [
+                            'request_id' => $requestId,
+                            'timestamp' => [$this, 'assertValidTimestamp'],
+                        ],
+                        next($commands),
+                        null
+                    );
 
                     return true;
                 },
@@ -186,6 +203,19 @@ public function testLoggingIsSent() : void
         );
     }
 
+    /** @noinspection PhpUnusedPrivateMethodInspection */
+    /** @throws Exception */
+    // phpcs:disable SlevomatCodingStandard.Classes.UnusedPrivateElements.UnusedMethod
+    private function assertValidTimestamp(?string $timestamp) : bool
+    {
+        self::assertNotNull($timestamp, 'Expected a non-null timestamp, but the timestamp was null');
+        self::assertSame($timestamp, (new DateTimeImmutable($timestamp))->format(Timer::FORMAT_FOR_CORE_AGENT));
+
+        return true;
+    }
+
+    // phpcs:enable
+
     /**
      * @param string[]|callable[]|array<string, (string|callable)>        $keysAndValuesToExpect
      * @param mixed[][]|array<string, array<string, (string|null|array)>> $actualCommand

diff --git a/tests/Unit/Events/Request/RequestTest.php b/tests/Unit/Events/Request/RequestTest.php
@@ -6,8 +6,11 @@
 
 use PHPUnit\Framework\TestCase;
 use Scoutapm\Events\Request\Request;
+use function json_decode;
+use function json_encode;
 use function next;
 use function reset;
+use function time;
 
 /** @covers \Scoutapm\Events\Request\Request */
 final class RequestTest extends TestCase
@@ -21,8 +24,34 @@ public function testCanBeInitialized() : void
     public function testCanBeStopped() : void
     {
         $request = new Request();
+
+        self::assertNull(json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp']);
+
         $request->stop();
-        self::assertNotNull($request);
+
+        self::assertIsString(json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp']);
+    }
+
+    public function testRequestIsStoppedIfRunning() : void
+    {
+        $request = new Request();
+
+        self::assertNull(json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp']);
+
+        $request->stopIfRunning();
+
+        self::assertIsString(json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp']);
+    }
+
+    public function testRequestFinishTimestampIsNotChangedWhenStopIfRunningIsCalledOnAStoppedRequest() : void
+    {
+        $request = new Request();
+        $request->stop(time() - 100.0);
+        $originalStopTime = json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp'];
+
+        $request->stopIfRunning();
+
+        self::assertSame($originalStopTime, json_decode(json_encode($request), true)['BatchCommand']['commands'][1]['FinishRequest']['timestamp']);
     }
 
     public function testJsonSerializes() : void