Merge pull request #52 from scoutapp/47-fixing-order-of-events

#47 - fixing order of events
scoutapp · Sep 6, 2019 · 73c6cd1 · 73c6cd1
2 parents b62af81 + a0e4e29
commit 73c6cd1
Show file tree

Hide file tree

Showing 8 changed files with 164 additions and 81 deletions.
diff --git a/src/Agent.php b/src/Agent.php
@@ -147,7 +147,7 @@ public function startSpan(string $operation, ?float $overrideTimestamp = null) :
         if ($this->request === null) {
             // Must return a Span object to match API. This is a dummy span
             // that is not ever used for anything.
-            return new Span('Ignored', RequestId::new());
+            return new Span(new Request(), 'Ignored', RequestId::new());
         }
 
         return $this->request->startSpan($operation, $overrideTimestamp);

diff --git a/src/Connector/CommandWithChildren.php b/src/Connector/CommandWithChildren.php
@@ -0,0 +1,10 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Scoutapm\Connector;
+
+interface CommandWithChildren extends Command
+{
+    public function appendChild(Command $command) : void;
+}
diff --git a/src/Connector/CommandWithParent.php b/src/Connector/CommandWithParent.php
@@ -0,0 +1,10 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Scoutapm\Connector;
+
+interface CommandWithParent extends Command
+{
+    public function parent() : CommandWithChildren;
+}
diff --git a/src/Events/Request/Request.php b/src/Events/Request/Request.php
@@ -6,26 +6,26 @@
 
 use Exception;
 use Scoutapm\Connector\Command;
-use Scoutapm\Events\Exception\SpanHasNotBeenStarted;
+use Scoutapm\Connector\CommandWithChildren;
 use Scoutapm\Events\Span\Span;
 use Scoutapm\Events\Tag\TagRequest;
 use Scoutapm\Helper\Backtrace;
 use Scoutapm\Helper\Timer;
-use function array_pop;
 use function array_slice;
-use function end;
 
 /** @internal */
-class Request implements Command
+class Request implements CommandWithChildren
 {
+    private const STACK_TRACE_THRESHOLD_SECONDS = 0.5;
+
     /** @var Timer */
     private $timer;
 
-    /** @var TagRequest[]|Span[]|array<int, (TagRequest|Span)> */
-    private $events = [];
+    /** @var Command[]|array<int, Command> */
+    private $children = [];
 
-    /** @var Span[]|array<int, Span> */
-    private $openSpans = [];
+    /** @var CommandWithChildren */
+    private $currentCommand;
 
     /** @var RequestId */
     private $id;
@@ -36,62 +36,64 @@ public function __construct()
         $this->id = RequestId::new();
 
         $this->timer = new Timer();
+
+        $this->currentCommand = $this;
     }
 
-    public function stop() : void
+    public function stop(?float $overrideTimestamp = null) : void
     {
-        $this->timer->stop();
+        $this->timer->stop($overrideTimestamp);
     }
 
     /** @throws Exception */
     public function startSpan(string $operation, ?float $overrideTimestamp = null) : Span
     {
-        $span = new Span($operation, $this->id, $overrideTimestamp);
+        $span = new Span($this->currentCommand, $operation, $this->id, $overrideTimestamp);
 
-        $parent = end($this->openSpans);
-        // Automatically wire up the parent of this span
-        if ($parent instanceof Span) {
-            $span->setParentId($parent->id());
-        }
+        $this->currentCommand->appendChild($span);
 
-        $this->openSpans[] = $span;
+        $this->currentCommand = $span;
 
         return $span;
     }
 
+    public function appendChild(Command $span) : void
+    {
+        $this->children[] = $span;
+    }
+
     /**
      * Stop the currently "running" span.
      * You can still tag it if needed up until the request as a whole is finished.
-     *
-     * @throws SpanHasNotBeenStarted
      */
     public function stopSpan(?float $overrideTimestamp = null) : void
     {
-        /** @var Span|null $span */
-        $span = array_pop($this->openSpans);
+        $command = $this->currentCommand;
+        if (! $command instanceof Span) {
+            $this->stop($overrideTimestamp);
 
-        if ($span === null) {
-            throw SpanHasNotBeenStarted::fromRequest($this->id);
+            return;
         }
 
-        $span->stop($overrideTimestamp);
+        $command->stop($overrideTimestamp);
 
-        $threshold = 0.5;
-        if ($span->duration() > $threshold) {
+        if ($command->duration() > self::STACK_TRACE_THRESHOLD_SECONDS) {
             $stack = Backtrace::capture();
             $stack = array_slice($stack, 4);
-            $span->tag('stack', $stack);
+            $command->tag('stack', $stack);
         }
 
-        $this->events[] = $span;
+        $this->currentCommand = $command->parent();
     }
 
     /**
      * Add a tag to the request as a whole
+     *
+     * @param mixed $value
      */
-    public function tag(string $tagName, string $value) : void
+    public function tag(string $tagName, $value) : void
     {
-        $this->events[] = new TagRequest($tagName, $value, $this->id);
+        $this->appendChild(new TagRequest($tagName, $value, $this->id));
     }
 
     /**
@@ -109,8 +111,8 @@ public function jsonSerialize() : array
             ],
         ];
 
-        foreach ($this->events as $event) {
-            foreach ($event->jsonSerialize() as $value) {
+        foreach ($this->children as $child) {
+            foreach ($child->jsonSerialize() as $value) {
                 $commands[] = $value;
             }
         }
@@ -131,10 +133,15 @@ public function jsonSerialize() : array
      * You probably don't need this, it's used in testing.
      * Returns all events that have occurred in this Request.
      *
-     * @return TagRequest[]|Span[]|array<int, (TagRequest|Span)>
+     * @internal
+     * @deprecated
+     *
+     * @return Command[]|array<int, Command>
+     *
+     * @todo remove
      */
     public function getEvents() : array
     {
-        return $this->events;
+        return $this->children;
     }
 }
diff --git a/src/Events/Span/Span.php b/src/Events/Span/Span.php
@@ -6,41 +6,44 @@
 
 use Exception;
 use Scoutapm\Connector\Command;
+use Scoutapm\Connector\CommandWithChildren;
+use Scoutapm\Connector\CommandWithParent;
 use Scoutapm\Events\Request\RequestId;
 use Scoutapm\Events\Tag\TagSpan;
 use Scoutapm\Helper\Timer;
+use function array_filter;
 
 /** @internal */
-class Span implements Command
+class Span implements CommandWithParent, CommandWithChildren
 {
     /** @var SpanId */
     private $id;
 
     /** @var RequestId */
     private $requestId;
 
-    /** @var SpanId|null */
-    private $parentId;
+    /** @var CommandWithChildren */
+    private $parent;
+
+    /** @var Command[]|array<int, Command> */
+    private $children = [];
 
     /** @var string */
     private $name;
 
     /** @var Timer */
     private $timer;
 
-    /** @var TagSpan[]|array<int, TagSpan> */
-    private $tags;
-
     /** @throws Exception */
-    public function __construct(string $name, RequestId $requestId, ?float $override = null)
+    public function __construct(CommandWithChildren $parent, string $name, RequestId $requestId, ?float $override = null)
     {
         $this->id = SpanId::new();
 
+        $this->parent = $parent;
+
         $this->name      = $name;
         $this->requestId = $requestId;
 
-        $this->tags = [];
-
         $this->timer = new Timer($override);
     }
 
@@ -49,6 +52,11 @@ public function id() : SpanId
         return $this->id;
     }
 
+    public function parent() : CommandWithChildren
+    {
+        return $this->parent;
+    }
+
     /**
      * Do not call this directly - use Request#stopSpan() or Agent#stopSpan() to correctly handle bookkeeping
      *
@@ -68,15 +76,15 @@ public function updateName(string $name) : void
         $this->name = $name;
     }
 
-    /** @param mixed $value */
-    public function tag(string $tag, $value) : void
+    public function appendChild(Command $command) : void
     {
-        $this->tags[] = new TagSpan($tag, $value, $this->requestId, $this->id);
+        $this->children[] = $command;
     }
 
-    public function setParentId(SpanId $parentId) : void
+    /** @param mixed $value */
+    public function tag(string $tag, $value) : void
     {
-        $this->parentId = $parentId;
+        $this->appendChild(new TagSpan($tag, $value, $this->requestId, $this->id));
     }
 
     public function getName() : string
@@ -99,10 +107,22 @@ public function duration() : ?float
         return $this->timer->duration();
     }
 
-    /** @return TagSpan[]|array<int, TagSpan> */
+    /**
+     * @internal
+     * @deprecated
+     *
+     * @return TagSpan[]|array<int, TagSpan>
+     *
+     * @todo remove - only used in tests
+     */
     public function getTags() : array
     {
-        return $this->tags;
+        return array_filter(
+            $this->children,
+            static function ($item) {
+                return $item instanceof TagSpan;
+            }
+        );
     }
 
     /** @return array<int, array<string, (string|array|bool|null)>> */
@@ -113,14 +133,14 @@ public function jsonSerialize() : array
             'StartSpan' => [
                 'request_id' => $this->requestId->toString(),
                 'span_id' => $this->id->toString(),
-                'parent_id' => $this->parentId ? $this->parentId->toString() : null,
+                'parent_id' => $this->parent instanceof self ? $this->parent->id->toString() : null,
                 'operation' => $this->name,
                 'timestamp' => $this->getStartTime(),
             ],
         ];
 
-        foreach ($this->tags as $tag) {
-            foreach ($tag->jsonSerialize() as $value) {
+        foreach ($this->children as $child) {
+            foreach ($child->jsonSerialize() as $value) {
                 $commands[] = $value;
             }
         }

diff --git a/src/Events/Tag/Tag.php b/src/Events/Tag/Tag.php
@@ -4,11 +4,12 @@
 
 namespace Scoutapm\Events\Tag;
 
+use Scoutapm\Connector\Command;
 use Scoutapm\Events\Request\RequestId;
 use function microtime;
 
 /** @internal */
-abstract class Tag
+abstract class Tag implements Command
 {
     /** @var RequestId */
     protected $requestId;