diff --git a/bin/plugin/commands/performance.js b/bin/plugin/commands/performance.js index e802a9550b80ef..6bb98ec4646bb4 100644 --- a/bin/plugin/commands/performance.js +++ b/bin/plugin/commands/performance.js @@ -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. */ /** @@ -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 ), @@ -314,7 +329,22 @@ 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[ branch ].serverResponse + ), + firstPaint: rawResults.map( + ( r ) => r[ branch ].firstPaint + ), + domContentLoaded: rawResults.map( + ( r ) => r[ branch ].domContentLoaded + ), + loaded: rawResults.map( ( r ) => r[ branch ].loaded ), + firstContentfulPaint: rawResults.map( + ( r ) => r[ branch ].firstContentfulPaint + ), + firstBlock: rawResults.map( + ( r ) => r[ branch ].firstBlock + ), type: rawResults.map( ( r ) => r[ branch ].type ), minType: rawResults.map( ( r ) => r[ branch ].minType ), maxType: rawResults.map( ( r ) => r[ branch ].maxType ), @@ -359,6 +389,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` ); diff --git a/docs/explanations/architecture/performance.md b/docs/explanations/architecture/performance.md index bd6753b6664221..5a9f56ee0996f9 100644 --- a/docs/explanations/architecture/performance.md +++ b/docs/explanations/architecture/performance.md @@ -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). diff --git a/packages/e2e-tests/config/performance-reporter.js b/packages/e2e-tests/config/performance-reporter.js index 0e8725cf472239..6c314917f8ac27 100644 --- a/packages/e2e-tests/config/performance-reporter.js +++ b/packages/e2e-tests/config/performance-reporter.js @@ -29,7 +29,12 @@ class PerformanceReporter { const results = readFileSync( filepath, 'utf8' ); const { - load, + serverResponse, + firstPaint, + domContentLoaded, + loaded, + firstContentfulPaint, + firstBlock, type, focus, inserterOpen, @@ -37,11 +42,26 @@ class PerformanceReporter { 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 ) { diff --git a/packages/e2e-tests/specs/performance/post-editor.test.js b/packages/e2e-tests/specs/performance/post-editor.test.js index 0bbfcd18660369..f9862f18c94484 100644 --- a/packages/e2e-tests/specs/performance/post-editor.test.js +++ b/packages/e2e-tests/specs/performance/post-editor.test.js @@ -26,13 +26,19 @@ import { getClickEventDurations, getHoverEventDurations, getSelectionEventDurations, + getLoadingDurations, } from './utils'; jest.setTimeout( 1000000 ); describe( 'Post Editor Performance', () => { const results = { - load: [], + serverResponse: [], + firstPaint: [], + domContentLoaded: [], + loaded: [], + firstContentfulPaint: [], + firstBlock: [], type: [], focus: [], inserterOpen: [], @@ -90,10 +96,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 ); } } ); diff --git a/packages/e2e-tests/specs/performance/site-editor.test.js b/packages/e2e-tests/specs/performance/site-editor.test.js index 9bb0f846efff4b..80fa8cecc3c958 100644 --- a/packages/e2e-tests/specs/performance/site-editor.test.js +++ b/packages/e2e-tests/specs/performance/site-editor.test.js @@ -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 ); @@ -39,7 +44,12 @@ describe( 'Site Editor Performance', () => { it( 'Loading', async () => { const results = { - load: [], + serverResponse: [], + firstPaint: [], + domContentLoaded: [], + loaded: [], + firstContentfulPaint: [], + firstBlock: [], type: [], focus: [], inserterOpen: [], @@ -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. diff --git a/packages/e2e-tests/specs/performance/utils.js b/packages/e2e-tests/specs/performance/utils.js index 1bb82d4745ae6c..1ffee009827ac4 100644 --- a/packages/e2e-tests/specs/performance/utils.js +++ b/packages/e2e-tests/specs/performance/utils.js @@ -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, + }; + } ); +}