Metrics: Time site starts from the moment the site shows as running

tools/metrics/tests/site-startup.test.ts

@@ -2,7 +2,7 @@ import { test, expect } from '@playwright/test';
 import { E2ESession } from '../../../apps/studio/e2e/e2e-helpers';
 import AddSite from '../../../apps/studio/e2e/page-objects/add-site';
 import Sidebar from '../../../apps/studio/e2e/page-objects/sidebar';
-import { median } from '../utils';
+import { getRunningSince, median, recordRunningTimes } from '../utils';
 
 test.describe( 'Startup Metrics', () => {
 	const results: Record< string, number[] > = {};
@@ -11,6 +11,7 @@ test.describe( 'Startup Metrics', () => {
 
 	test.beforeAll( async () => {
 		await session.launch();
+		await recordRunningTimes( session.mainWindow );
 	} );
 
 	// eslint-disable-next-line no-empty-pattern
@@ -41,7 +42,7 @@ test.describe( 'Startup Metrics', () => {
 			const startTime = Date.now();
 			await addSite.createSite( { siteName } );
 			await sidebar.expectRunning( siteName );
-			results.siteCreation = [ Date.now() - startTime ];
+			results.siteCreation = [ ( await getRunningSince( statusButton ) ) - startTime ];
 		} );
 
 		results.siteStartup = [];
@@ -56,7 +57,7 @@ test.describe( 'Startup Metrics', () => {
 				const startTime = Date.now();
 				await statusButton.click();
 				await sidebar.expectRunning( siteName );
-				const duration = Date.now() - startTime;
+				const duration = ( await getRunningSince( statusButton ) ) - startTime;
 
 				console.log( `Run ${ i + 1 }/5: Restart took ${ duration }ms` );
 				results.siteStartup.push( duration );

tools/metrics/utils.ts

@@ -1,5 +1,6 @@
 import fs from 'fs';
 import path from 'path';
+import type { Locator, Page } from '@playwright/test';
 
 export function median( array ) {
 	if ( ! array || ! array.length ) return undefined;
@@ -29,3 +30,52 @@ export function getDirSize( dirPath: string ): number {
 	}
 	return total;
 }
+
+type RunningTimes = { studioMetricsRunningSince?: WeakMap< Element, number > };
+
+/**
+ * Records in the page when each element's `data-state` last became `running`.
+ * Playwright retries an assertion every 500 ms after its first few tries, so a
+ * time taken when the assertion passes lands up to 500 ms after the change.
+ */
+export async function recordRunningTimes( page: Page ): Promise< void > {
+	await page.evaluate( () => {
+		const runningSince = new WeakMap< Element, number >();
+		const note = ( element: Element ) => {
+			if ( element.getAttribute( 'data-state' ) !== 'running' ) {
+				runningSince.delete( element );
+			} else if ( ! runningSince.has( element ) ) {
+				runningSince.set( element, Date.now() );
+			}
+		};
+		new MutationObserver( ( mutations ) => {
+			for ( const mutation of mutations ) {
+				if ( mutation.type === 'attributes' ) {
+					note( mutation.target as Element );
+				}
+				for ( const node of mutation.addedNodes ) {
+					if ( node instanceof Element ) {
+						[ node, ...node.querySelectorAll( '[data-state]' ) ].forEach( note );
+					}
+				}
+			}
+		} ).observe( document.body, {
+			subtree: true,
+			childList: true,
+			attributes: true,
+			attributeFilter: [ 'data-state' ],
+		} );
+		( window as RunningTimes ).studioMetricsRunningSince = runningSince;
+	} );
+}
+
+/** When the element became `running`, as recorded by `recordRunningTimes`. */
+export async function getRunningSince( locator: Locator ): Promise< number > {
+	const runningSince = await locator.evaluate(
+		( element ) => ( window as RunningTimes ).studioMetricsRunningSince?.get( element )
+	);
+	if ( runningSince === undefined ) {
+		throw new Error( 'No running time was recorded for the element' );
+	}
+	return runningSince;
+}