From 1b32de48d58639be431b50f487e015fd65d1c44c Mon Sep 17 00:00:00 2001
From: Aaron Schulz <aschulz@wikimedia.org>
Date: Mon, 8 Dec 2014 14:05:23 -0800
Subject: [PATCH] Made xhprof scopedProfileIn() work via merging
 SectionProfiler results

* This works around various pecl/hhvm xhprof extension issues.

Change-Id: I04555db1d0781bafc758ab9965c4af2fab9569f4
---
 includes/profiler/ProfilerXhprof.php  | 41 +++++++++++++++------------
 includes/profiler/SectionProfiler.php | 12 +++++++-
 2 files changed, 34 insertions(+), 19 deletions(-)

diff --git a/includes/profiler/ProfilerXhprof.php b/includes/profiler/ProfilerXhprof.php
index 2fef011133..5603aa5d1d 100644
--- a/includes/profiler/ProfilerXhprof.php
+++ b/includes/profiler/ProfilerXhprof.php
@@ -59,12 +59,17 @@
  * @see https://github.com/facebook/hhvm/blob/master/hphp/doc/profiling.md
  */
 class ProfilerXhprof extends Profiler {
-
 	/**
 	 * @var Xhprof $xhprof
 	 */
 	protected $xhprof;
 
+	/**
+	 * Profiler for explicit, arbitrary, frame labels
+	 * @var SectionProfiler
+	 */
+	protected $sprofiler;
+
 	/**
 	 * Type of report to send when logData() is called.
 	 * @var string $logType
@@ -93,6 +98,7 @@ class ProfilerXhprof extends Profiler {
 		$this->logType = $params['log'];
 		$this->visible = $params['visible'];
 		$this->xhprof = new Xhprof( $params );
+		$this->sprofiler = new SectionProfiler();
 	}
 
 	/**
@@ -118,22 +124,7 @@ class ProfilerXhprof extends Profiler {
 	}
 
 	public function scopedProfileIn( $section ) {
-		static $exists = null;
-		// Only HHVM supports this, not the standard PECL extension
-		if ( $exists === null ) {
-			$exists = function_exists( 'xhprof_frame_begin' );
-		}
-
-		if ( $exists ) {
-			xhprof_frame_begin( $section );
-			return new ScopedCallback( function () {
-				xhprof_frame_end();
-			} );
-		}
-
-		return new ScopedCallback( function () {
-			// no-op
-		} );
+		return $this->sprofiler->scopedProfileIn( $section );
 	}
 
 	/**
@@ -146,9 +137,10 @@ class ProfilerXhprof extends Profiler {
 		$metrics = $this->xhprof->getCompleteMetrics();
 		$profile = array();
 
+		$main = null; // units in ms
 		foreach ( $metrics as $fname => $stats ) {
 			// Convert elapsed times from μs to ms to match ProfilerStandard
-			$profile[] = array(
+			$entry = array(
 				'name' => $fname,
 				'calls' => $stats['ct'],
 				'real' => $stats['wt']['total'] / 1000,
@@ -160,6 +152,19 @@ class ProfilerXhprof extends Profiler {
 				'min_real' => $stats['wt']['min'] / 1000,
 				'max_real' => $stats['wt']['max'] / 1000
 			);
+			$profile[] = $entry;
+			if ( $fname === 'main()' ) {
+				$main = $entry;
+			}
+		}
+
+		// Merge in all of the custom profile sections
+		foreach ( $this->sprofiler->getFunctionStats() as $stats ) {
+			// @note: getFunctionStats() values already in ms
+			$stats['%real'] = $stats['real'] / $main['real'];
+			$stats['%cpu'] = $main['cpu'] ? $stats['cpu'] / $main['cpu'] * 100 : 0;
+			$stats['%memory'] = $main['memory'] ? $stats['memory'] / $main['memory'] * 100 : 0;
+			$profile[] = $stats; // assume no section names collide with $metrics
 		}
 
 		return $profile;
diff --git a/includes/profiler/SectionProfiler.php b/includes/profiler/SectionProfiler.php
index d28c36ae86..275e986e07 100644
--- a/includes/profiler/SectionProfiler.php
+++ b/includes/profiler/SectionProfiler.php
@@ -93,6 +93,8 @@ class SectionProfiler {
 	 *   - %cpu    : percent real time
 	 *   - memory  : memory used (bytes)
 	 *   - %memory : percent memory used
+	 *   - min_real : min real time in a call (ms)
+	 *   - max_real : max real time in a call (ms)
 	 */
 	public function getFunctionStats() {
 		$this->collateData();
@@ -112,6 +114,8 @@ class SectionProfiler {
 				'%cpu' => $totalCpu ? 100 * $data['cpu'] / $totalCpu : 0,
 				'memory' => $data['memory'],
 				'%memory' => $totalMem ? 100 * $data['memory'] / $totalMem : 0,
+				'min_real' => 1000 * $data['min_real'],
+				'max_real' => 1000 * $data['max_real']
 			);
 		}
 
@@ -124,6 +128,8 @@ class SectionProfiler {
 			'%cpu' => 100,
 			'memory' => $totalMem,
 			'%memory' => 100,
+			'min_real' => 1000 * $totalReal,
+			'max_real' => 1000 * $totalReal
 		);
 
 		return $profile;
@@ -149,7 +155,9 @@ class SectionProfiler {
 			'cpu'      => 0.0,
 			'real'     => 0.0,
 			'memory'   => 0,
-			'count'    => 0
+			'count'    => 0,
+			'min_real' => 0.0,
+			'max_real' => 0.0
 		);
 	}
 
@@ -180,6 +188,8 @@ class SectionProfiler {
 		$entry['real'] += $elapsedReal;
 		$entry['memory'] += $memChange > 0 ? $memChange : 0;
 		$entry['count']++;
+		$entry['min_real'] = min( $entry['min_real'], $elapsedReal );
+		$entry['max_real'] = max( $entry['max_real'], $elapsedReal );
 	}
 
 	/**
-- 
2.20.1