Implementation of optional sentry tracing with twig

rjd22 · rjd22 · commit b5bd18ab773f · 2021-02-21T11:54:52.000+01:00
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -2,6 +2,7 @@
 
 ## Unreleased
 
+- Add support for distributed tracing of Twig template rendering (#430)
 - Add support for distributed tracing of SQL queries while using Doctrine DBAL (#426)
 - Added missing `capture-soft-fails` config schema option (#417)
 - Deprecate the `Sentry\SentryBundle\EventListener\ConsoleCommandListener` class in favor of its parent class `Sentry\SentryBundle\EventListener\ConsoleListener` (#429)
diff --git a/composer.json b/composer.json
@@ -50,12 +50,14 @@
         "symfony/monolog-bundle": "^3.4",
         "symfony/phpunit-bridge": "^5.0",
         "symfony/polyfill-php80": "^1.22",
+        "symfony/twig-bundle": "^3.4.44||^4.4.12||^5.0.11",
         "symfony/yaml": "^3.4.44||^4.4.11||^5.0.11",
         "vimeo/psalm": "^4.3"
     },
     "suggest": {
         "monolog/monolog": "Allow sending log messages to Sentry by using the included Monolog handler.",
-        "doctrine/doctrine-bundle": "Allow distributed tracing of database queries using Sentry."
+        "doctrine/doctrine-bundle": "Allow distributed tracing of database queries using Sentry.",
+        "symfony/twig-bundle": "Allow distributed tracing of twig template rendering using Sentry."
     },
     "autoload": {
         "files": [
diff --git a/src/DependencyInjection/Configuration.php b/src/DependencyInjection/Configuration.php
@@ -163,6 +163,9 @@ private function addDistributedTracingSection(ArrayNodeDefinition $rootNode): vo
                                 ->end()
                             ->end()
                         ->end()
+                        ->arrayNode('twig')
+                            ->canBeEnabled()
+                        ->end()
                     ->end()
                 ->end()
             ->end();
diff --git a/src/DependencyInjection/SentryExtension.php b/src/DependencyInjection/SentryExtension.php
@@ -16,6 +16,7 @@
 use Sentry\Options;
 use Sentry\SentryBundle\EventListener\ErrorListener;
 use Sentry\SentryBundle\EventListener\MessengerListener;
+use Sentry\SentryBundle\Tracing\Twig\TwigTracingExtension;
 use Sentry\SentryBundle\SentryBundle;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\ConnectionConfigurator;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\TracingDriverMiddleware;
@@ -62,6 +63,7 @@ protected function loadInternal(array $mergedConfig, ContainerBuilder $container
         $this->registerErrorListenerConfiguration($container, $mergedConfig);
         $this->registerMessengerListenerConfiguration($container, $mergedConfig['messenger']);
         $this->registerTracingConfiguration($container, $mergedConfig['tracing']);
+        $this->registerTracingTwigExtensionConfiguration($container, $mergedConfig['tracing']);
     }
 
     /**
@@ -173,6 +175,18 @@ private function registerTracingConfiguration(ContainerBuilder $container, array
         }
     }
 
+    /**
+     * @param array<string, mixed> $config
+     */
+    private function registerTracingTwigExtensionConfiguration(ContainerBuilder $container, array $config): void
+    {
+        $isConfigEnabled = $this->isConfigEnabled($container, $config['twig']);
+
+        if (!$isConfigEnabled) {
+            $container->removeDefinition(TwigTracingExtension::class);
+        }
+    }
+
     /**
      * @param string[]             $integrations
      * @param array<string, mixed> $config
diff --git a/src/Resources/config/schema/sentry-1.0.xsd b/src/Resources/config/schema/sentry-1.0.xsd
@@ -84,6 +84,7 @@
     <xsd:complexType name="tracing">
         <xsd:choice maxOccurs="unbounded">
             <xsd:element name="dbal" type="tracing-dbal" minOccurs="0" maxOccurs="1" />
+            <xsd:element name="twig" type="tracing-twig" minOccurs="0" maxOccurs="1" />
         </xsd:choice>
     </xsd:complexType>
 
@@ -94,4 +95,7 @@
 
         <xsd:attribute name="enabled" type="xsd:boolean" />
     </xsd:complexType>
+    <xsd:complexType name="tracing-twig">
+        <xsd:attribute name="enabled" type="xsd:boolean" />
+    </xsd:complexType>
 </xsd:schema>
diff --git a/src/Resources/config/services.xml b/src/Resources/config/services.xml
@@ -73,6 +73,11 @@
             <argument type="service" id="Sentry\SentryBundle\Tracing\Doctrine\DBAL\TracingDriverMiddleware" />
         </service>
 
+        <service id="Sentry\SentryBundle\Tracing\Twig\TwigTracingExtension" class="Sentry\SentryBundle\Tracing\Twig\TwigTracingExtension">
+            <argument type="service" id="Sentry\State\HubInterface" />
+            <tag name="twig.extension" />
+        </service>
+
         <service id="Sentry\Integration\RequestFetcherInterface" class="Sentry\SentryBundle\Integration\RequestFetcher">
             <argument type="service" id="Symfony\Component\HttpFoundation\RequestStack" />
             <argument type="service" id="Symfony\Bridge\PsrHttpMessage\HttpMessageFactoryInterface" on-invalid="null" />
diff --git a/src/Tracing/Twig/TwigTracingExtension.php b/src/Tracing/Twig/TwigTracingExtension.php
@@ -0,0 +1,70 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Sentry\SentryBundle\Tracing\Twig;
+
+use Sentry\State\HubInterface;
+use Sentry\Tracing\SpanContext;
+use SplObjectStorage;
+use Twig\Extension\AbstractExtension;
+use Twig\Profiler\NodeVisitor\ProfilerNodeVisitor;
+use Twig\Profiler\Profile;
+
+final class TwigTracingExtension extends AbstractExtension
+{
+    /**
+     * @var HubInterface The current hub
+     */
+    private $hub;
+
+    /**
+     * @var SplObjectStorage<object, \Sentry\Tracing\Span>
+     */
+    private $events;
+
+    /**
+     * @param HubInterface $hub The current hub
+     */
+    public function __construct(HubInterface $hub)
+    {
+        $this->hub = $hub;
+        $this->events = new SplObjectStorage();
+    }
+
+    /**
+     * @param Profile $profile
+     */
+    public function enter(Profile $profile): void
+    {
+        $transaction = $this->hub->getTransaction();
+
+        if (null === $transaction || !$profile->isTemplate()) {
+            return;
+        }
+
+        $spanContext = new SpanContext();
+        $spanContext->setOp('twig.template');
+        $spanContext->setDescription($profile->getName());
+
+        $this->events[$profile] = $transaction->startChild($spanContext);
+    }
+
+    /**
+     * @param Profile $profile
+     */
+    public function leave(Profile $profile): void
+    {
+        if (empty($this->events[$profile]) || !$profile->isTemplate()) {
+            return;
+        }
+
+        $this->events[$profile]->finish();
+        unset($this->events[$profile]);
+    }
+
+    public function getNodeVisitors(): array
+    {
+        return [new ProfilerNodeVisitor(static::class)];
+    }
+}
diff --git a/src/aliases.php b/src/aliases.php
@@ -14,6 +14,8 @@
 use Sentry\SentryBundle\EventListener\ErrorListenerExceptionEvent;
 use Sentry\SentryBundle\EventListener\RequestListenerControllerEvent;
 use Sentry\SentryBundle\EventListener\RequestListenerRequestEvent;
+use Sentry\SentryBundle\EventListener\RequestListenerResponseEvent;
+use Sentry\SentryBundle\EventListener\RequestListenerTerminateEvent;
 use Sentry\SentryBundle\EventListener\SubRequestListenerRequestEvent;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\Compatibility\DriverInterface;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\Compatibility\ExceptionConverterDriverInterface;
diff --git a/tests/DependencyInjection/ConfigurationTest.php b/tests/DependencyInjection/ConfigurationTest.php
@@ -41,6 +41,9 @@ public function testProcessConfigurationWithDefaultConfiguration(): void
                     'enabled' => false,
                     'connections' => class_exists(DoctrineBundle::class) ? ['%doctrine.default_connection%'] : [],
                 ],
+                'twig' => [
+                    'enabled' => false,
+                ],
             ],
         ];
 
diff --git a/tests/DependencyInjection/Fixtures/php/full.php b/tests/DependencyInjection/Fixtures/php/full.php
@@ -47,5 +47,8 @@
             'enabled' => false,
             'connections' => ['default'],
         ],
+        'twig' => [
+            'enabled' => false
+        ],
     ],
 ]);
diff --git a/tests/DependencyInjection/Fixtures/php/twig_tracing_enabled.php b/tests/DependencyInjection/Fixtures/php/twig_tracing_enabled.php
@@ -0,0 +1,14 @@
+<?php
+
+declare(strict_types=1);
+
+use Symfony\Component\DependencyInjection\ContainerBuilder;
+
+/** @var ContainerBuilder $container */
+$container->loadFromExtension('sentry', [
+    'tracing' => [
+        'twig' => [
+            'enabled' => true
+        ],
+    ],
+]);
diff --git a/tests/DependencyInjection/Fixtures/xml/full.xml b/tests/DependencyInjection/Fixtures/xml/full.xml
@@ -41,6 +41,7 @@
             <sentry:dbal enabled="false">
                 <sentry:connection>default</sentry:connection>
             </sentry:dbal>
+            <sentry:twig enabled="false" />
         </sentry:tracing>
     </sentry:config>
 </container>
diff --git a/tests/DependencyInjection/Fixtures/xml/twig_tracing_enabled.xml b/tests/DependencyInjection/Fixtures/xml/twig_tracing_enabled.xml
@@ -0,0 +1,14 @@
+<?xml version="1.0" ?>
+
+<container xmlns="http://symfony.com/schema/dic/services"
+           xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+           xmlns:sentry="https://sentry.io/schema/dic/sentry-symfony"
+           xsi:schemaLocation="http://symfony.com/schema/dic/services https://symfony.com/schema/dic/services/services-1.0.xsd
+                               https://sentry.io/schema/dic/sentry-symfony https://sentry.io/schema/dic/sentry-symfony/sentry-1.0.xsd">
+
+    <sentry:config>
+        <sentry:tracing>
+            <sentry:twig enabled="true" />
+        </sentry:tracing>
+    </sentry:config>
+</container>
diff --git a/tests/DependencyInjection/Fixtures/yml/full.yml b/tests/DependencyInjection/Fixtures/yml/full.yml
@@ -42,3 +42,5 @@ sentry:
             enabled: false
             connections:
                 - enabled
+        twig:
+            enabled: false
diff --git a/tests/DependencyInjection/Fixtures/yml/twig_tracing_enabled.yml b/tests/DependencyInjection/Fixtures/yml/twig_tracing_enabled.yml
@@ -0,0 +1,4 @@
+sentry:
+    tracing:
+        twig:
+            enabled: true
diff --git a/tests/DependencyInjection/SentryExtensionTest.php b/tests/DependencyInjection/SentryExtensionTest.php
@@ -19,6 +19,7 @@
 use Sentry\SentryBundle\SentryBundle;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\ConnectionConfigurator;
 use Sentry\SentryBundle\Tracing\Doctrine\DBAL\TracingDriverMiddleware;
+use Sentry\SentryBundle\Tracing\Twig\TwigTracingExtension;
 use Sentry\Serializer\RepresentationSerializer;
 use Sentry\Serializer\Serializer;
 use Sentry\Transport\TransportFactoryInterface;
@@ -286,6 +287,20 @@ public function testTracingDriverMiddlewareIsRemovedWhenDbalTracingIsDisabled():
         $this->assertEmpty($container->getParameter('sentry.tracing.dbal.connections'));
     }
 
+    public function testTwigTracingExtensionIsConfiguredWhenTwigTracingIsEnabled(): void
+    {
+        $container = $this->createContainerFromFixture('twig_tracing_enabled');
+
+        $this->assertTrue($container->hasDefinition(TwigTracingExtension::class));
+    }
+
+    public function testTwigTracingExtensionIsRemovedWhenTwigTracingIsDisabled(): void
+    {
+        $container = $this->createContainerFromFixture('full');
+
+        $this->assertFalse($container->hasDefinition(TwigTracingExtension::class));
+    }
+
     private function createContainerFromFixture(string $fixtureFile): ContainerBuilder
     {
         $container = new ContainerBuilder(new EnvPlaceholderParameterBag([
diff --git a/tests/Tracing/Twig/TwigTracingExtensionTest.php b/tests/Tracing/Twig/TwigTracingExtensionTest.php
@@ -0,0 +1,111 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Sentry\SentryBundle\Tests\Tracing\Twig;
+
+use PHPUnit\Framework\MockObject\MockObject;
+use PHPUnit\Framework\TestCase;
+use Sentry\SentryBundle\Tracing\Twig\TwigTracingExtension;
+use Sentry\State\HubInterface;
+use Sentry\Tracing\Transaction;
+use Sentry\Tracing\TransactionContext;
+use Twig\Profiler\Profile;
+
+final class TwigTracingExtensionTest extends TestCase
+{
+    /**
+     * @var MockObject&HubInterface
+     */
+    private $hub;
+
+    /**
+     * @var TwigTracingExtension
+     */
+    private $listener;
+
+    protected function setUp(): void
+    {
+        $this->hub = $this->createMock(HubInterface::class);
+        $this->listener = new TwigTracingExtension($this->hub);
+    }
+
+    public function testThatTwigEnterProfileIgnoresTracingWhenTransactionIsNotStarted(): void
+    {
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn(null);
+
+        $this->listener->enter(new Profile('main', Profile::TEMPLATE));
+    }
+
+    public function testThatTwigEnterProfileIgnoresTracingWhenNotATemplate(): void
+    {
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn(new Transaction(new TransactionContext()));
+
+        $this->listener->enter(new Profile('main', Profile::ROOT));
+    }
+
+    public function testThatTwigLeaveProfileIgnoresTracingWhenTransactionIsNotStarted(): void
+    {
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn(null);
+
+        $profile = new Profile('main', Profile::TEMPLATE);
+
+        $this->listener->enter($profile);
+        $this->listener->leave($profile);
+    }
+
+    public function testThatTwigLeaveProfileIgnoresTracingWhenNotATemplate(): void
+    {
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn(new Transaction(new TransactionContext()));
+
+        $profile = new Profile('main', Profile::ROOT);
+
+        $this->listener->enter($profile);
+        $this->listener->leave($profile);
+    }
+
+    public function testThatTwigEnterProfileAttachesAChildSpanWhenTransactionStarted(): void
+    {
+        $transaction = new Transaction(new TransactionContext());
+        $transaction->initSpanRecorder();
+
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn($transaction);
+
+        $this->listener->enter(new Profile('main', Profile::TEMPLATE));
+
+        $spans = $transaction->getSpanRecorder()->getSpans();
+
+        $this->assertCount(2, $spans);
+        $this->assertNull($spans[1]->getEndTimestamp());
+    }
+
+    public function testThatTwigLeaveProfileFinishesTheChildSpanWhenChildSpanStarted(): void
+    {
+        $transaction = new Transaction(new TransactionContext());
+        $transaction->initSpanRecorder();
+
+        $this->hub->expects($this->once())
+            ->method('getTransaction')
+            ->willReturn($transaction);
+
+        $profile = new Profile('main', Profile::TEMPLATE);
+
+        $this->listener->enter($profile);
+        $this->listener->leave($profile);
+
+        $spans = $transaction->getSpanRecorder()->getSpans();
+
+        $this->assertCount(2, $spans);
+        $this->assertNotNull($spans[1]->getEndTimestamp());
+    }
+}
