resourceloader: Introduce metric for backend response timing

We currently have several counts and timings of individual pieces
of ResourceLoader backend logic (minification, module building, ..)
but no measure of the response overall.

This responseTime metric will effectively provide both a timing
measure as well as a backend request count.

Bug: T178350
Change-Id: I625a5eb90f5a4ea90aebf9292dfda0f1c5ae4f2e

diff --git a/includes/resourceloader/ResourceLoader.php b/includes/resourceloader/ResourceLoader.php
index c58bb00..b2e1c49 100644 (file)
--- a/includes/resourceloader/ResourceLoader.php
+++ b/includes/resourceloader/ResourceLoader.php
@@ -728,6 +728,8 @@ class ResourceLoader implements LoggerAwareInterface {
                // See https://bugs.php.net/bug.php?id=36514
                ob_start();
 
+               $this->measureResponseTime( RequestContext::getMain()->getTiming() );
+
                // Find out which modules are missing and instantiate the others
                $modules = [];
                $missing = [];
@@ -828,6 +830,16 @@ class ResourceLoader implements LoggerAwareInterface {
                echo $response;
        }
 
+       protected function measureResponseTime( Timing $timing ) {
+               DeferredUpdates::addCallableUpdate( function () use ( $timing ) {
+                       $measure = $timing->measure( 'responseTime', 'requestStart', 'requestShutdown' );
+                       if ( $measure !== false ) {
+                               $stats = MediaWikiServices::getInstance()->getStatsdDataFactory();
+                               $stats->timing( 'resourceloader.responseTime', $measure['duration'] * 1000 );
+                       }
+               } );
+       }
+
        /**
         * Send main response headers to the client.
         *

diff --git a/tests/phpunit/includes/resourceloader/ResourceLoaderTest.php b/tests/phpunit/includes/resourceloader/ResourceLoaderTest.php
index e9d022f..f45f8ae 100644 (file)
--- a/tests/phpunit/includes/resourceloader/ResourceLoaderTest.php
+++ b/tests/phpunit/includes/resourceloader/ResourceLoaderTest.php
@@ -869,4 +869,41 @@ mw.example();
                        'Extra headers'
                );
        }
+
+       /**
+        * @covers ResourceLoader::respond
+        */
+       public function testRespond() {
+               $rl = $this->getMockBuilder( EmptyResourceLoader::class )
+                       ->setMethods( [
+                               'tryRespondNotModified',
+                               'sendResponseHeaders',
+                               'measureResponseTime',
+                       ] )
+                       ->getMock();
+               $context = $this->getResourceLoaderContext( [ 'modules' => '' ], $rl );
+
+               $rl->expects( $this->once() )->method( 'measureResponseTime' );
+               $this->expectOutputRegex( '/no modules were requested/' );
+
+               $rl->respond( $context );
+       }
+
+       /**
+        * @covers ResourceLoader::measureResponseTime
+        */
+       public function testMeasureResponseTime() {
+               $stats = $this->getMockBuilder( NullStatsdDataFactory::class )
+                       ->setMethods( [ 'timing' ] )->getMock();
+               $this->setService( 'StatsdDataFactory', $stats );
+
+               $stats->expects( $this->once() )->method( 'timing' )
+                       ->with( 'resourceloader.responseTime', $this->anything() );
+
+               $timing = new Timing();
+               $timing->mark( 'requestShutdown' );
+               $rl = TestingAccessWrapper::newFromObject( new EmptyResourceLoader );
+               $rl->measureResponseTime( $timing );
+               DeferredUpdates::doUpdates();
+       }
 }