EBernhardson has uploaded a new change for review.
https://gerrit.wikimedia.org/r/104318
Change subject: Debug toolbar profiler timeline
......................................................................
Debug toolbar profiler timeline
This adds a new pane for the debug toolbar labeled Profiler. It groups
together events sent to wfProfileIn/Out and draws a timeline giving a
visual representation of what the page was doing at a particular point
in time.
This is mostly inspired by, and some code reused from, the
WebProfilerBundle for symfony2.
Change-Id: I23a0ce4137abcd74ad87967fb263214c08cb9685
---
M includes/debug/Debug.php
M includes/profiler/Profiler.php
M resources/Resources.php
M resources/mediawiki/mediawiki.debug.js
A resources/mediawiki/mediawiki.profile.js
5 files changed, 345 insertions(+), 3 deletions(-)
git pull ssh://gerrit.wikimedia.org:29418/mediawiki/core
refs/changes/18/104318/1
diff --git a/includes/debug/Debug.php b/includes/debug/Debug.php
index d0f8916..1ee541b 100644
--- a/includes/debug/Debug.php
+++ b/includes/debug/Debug.php
@@ -547,6 +547,7 @@
'memory' => $context->getLanguage()->formatSize(
memory_get_usage() ),
'memoryPeak' => $context->getLanguage()->formatSize(
memory_get_peak_usage() ),
'includes' => self::getFilesIncluded( $context ),
+ 'profile' => Profiler::instance()->getRawData(),
);
}
}
diff --git a/includes/profiler/Profiler.php b/includes/profiler/Profiler.php
index 235a5ad..ef84bc0 100644
--- a/includes/profiler/Profiler.php
+++ b/includes/profiler/Profiler.php
@@ -96,7 +96,7 @@
*/
class Profiler {
protected $mStack = array(), $mWorkStack = array(), $mCollated =
array(),
- $mCalls = array(), $mTotals = array();
+ $mCalls = array(), $mTotals = array(), $mPeriods = array();
protected $mTimeMetric = 'wall';
protected $mProfileID = false, $mCollateDone = false, $mTemplated =
false;
@@ -556,6 +556,7 @@
$this->mMin[$fname] = 1 << 24;
$this->mMax[$fname] = 0;
$this->mOverhead[$fname] = 0;
+ $this->mPeriods[$fname] = array();
}
$this->mCollated[$fname] += $elapsed;
@@ -564,6 +565,7 @@
$this->mMin[$fname] = min( $this->mMin[$fname],
$elapsed );
$this->mMax[$fname] = max( $this->mMax[$fname],
$elapsed );
$this->mOverhead[$fname] += $subcalls;
+ $this->mPeriods[$fname][] = compact( 'start', 'end' );
}
$this->mCalls['-overhead-total'] = $profileCount;
@@ -608,6 +610,33 @@
return $prof;
}
+ function getRawData() {
+ $this->collateData();
+
+ $output = array();
+ $total = isset( $this->mCollated['-total'] ) ?
$this->mCollated['-total'] : 0;
+ foreach ( $this->mCollated as $fname => $elapsed ) {
+ $periods = array();
+ foreach ( $this->mPeriods[$fname] as $period ) {
+ $periods[] = array(
+ 'start' => $period['start'] * 1000,
+ 'end' => $period['end'] * 1000,
+ );
+ }
+ $output[$fname] = array(
+ 'calls' => $this->mCalls[$fname],
+ 'elapsed' => $elapsed * 1000,
+ 'percent' => $total ? 100. * $elapsed / $total
: 0,
+ 'memory' => $this->mMemory[$fname],
+ 'min' => $this->mMin[$fname] * 1000,
+ 'max' => $this->mMax[$fname] * 1000,
+ 'overhead' => $this->mOverhead[$fname],
+ 'periods' => $periods,
+ );
+ }
+ return $output;
+ }
+
/**
* Dummy calls to wfProfileIn/wfProfileOut to calculate its overhead
*/
diff --git a/resources/Resources.php b/resources/Resources.php
index d79b29b..e8ba975 100644
--- a/resources/Resources.php
+++ b/resources/Resources.php
@@ -700,7 +700,7 @@
),
),
'mediawiki.debug' => array(
- 'scripts' => 'resources/mediawiki/mediawiki.debug.js',
+ 'scripts' => array( 'resources/mediawiki/mediawiki.debug.js',
'resources/mediawiki/mediawiki.profile.js' ),
'styles' => 'resources/mediawiki/mediawiki.debug.css',
'dependencies' => 'jquery.footHovzer',
'position' => 'bottom',
diff --git a/resources/mediawiki/mediawiki.debug.js
b/resources/mediawiki/mediawiki.debug.js
index 986917a..ff96c60 100644
--- a/resources/mediawiki/mediawiki.debug.js
+++ b/resources/mediawiki/mediawiki.debug.js
@@ -160,6 +160,8 @@
paneTriggerBitDiv( 'includes', 'PHP includes',
this.data.includes.length );
+ paneTriggerBitDiv( 'profile', 'Profile',
this.data.profile.length );
+
gitInfo = '';
if ( this.data.gitRevision !== false ) {
gitInfo = '(' +
this.data.gitRevision.substring( 0, 7 ) + ')';
@@ -196,7 +198,8 @@
querylist: this.buildQueryTable(),
debuglog: this.buildDebugLogTable(),
request: this.buildRequestPane(),
- includes: this.buildIncludesPane()
+ includes: this.buildIncludesPane(),
+ profile: this.buildProfilePane()
};
for ( id in panes ) {
@@ -359,6 +362,11 @@
}
return $table;
+ },
+
+ buildProfilePane: function() {
+ mw.Debug.Profile.init();
+ return mw.Debug.Profile.canvas;
}
};
diff --git a/resources/mediawiki/mediawiki.profile.js
b/resources/mediawiki/mediawiki.profile.js
new file mode 100644
index 0000000..c888978
--- /dev/null
+++ b/resources/mediawiki/mediawiki.profile.js
@@ -0,0 +1,304 @@
+/**
+ * JavaScript for the debug toolbar profiler, enabled through $wgDebugToolbar
+ * and StartProfiler.php.
+ *
+ * @author Erik Bernhardson
+ * @since 1.23
+ */
+
+( function ( mw, $ ) {
+ 'use strict';
+
+ var profile,
+ hovzer = $.getFootHovzer();
+
+ profile = mw.Debug.Profile = {
+ /**
+ * Object containing data for the debug toolbar
+ *
+ * @var {Object}
+ */
+ data: {},
+
+ /**
+ * Canvas timeline is drawn to
+ *
+ * @var {Element}
+ */
+ canvas: null,
+
+ /**
+ * Initializes the debugging pane.
+ * Shouldn't be called before the document is ready
+ * (since it binds to elements on the page).
+ *
+ * @param {Object} data, defaults to 'debugInfo' from mw.config
+ */
+ init: function ( data, width, mergeThreshold, dropThreshold ) {
+
+ this.canvas = document.createElement( 'canvas' );
+ this.data = data || mw.config.get( 'debugInfo'
).profile;
+ this.buildCanvas( width || $(window).width() - 100,
mergeThreshold || 1, dropThreshold || 1 );
+ },
+
+ collate: function( width, mergeThreshold, dropThreshold ) {
+ var label, pos, i, sum, minmax, ratio,
+ groups = {},
+ prefix = 'Profile section ended by close(): ';
+
+
+ // group together by partial label and period
+ for ( i in this.data ) {
+ if ( 0 === i.indexOf( '-' ) || i == "" ) {
+ continue;
+ }
+ if ( 0 === i.indexOf( prefix ) ) {
+ i = i.substring( prefix.length );
+ }
+ pos = [ '::', ':', '-' ].reduce( function(
result, separator ) {
+ var pos = i.indexOf( separator );
+ if ( pos === -1 ) {
+ return result;
+ } else if ( result === -1 ) {
+ return pos;
+ } else {
+ return Math.min( pos, result );
+ }
+ }, -1 );
+ if ( pos === -1 ) {
+ label = i;
+ } else {
+ label = i.substring( 0, pos );
+ }
+ groups[label] = groups[label] || [];
+ groups[label].push.apply(
+ groups[label],
+ // filter any bad data
+ this.data[i].periods.filter( function(
period ) {
+ return period.start &&
period.end && period.end > period.start;
+ } )
+ );
+ }
+
+ // find the min and max timestamp
+ minmax = Object.keys( groups ).reduce( function (
result, label ) {
+ return groups[label].reduce( periodMinMax,
result );
+ }, { start: Number.POSITIVE_INFINITY, end:
Number.NEGATIVE_INFINITY} );
+
+ // change mergeThreshold from pixels to ms
+ ratio = ( minmax.end - minmax.start ) / width;
+ mergeThreshold *= ratio;
+
+ // merge periods closer than a step size
+ return Object.keys( groups ).reduce( function( result,
label ) {
+ var periods = groups[label].sort( function ( a,
b ) {
+ if ( a.start == b.start ) {
+ return a.end - b.end;
+ }
+ return a.start - b.start;
+ } ).reduce( function ( result, period ){
+ // shift all periods left by
minmax.start
+ // only when period.start > 1000000,
because sometimes mw profiler
+ // outputs relative time(bug?)
+ if ( period.start > 1000000 ) {
+ period.start -= minmax.start;
+ period.end -= minmax.start;
+ }
+
+ if ( result.length == 0 ) {
+ return [period];
+ }
+ var last = result[result.length - 1];
+ if ( period.end < last.end ) {
+ // skip, end is contained
within previous
+ } else if ( period.start -
mergeThreshold < last.end ) {
+ // neighbors within merging
distance
+ result[result.length - 1].end =
period.end;
+ } else {
+ // period is next result
+ result.push( period );
+ }
+ return result;
+ }, [] ).filter( function( period ) {
+ return period.end - period.start >
dropThreshold;
+ } );
+ if ( periods.length ) {
+ result[label] = periods;
+ }
+ return result;
+ }, {} );
+ },
+
+ /**
+ * Constructs the HTML for the profile toolbar
+ */
+ buildCanvas: function ( width, mergeThreshold, dropThreshold ) {
+ var $container, $bits, i, pos, groups, label;
+
+ $container = $( '<div id="mw-profile-toolbar"
class="mw-profile" lang="en" dir="ltr"></div>' );
+
+ $bits = $( '<div class="mw-debug-bits"></div>' );
+
+ groups = this.collate( width, mergeThreshold,
dropThreshold );
+
+ // Calculate extra timespan based data
+ var timespans = {}, first, last;
+ for ( label in groups ) {
+ timespans[label] = groups[label].reduce(
+ periodMinMax,
+ { start: Number.POSITIVE_INFINITY, end:
Number.NEGATIVE_INFINITY}
+ );
+ timespans[label].length = timespans[label].end
- timespans[label].start;
+ timespans[label].sum = groups[label].reduce(
function( result, period ) {
+ return result + period.end -
period.start;
+ }, 0 );
+ }
+ var total = Object.keys( timespans ).reduce(
+ function( result, label ) { return
periodMinMax( result, timespans[label] ); },
+ { start: Number.POSITIVE_INFINITY, end:
Number.NEGATIVE_INFINITY}
+ );
+ var max = total.end - total.start;
+
+ // Sort by contained time
+ this.sortedLabels = Object.keys( groups ).sort(
function( a, b ) {
+ return timespans[a].start - timespans[b].start;
+ } );
+ // for debugging
+ this.other = groups;
+
+ // start drawing
+ var i, j,
+ text,
+ canvasHeight = 0,
+ gapPerEvent = 38,
+ colors = {
+ default: 'red',
+ },
+ space = 10.5,
+ ratio = ( width - space * 2 ) / max,
+ h = space,
+ x = 0,
+ canvas = this.canvas,
+ ctx = canvas.getContext( "2d" ),
+ backingStoreRatio,
+ scaleRatio,
+ devicePixelRatio;
+
+
+ // reset the canvas
+ ctx.save();
+ ctx.setTransform( 1, 0, 0, 1, 0, 0 );
+ ctx.clearRect( 0, 0, canvas.width, canvas.height );
+ ctx.restore();
+
+ // Figure out our size
+ canvasHeight += gapPerEvent * Object.keys( groups
).length;
+ devicePixelRatio = window.devicePixelRatio ==
"undefined" ? 1 : window.devicePixelRatio;
+ backingStoreRatio = ctx.webkitBackingStorePixelRatio ==
"undefined" ? 1 : ctx.webkitBackingStorePixelRatio;
+ scaleRatio = devicePixelRatio / 1;
+
+ canvas.width = width * scaleRatio;
+ canvas.height = canvasHeight * scaleRatio;
+
+ canvas.style.width = width + 'px';
+ canvas.style.height = canvasHeight + 'px';
+
+ ctx.scale( scaleRatio, scaleRatio );
+
+ ctx.textBaseline = "middle";
+ ctx.lineWidth = 0;
+
+ this.sortedLabels.forEach( function( label ) {
+ h += 8;
+
+ if ( colors[label] ) {
+ ctx.fillStyle = colors[label];
+ ctx.strokeStyle = colors[label];
+ } else {
+ ctx.fillStyle = colors['default'];
+ ctx.strokeStyle = colors['default'];
+ }
+
+ groups[label].forEach( function( period ) {
+
+ var timelineHeadPosition = x +
period.start * ratio,
+ timelineTailPosition = x +
period.end * ratio;
+
+ // if less than width draw a plain box
+ if ( timelineHeadPosition + 16 >
timelineTailPosition ) {
+ ctx.fillRect(
timelineHeadPosition, h, 2, 9 );
+ ctx.fillRect(
timelineHeadPosition, h, ( period.end - period.start ) * ratio || 2, 6 );
+ } else {
+ ctx.beginPath();
+ ctx.moveTo(
timelineHeadPosition, h );
+ ctx.lineTo(
timelineHeadPosition, h + 11 );
+ ctx.lineTo(
timelineHeadPosition + 8, h );
+ ctx.lineTo(
timelineHeadPosition, h );
+ ctx.fill();
+ ctx.closePath();
+ ctx.stroke();
+
+ ctx.beginPath();
+ ctx.moveTo(
timelineTailPosition, h );
+ ctx.lineTo(
timelineTailPosition, h + 11 );
+ ctx.lineTo(
timelineTailPosition - 8, h );
+ ctx.lineTo(
timelineTailPosition, h );
+ ctx.fill();
+ ctx.closePath();
+ ctx.stroke();
+
+ ctx.beginPath();
+ ctx.moveTo(
timelineHeadPosition, h );
+ ctx.lineTo(
timelineTailPosition, h );
+ ctx.lineTo(
timelineTailPosition, h + 2 );
+ ctx.lineTo(
timelineHeadPosition, h + 2 );
+ ctx.lineTo(
timelineHeadPosition, h );
+ ctx.fill();
+ ctx.closePath();
+ ctx.stroke();
+ }
+ } );
+
+ h += 30;
+
+ ctx.beginPath();
+ ctx.strokeStyle = "#dfdfdf";
+ ctx.moveTo( 0, h - 10 );
+ ctx.lineTo( width, h - 10 );
+ ctx.closePath();
+ ctx.stroke();
+ } );
+
+ h = space;
+
+ this.sortedLabels.forEach( function( label ) {
+ var ms = " ~ " + ( timespans[label].sum < 1 ?
timespans[label].sum : parseInt( timespans[label].sum, 10 ) ) + " ms",
+ xc;
+
+ ctx.fillStyle = "#444";
+ ctx.font = "12px sans-serif";
+ ctx.textAlign = "start";
+ xc = x + timespans[label].start * ratio + 1;
+ ctx.fillText( label, xc, h );
+
+ xc += ctx.measureText( label ).width;
+ ctx.font = "10px sans-serif";
+ ctx.fillText( ms, xc, h );
+
+ h += gapPerEvent;
+ } );
+ }
+ };
+
+ // reducer to find edges of period array
+ function periodMinMax( result, period ) {
+ if ( period.start < result.start ) {
+ result.start = period.start;
+ }
+ if ( period.end > result.end ) {
+ result.end = period.end;
+ }
+ return result;
+ };
+
+}( mediaWiki, jQuery ) );
--
To view, visit https://gerrit.wikimedia.org/r/104318
To unsubscribe, visit https://gerrit.wikimedia.org/r/settings
Gerrit-MessageType: newchange
Gerrit-Change-Id: I23a0ce4137abcd74ad87967fb263214c08cb9685
Gerrit-PatchSet: 1
Gerrit-Project: mediawiki/core
Gerrit-Branch: master
Gerrit-Owner: EBernhardson <[email protected]>
_______________________________________________
MediaWiki-commits mailing list
[email protected]
https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
