Add Timing interface
authorOri Livneh <ori@wikimedia.org>
Tue, 3 Nov 2015 02:26:07 +0000 (18:26 -0800)
committerOri Livneh <ori@wikimedia.org>
Tue, 3 Nov 2015 23:05:37 +0000 (15:05 -0800)
* Add `Timing`, an interface which mimics the W3C User Timing API.
  It provides a canonical way to store and retrieve markers (timestamps)
  and measures (timestamps + duration).
* As the initial use-case, use it to record 'requestShutdown'.

Change-Id: I36b29162ffcc091406df025463b0e2797e52f19a

autoload.php
includes/MediaWiki.php
includes/context/ContextSource.php
includes/context/DerivativeContext.php
includes/context/IContextSource.php
includes/context/RequestContext.php
includes/libs/Timing.php [new file with mode: 0644]
tests/phpunit/includes/libs/TimingTest.php [new file with mode: 0644]

index 6c792e2..1c3bf20 100644 (file)
@@ -1253,6 +1253,7 @@ $wgAutoloadLocalClasses = array(
        'TidyUpBug37714' => __DIR__ . '/maintenance/tidyUpBug37714.php',
        'TiffHandler' => __DIR__ . '/includes/media/Tiff.php',
        'TimestampException' => __DIR__ . '/includes/exception/TimestampException.php',
+       'Timing' => __DIR__ . '/includes/libs/Timing.php',
        'Title' => __DIR__ . '/includes/Title.php',
        'TitleArray' => __DIR__ . '/includes/TitleArray.php',
        'TitleArrayFromResult' => __DIR__ . '/includes/TitleArrayFromResult.php',
index 676108c..d048b57 100644 (file)
@@ -531,6 +531,9 @@ class MediaWiki {
         * @since 1.26
         */
        public function doPostOutputShutdown( $mode = 'normal' ) {
+               $timing = $this->context->getTiming();
+               $timing->mark( 'requestShutdown' );
+
                // Show visible profiling data if enabled (which cannot be post-send)
                Profiler::instance()->logDataPageOutputOnly();
 
index caf5afa..a8850fc 100644 (file)
@@ -152,6 +152,16 @@ abstract class ContextSource implements IContextSource {
                return $this->getContext()->getSkin();
        }
 
+       /**
+        * Get the Timing object
+        *
+        * @since 1.27
+        * @return Timing
+        */
+       public function getTiming() {
+               return $this->getContext()->getTiming();
+       }
+
        /**
         * Get the Stats object
         *
index 09c3939..1b881e4 100644 (file)
@@ -72,6 +72,11 @@ class DerivativeContext extends ContextSource implements MutableContext {
         */
        private $stats;
 
+       /**
+        * @var Timing
+        */
+       private $timing;
+
        /**
         * Constructor
         * @param IContextSource $context Context to inherit from
@@ -115,6 +120,19 @@ class DerivativeContext extends ContextSource implements MutableContext {
                }
        }
 
+       /**
+        * Get the timing object
+        *
+        * @return Timing
+        */
+       public function getTiming() {
+               if ( !is_null( $this->timing ) ) {
+                       return $this->timing;
+               } else {
+                       return $this->getContext()->getTiming();
+               }
+       }
+
        /**
         * Set the WebRequest object
         *
index 58bf5d9..750389d 100644 (file)
@@ -131,6 +131,14 @@ interface IContextSource {
         */
        public function getStats();
 
+       /**
+        * Get the timing object
+        *
+        * @since 1.27
+        * @return Timing
+        */
+       public function getTiming();
+
        /**
         * Get a Message object with context set.  See wfMessage for parameters.
         *
index 42a2aee..4f8e65d 100644 (file)
@@ -66,6 +66,11 @@ class RequestContext implements IContextSource, MutableContext {
         */
        private $stats;
 
+       /**
+        * @var Timing
+        */
+       private $timing;
+
        /**
         * @var Config
         */
@@ -139,6 +144,18 @@ class RequestContext implements IContextSource, MutableContext {
                return $this->stats;
        }
 
+       /**
+        * Get the timing object
+        *
+        * @return Timing
+        */
+       public function getTiming() {
+               if ( $this->timing === null ) {
+                       $this->timing = new Timing();
+               }
+               return $this->timing;
+       }
+
        /**
         * Set the Title object
         *
diff --git a/includes/libs/Timing.php b/includes/libs/Timing.php
new file mode 100644 (file)
index 0000000..653227e
--- /dev/null
@@ -0,0 +1,168 @@
+<?php
+/**
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ */
+
+/**
+ * An interface to help developers measure the performance of their applications.
+ * This interface closely matches the W3C's User Timing specification.
+ * The key differences are:
+ *
+ * - The reference point for all measurements which do not explicitly specify
+ *   a start time is $_SERVER['REQUEST_TIME_FLOAT'], not navigationStart.
+ * - Successive calls to mark() and measure() with the same entry name cause
+ *   the previous entry to be overwritten. This ensures that there is a 1:1
+ *   mapping between names and entries.
+ * - Because there is a 1:1 mapping, instead of getEntriesByName(), we have
+ *   getEntryByName().
+ *
+ * The in-line documentation incorporates content from the User Timing Specification
+ * http://www.w3.org/TR/user-timing/
+ * Copyright © 2013 World Wide Web Consortium, (MIT, ERCIM, Keio, Beihang).
+ * http://www.w3.org/Consortium/Legal/2015/doc-license
+ *
+ * @since 1.27
+ */
+class Timing {
+
+       /** @var array[] */
+       private $entries = array();
+
+       public function __construct() {
+               $this->clearMarks();
+       }
+
+       /**
+        * Store a timestamp with the associated name (a "mark")
+        *
+        * @param string $markName The name associated with the timestamp.
+        *  If there already exists an entry by that name, it is overwritten.
+        * @return array The mark that has been created.
+        */
+       public function mark( $markName ) {
+               $this->entries[$markName] = array(
+                       'name'      => $markName,
+                       'entryType' => 'mark',
+                       'startTime' => microtime( true ),
+                       'duration'  => 0,
+               );
+               return $this->entries[$markName];
+       }
+
+       /**
+        * @param string $markName The name of the mark that should
+        *  be cleared. If not specified, all marks will be cleared.
+        */
+       public function clearMarks( $markName = null ) {
+               if ( $markName !== null ) {
+                       unset( $this->entries[$markName] );
+               } else {
+                       $this->entries = array(
+                               'requestStart' => array(
+                                       'name'      => 'requestStart',
+                                       'entryType' => 'mark',
+                                       'startTime' => isset( $_SERVER['REQUEST_TIME_FLOAT'] )
+                                               ? $_SERVER['REQUEST_TIME_FLOAT']
+                                               : $_SERVER['REQUEST_TIME'],
+                                       'duration'  => 0,
+                               ),
+                       );
+               }
+       }
+
+       /**
+        * This method stores the duration between two marks along with
+        * the associated name (a "measure").
+        *
+        * If neither the startMark nor the endMark argument is specified,
+        * measure() will store the duration from $_SERVER['REQUEST_TIME_FLOAT'] to
+        * the current time.
+        * If the startMark argument is specified, but the endMark argument is not
+        * specified, measure() will store the duration from the most recent
+        * occurrence of the start mark to the current time.
+        * If both the startMark and endMark arguments are specified, measure()
+        * will store the duration from the most recent occurrence of the start
+        * mark to the most recent occurrence of the end mark.
+        *
+        * @param string $measureName
+        * @param string $startMark
+        * @param string $endMark
+        * @return array The measure that has been created.
+        */
+       public function measure( $measureName, $startMark = 'requestStart', $endMark = null ) {
+               $start = $this->getEntryByName( $startMark );
+               $startTime = $start['startTime'];
+
+               if ( $endMark ) {
+                       $end = $this->getEntryByName( $endMark );
+                       $endTime = $end['startTime'];
+               } else {
+                       $endTime = microtime( true );
+               }
+
+               $this->entries[$measureName] = array(
+                       'name'      => $measureName,
+                       'entryType' => 'measure',
+                       'startTime' => $startTime,
+                       'duration'  => $endTime - $startTime,
+               );
+
+               return $this->entries[$measureName];
+       }
+
+       /**
+        * Sort entries in chronological order with respect to startTime.
+        */
+       private function sortEntries() {
+               uasort( $this->entries, function ( $a, $b ) {
+                       return 10000 * ( $a['startTime'] - $b['startTime'] );
+               } );
+       }
+
+       /**
+        * @return array[] All entries in chronological order.
+        */
+       public function getEntries() {
+               $this->sortEntries();
+               return $this->entries;
+       }
+
+       /**
+        * @param string $entryType
+        * @return array[] Entries (in chronological order) that have the same value
+        *  for the entryType attribute as the $entryType parameter.
+        */
+       public function getEntriesByType( $entryType ) {
+               $this->sortEntries();
+               $entries = array();
+               foreach ( $this->entries as $entry ) {
+                       if ( $entry['entryType'] === $entryType ) {
+                               $entries[] = $entry;
+                       }
+               }
+               return $entries;
+       }
+
+       /**
+        * @param string $name
+        * @return array|null Entry named $name or null if it does not exist.
+        */
+       public function getEntryByName( $name ) {
+               return isset( $this->entries[$name] ) ? $this->entries[$name] : null;
+       }
+}
diff --git a/tests/phpunit/includes/libs/TimingTest.php b/tests/phpunit/includes/libs/TimingTest.php
new file mode 100644 (file)
index 0000000..93e9d6b
--- /dev/null
@@ -0,0 +1,111 @@
+<?php
+/**
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @author Ori Livneh <ori@wikimedia.org>
+ */
+
+class TimingTest extends PHPUnit_Framework_TestCase {
+
+       /**
+        * @covers Timing::clearMarks
+        * @covers Timing::getEntries
+        */
+       public function testClearMarks() {
+               $timing = new Timing;
+               $this->assertCount( 1, $timing->getEntries() );
+
+               $timing->mark( 'a' );
+               $timing->mark( 'b' );
+               $this->assertCount( 3, $timing->getEntries() );
+
+               $timing->clearMarks( 'a' );
+               $this->assertNull( $timing->getEntryByName( 'a' ) );
+               $this->assertNotNull( $timing->getEntryByName( 'b' ) );
+
+               $timing->clearMarks();
+               $this->assertCount( 1, $timing->getEntries() );
+       }
+
+       /**
+        * @covers Timing::mark
+        * @covers Timing::getEntryByName
+        */
+       public function testMark() {
+               $timing = new Timing;
+               $timing->mark( 'a' );
+
+               $entry = $timing->getEntryByName( 'a' );
+               $this->assertEquals( 'a', $entry['name'] );
+               $this->assertEquals( 'mark', $entry['entryType'] );
+               $this->assertArrayHasKey( 'startTime', $entry );
+               $this->assertEquals( 0, $entry['duration'] );
+
+               $timing->mark( 'a' );
+               $newEntry = $timing->getEntryByName( 'a' );
+               $this->assertGreaterThan( $entry['startTime'], $newEntry['startTime'] );
+       }
+
+       /**
+        * @covers Timing::measure
+        */
+       public function testMeasure() {
+               $timing = new Timing;
+
+               $timing->mark( 'a' );
+               $a = $timing->getEntryByName( 'a' );
+
+               $timing->mark( 'b' );
+               $b = $timing->getEntryByName( 'b' );
+
+               $timing->measure( 'a_to_b', 'a', 'b' );
+
+               $entry = $timing->getEntryByName( 'a_to_b' );
+               $this->assertEquals( 'a_to_b', $entry['name'] );
+               $this->assertEquals( 'measure', $entry['entryType'] );
+               $this->assertEquals( $a['startTime'], $entry['startTime'] );
+               $this->assertEquals( $b['startTime'] - $a['startTime'], $entry['duration'] );
+       }
+
+       /**
+        * @covers Timing::getEntriesByType
+        */
+       public function testGetEntriesByType() {
+               $timing = new Timing;
+
+               $timing->mark( 'mark_a' );
+               usleep( 100 );
+               $timing->mark( 'mark_b' );
+               usleep( 100 );
+               $timing->mark( 'mark_c' );
+
+               $timing->measure( 'measure_a', 'mark_a', 'mark_b' );
+               $timing->measure( 'measure_b', 'mark_b', 'mark_c' );
+
+               $marks = array_map( function ( $entry ) {
+                       return $entry['name'];
+               }, $timing->getEntriesByType( 'mark' ) );
+
+               $this->assertEquals( array( 'requestStart', 'mark_a', 'mark_b', 'mark_c' ), $marks );
+
+               $measures = array_map( function ( $entry ) {
+                       return $entry['name'];
+               }, $timing->getEntriesByType( 'measure' ) );
+
+               $this->assertEquals( array( 'measure_a', 'measure_b' ), $measures );
+       }
+}