Skip to content

Commit

Permalink
Performance tests: add more detailed loading metrics
Browse files Browse the repository at this point in the history
  • Loading branch information
@ellatrix
ellatrix committed Aug 16, 2021
1 parent 947816e commit 86f0b68
Show file tree
Hide file tree
Showing 6 changed files with 158 additions and 36 deletions.
77 changes: 53 additions & 24 deletions bin/plugin/commands/performance.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,33 +29,43 @@ const config = require( '../config' );
/**
* @typedef WPRawPerformanceResults
*
* @property {number[]} load Load Time.
* @property {number[]} type Average type time.
* @property {number[]} focus Average block selection time.
* @property {number[]} inserterOpen Average time to open global inserter.
* @property {number[]} inserterSearch Average time to search the inserter.
* @property {number[]} inserterHover Average time to move mouse between two block item in the inserter.
* @property {number[]} serverResponse Represents the time the server takes to respond.
* @property {number[]} firstPaint Represents the time when the user agent first rendered after navigation.
* @property {number[]} domContentLoaded Represents the time immediately after the document's DOMContentLoaded event completes.
* @property {number[]} loaded Represents the time when the load event of the current document is completed.
* @property {number[]} firstContentfulPaint Represents the time when the browser first renders any text or media.
* @property {number[]} firstBlock Represents the time when Puppeteer first sees a block selector in the DOM.
* @property {number[]} type Average type time.
* @property {number[]} focus Average block selection time.
* @property {number[]} inserterOpen Average time to open global inserter.
* @property {number[]} inserterSearch Average time to search the inserter.
* @property {number[]} inserterHover Average time to move mouse between two block item in the inserter.
*/

/**
* @typedef WPPerformanceResults
*
* @property {number=} load Load Time.
* @property {number=} type Average type time.
* @property {number=} minType Minium type time.
* @property {number=} maxType Maximum type time.
* @property {number=} focus Average block selection time.
* @property {number=} minFocus Min block selection time.
* @property {number=} maxFocus Max block selection time.
* @property {number=} inserterOpen Average time to open global inserter.
* @property {number=} minInserterOpen Min time to open global inserter.
* @property {number=} maxInserterOpen Max time to open global inserter.
* @property {number=} inserterSearch Average time to open global inserter.
* @property {number=} minInserterSearch Min time to open global inserter.
* @property {number=} maxInserterSearch Max time to open global inserter.
* @property {number=} inserterHover Average time to move mouse between two block item in the inserter.
* @property {number=} minInserterHover Min time to move mouse between two block item in the inserter.
* @property {number=} maxInserterHover Max time to move mouse between two block item in the inserter.
* @property {number=} serverResponse Represents the time the server takes to respond.
* @property {number=} firstPaint Represents the time when the user agent first rendered after navigation.
* @property {number=} domContentLoaded Represents the time immediately after the document's DOMContentLoaded event completes.
* @property {number=} loaded Represents the time when the load event of the current document is completed.
* @property {number=} firstContentfulPaint Represents the time when the browser first renders any text or media.
* @property {number=} firstBlock Represents the time when Puppeteer first sees a block selector in the DOM.
* @property {number=} type Average type time.
* @property {number=} minType Minium type time.
* @property {number=} maxType Maximum type time.
* @property {number=} focus Average block selection time.
* @property {number=} minFocus Min block selection time.
* @property {number=} maxFocus Max block selection time.
* @property {number=} inserterOpen Average time to open global inserter.
* @property {number=} minInserterOpen Min time to open global inserter.
* @property {number=} maxInserterOpen Max time to open global inserter.
* @property {number=} inserterSearch Average time to open global inserter.
* @property {number=} minInserterSearch Min time to open global inserter.
* @property {number=} maxInserterSearch Max time to open global inserter.
* @property {number=} inserterHover Average time to move mouse between two block item in the inserter.
* @property {number=} minInserterHover Min time to move mouse between two block item in the inserter.
* @property {number=} maxInserterHover Max time to move mouse between two block item in the inserter.
*/

/**
Expand Down Expand Up @@ -105,7 +115,12 @@ function formatTime( number ) {
*/
function curateResults( results ) {
return {
load: average( results.load ),
serverResponse: average( results.serverResponse ),
firstPaint: average( results.firstPaint ),
domContentLoaded: average( results.domContentLoaded ),
loaded: average( results.loaded ),
firstContentfulPaint: average( results.firstContentfulPaint ),
firstBlock: average( results.firstBlock ),
type: average( results.type ),
minType: Math.min( ...results.type ),
maxType: Math.max( ...results.type ),
Expand Down Expand Up @@ -321,7 +336,16 @@ async function runPerformanceTests( branches, options ) {
for ( const branch of branches ) {
const medians = mapValues(
{
load: rawResults.map( ( r ) => r[ branch ].load ),
serverResponse: rawResults.map( ( r ) => r.serverResponse ),
firstPaint: rawResults.map( ( r ) => r.firstPaint ),
domContentLoaded: rawResults.map(
( r ) => r.domContentLoaded
),
loaded: rawResults.map( ( r ) => r.loaded ),
firstContentfulPaint: rawResults.map(
( r ) => r.firstContentfulPaint
),
firstBlock: rawResults.map( ( r ) => r.firstBlock ),
type: rawResults.map( ( r ) => r[ branch ].type ),
minType: rawResults.map( ( r ) => r[ branch ].minType ),
maxType: rawResults.map( ( r ) => r[ branch ].maxType ),
Expand Down Expand Up @@ -366,6 +390,11 @@ async function runPerformanceTests( branches, options ) {

// 5- Formatting the results.
log( '\n>> 🎉 Results.\n' );

log(
'\nPlease note that client side metrics EXCLUDE the server response time.\n'
);

for ( const testSuite of testSuites ) {
log( `\n>> ${ testSuite }\n` );

Expand Down
2 changes: 1 addition & 1 deletion docs/explanations/architecture/performance.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ Performance is a key feature for editor applications and the Block editor is not

To ensure the block editor stays performant across releases and development, we monitor some key metrics using [performance testing](/docs/contributors/code/testing-overview.md#performance-testing).

**Loading Time:** The time it takes to load an editor page.
**Loading Time:** The time it takes to load an editor page. This includes time the server takes to respond, times to first paint, first contentful paint, DOM content load complete, load complete and first block render.
**Typing Time:** The time it takes for the browser to respond while typing on the editor.
**Block Selection Time:** The time it takes for the browser to respond after a user selects block. (Inserting a block is also equivalent to selecting a block. Monitoring the selection is sufficient to cover both metrics).

Expand Down
26 changes: 23 additions & 3 deletions packages/e2e-tests/config/performance-reporter.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,19 +29,39 @@ class PerformanceReporter {

const results = readFileSync( filepath, 'utf8' );
const {
load,
serverResponse,
firstPaint,
domContentLoaded,
loaded,
firstContentfulPaint,
firstBlock,
type,
focus,
inserterOpen,
inserterHover,
inserterSearch,
} = JSON.parse( results );

if ( load && load.length ) {
if ( serverResponse && serverResponse.length ) {
// eslint-disable-next-line no-console
console.log( `
${ title( 'Loading Time:' ) }
Average time to load: ${ success( round( average( load ) ) + 'ms' ) }` );
Average time to server response (subtracted from client side metrics): ${ success(
round( average( serverResponse ) ) + 'ms'
) }
Average time to first paint: ${ success(
round( average( firstPaint ) ) + 'ms'
) }
Average time to DOM content load: ${ success(
round( average( domContentLoaded ) ) + 'ms'
) }
Average time to load: ${ success( round( average( loaded ) ) + 'ms' ) }
Average time to first contentful paint: ${ success(
round( average( firstContentfulPaint ) ) + 'ms'
) }
Average time to first block: ${ success(
round( average( firstBlock ) ) + 'ms'
) }` );
}

if ( type && type.length ) {
Expand Down
25 changes: 22 additions & 3 deletions packages/e2e-tests/specs/performance/post-editor.test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import {
getClickEventDurations,
getHoverEventDurations,
getSelectionEventDurations,
getLoadingDurations,
} from './utils';

jest.setTimeout( 1000000 );
Expand All @@ -35,7 +36,12 @@ describe( 'Post Editor Performance', () => {
const traceFile = __dirname + '/trace.json';
let traceResults;
const results = {
load: [],
serverResponse: [],
firstPaint: [],
domContentLoaded: [],
loaded: [],
firstContentfulPaint: [],
firstBlock: [],
type: [],
focus: [],
inserterOpen: [],
Expand Down Expand Up @@ -67,10 +73,23 @@ describe( 'Post Editor Performance', () => {
// Measuring loading time
let i = 5;
while ( i-- ) {
const startTime = new Date();
await page.reload();
await page.waitForSelector( '.wp-block' );
results.load.push( new Date() - startTime );
const {
serverResponse,
firstPaint,
domContentLoaded,
loaded,
firstContentfulPaint,
firstBlock,
} = await getLoadingDurations();

results.serverResponse.push( serverResponse );
results.firstPaint.push( firstPaint );
results.domContentLoaded.push( domContentLoaded );
results.loaded.push( loaded );
results.firstContentfulPaint.push( firstContentfulPaint );
results.firstBlock.push( firstBlock );
}

// Measure time to open inserter
Expand Down
32 changes: 27 additions & 5 deletions packages/e2e-tests/specs/performance/site-editor.test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,12 @@ import {
* Internal dependencies
*/
import { siteEditor } from '../../experimental-features';
import { readFile, deleteFile, getTypingEventDurations } from './utils';
import {
readFile,
deleteFile,
getTypingEventDurations,
getLoadingDurations,
} from './utils';

jest.setTimeout( 1000000 );

Expand All @@ -39,7 +44,12 @@ describe( 'Site Editor Performance', () => {

it( 'Loading', async () => {
const results = {
load: [],
serverResponse: [],
firstPaint: [],
domContentLoaded: [],
loaded: [],
firstContentfulPaint: [],
firstBlock: [],
type: [],
focus: [],
inserterOpen: [],
Expand Down Expand Up @@ -78,14 +88,26 @@ describe( 'Site Editor Performance', () => {

// Measuring loading time
while ( i-- ) {
const startTime = new Date();
await page.reload();
await page.waitForSelector( '.edit-site-visual-editor', {
timeout: 120000,
} );
await canvas().waitForSelector( '.wp-block', { timeout: 120000 } );

results.load.push( new Date() - startTime );
const {
serverResponse,
firstPaint,
domContentLoaded,
loaded,
firstContentfulPaint,
firstBlock,
} = await getLoadingDurations();

results.serverResponse.push( serverResponse );
results.firstPaint.push( firstPaint );
results.domContentLoaded.push( domContentLoaded );
results.loaded.push( loaded );
results.firstContentfulPaint.push( firstContentfulPaint );
results.firstBlock.push( firstBlock );
}

// Measuring typing performance inside the post content.
Expand Down
32 changes: 32 additions & 0 deletions packages/e2e-tests/specs/performance/utils.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -81,3 +81,35 @@ export function getHoverEventDurations( trace ) {
getEventDurationsForType( trace, isMouseOutEvent ),
];
}

export async function getLoadingDurations() {
return await page.evaluate( () => {
const [
{
requestStart,
responseStart,
responseEnd,
domContentLoadedEventEnd,
loadEventEnd,
},
] = performance.getEntriesByType( 'navigation' );
const paintTimings = performance.getEntriesByType( 'paint' );
return {
// Server side metric.
serverResponse: responseStart - requestStart,
// For client side metrics, consider the end of the response (the
// browser receives the HTML) as the start time (0).
firstPaint:
paintTimings.find( ( { name } ) => name === 'first-paint' )
.startTime - responseEnd,
domContentLoaded: domContentLoadedEventEnd - responseEnd,
loaded: loadEventEnd - responseEnd,
firstContentfulPaint:
paintTimings.find(
( { name } ) => name === 'first-contentful-paint'
).startTime - responseEnd,
// This is evaluated right after Puppeteer found the block selector.
firstBlock: performance.now() - responseEnd,
};
} );
}

0 comments on commit 86f0b68

Please sign in to comment.