@@ -28,6 +28,9 @@ const describeUiBudgetMs = Number(
2828const httpActionBudgetMs = Number (
2929 process . env . SIMDECK_INTEGRATION_HTTP_BUDGET_MS ?? "10000" ,
3030) ;
31+ const phaseSetup = "setup" ;
32+ const phaseTest = "test" ;
33+ const phaseSimulatorLifecycle = "simulator-lifecycle" ;
3134
3235let simulatorUDID = "" ;
3336let serverProcess = null ;
@@ -68,27 +71,43 @@ async function main() {
6871 const runtime = latestAvailableIosRuntime ( ) ;
6972 const deviceType = preferredIphoneDeviceType ( runtime ) ;
7073 const simulatorName = `SimDeck CLI Integration ${ Date . now ( ) } ` ;
71- simulatorUDID = runText ( "xcrun" , [
72- "simctl" ,
73- "create" ,
74- simulatorName ,
75- deviceType . identifier ,
76- runtime . identifier ,
77- ] ) . trim ( ) ;
74+ simulatorUDID = await measuredStep (
75+ "simctl create simulator" ,
76+ ( ) =>
77+ runText ( "xcrun" , [
78+ "simctl" ,
79+ "create" ,
80+ simulatorName ,
81+ deviceType . identifier ,
82+ runtime . identifier ,
83+ ] ) . trim ( ) ,
84+ { phase : phaseSetup } ,
85+ ) ;
7886
7987 console . log (
8088 `created ${ simulatorUDID } (${ deviceType . name } , ${ runtime . version } )` ,
8189 ) ;
82- simdeckJson ( [ "boot" , simulatorUDID ] ) ;
83- runText ( "xcrun" , [ "simctl" , "bootstatus" , simulatorUDID , "-b" ] , {
84- timeoutMs : 600_000 ,
85- } ) ;
90+ await measuredStep (
91+ "CLI boot simulator" ,
92+ ( ) => simdeckJson ( [ "boot" , simulatorUDID ] ) ,
93+ { phase : phaseSetup } ,
94+ ) ;
95+ await measuredStep (
96+ "simctl bootstatus initial" ,
97+ ( ) =>
98+ runText ( "xcrun" , [ "simctl" , "bootstatus" , simulatorUDID , "-b" ] , {
99+ timeoutMs : 600_000 ,
100+ } ) ,
101+ { phase : phaseSetup } ,
102+ ) ;
86103 if ( showSimulator ) {
87104 openSimulatorApp ( simulatorUDID ) ;
88105 }
89106
90- const fixture = await measuredStep ( "build SwiftUI fixture" , ( ) =>
91- buildFixtureApp ( ) ,
107+ const fixture = await measuredStep (
108+ "build SwiftUI fixture" ,
109+ ( ) => buildFixtureApp ( ) ,
110+ { phase : phaseSetup } ,
92111 ) ;
93112
94113 await measuredStep ( "CLI list" , ( ) => assertSimulatorListed ( simulatorUDID ) ) ;
@@ -105,14 +124,20 @@ async function main() {
105124 ) ,
106125 ) ;
107126
108- await measuredStep ( "CLI install fixture" , async ( ) => {
109- simdeckJson ( [ "install" , simulatorUDID , fixture . appPath ] ) ;
110- preapproveFixtureUrlScheme ( ) ;
111- await verifyUi ( "after install" ) ;
112- } ) ;
127+ await measuredStep (
128+ "CLI install fixture" ,
129+ async ( ) => {
130+ simdeckJson ( [ "install" , simulatorUDID , fixture . appPath ] ) ;
131+ preapproveFixtureUrlScheme ( ) ;
132+ await verifyUi ( "after install" ) ;
133+ } ,
134+ { phase : phaseSetup } ,
135+ ) ;
113136
114137 startServer ( ) ;
115- await measuredStep ( "server health" , ( ) => waitForHealth ( ) ) ;
138+ await measuredStep ( "server health" , ( ) => waitForHealth ( ) , {
139+ phase : phaseSetup ,
140+ } ) ;
116141 logStep ( `server ready at ${ serverUrl } ` ) ;
117142
118143 const fullTree = await measuredStep ( "direct describe-ui json" , ( ) =>
@@ -247,35 +272,48 @@ async function main() {
247272 await measuredStep ( "CLI uninstall fixture" , ( ) =>
248273 simdeckJson ( [ "uninstall" , simulatorUDID , fixtureBundleId ] ) ,
249274 ) ;
250- await measuredStep ( "CLI shutdown" , ( ) =>
251- simdeckJson ( [ "shutdown" , simulatorUDID ] ) ,
252- ) ;
253- await measuredStep ( "CLI erase" , ( ) => simdeckJson ( [ "erase" , simulatorUDID ] ) ) ;
254- await measuredStep ( "CLI boot after erase" , ( ) =>
255- simdeckJson ( [ "boot" , simulatorUDID ] ) ,
275+ await measuredStep (
276+ "CLI shutdown" ,
277+ ( ) => simdeckJson ( [ "shutdown" , simulatorUDID ] ) ,
278+ { phase : phaseSimulatorLifecycle } ,
256279 ) ;
257- await measuredStep ( "simctl bootstatus after erase" , ( ) =>
258- runText ( "xcrun" , [ "simctl" , "bootstatus" , simulatorUDID , "-b" ] , {
259- timeoutMs : 600_000 ,
260- } ) ,
280+ await measuredStep ( "CLI erase" , ( ) => simdeckJson ( [ "erase" , simulatorUDID ] ) , {
281+ phase : phaseSimulatorLifecycle ,
282+ } ) ;
283+ await measuredStep (
284+ "CLI boot after erase" ,
285+ ( ) => simdeckJson ( [ "boot" , simulatorUDID ] ) ,
286+ { phase : phaseSimulatorLifecycle } ,
287+ ) ;
288+ await measuredStep (
289+ "simctl bootstatus after erase" ,
290+ ( ) =>
291+ runText ( "xcrun" , [ "simctl" , "bootstatus" , simulatorUDID , "-b" ] , {
292+ timeoutMs : 600_000 ,
293+ } ) ,
294+ { phase : phaseSimulatorLifecycle } ,
261295 ) ;
262- await measuredStep ( "post-erase describe-ui" , async ( ) => {
263- assertRoots (
264- await retrySimdeckJson (
265- [
266- "describe-ui" ,
267- simulatorUDID ,
268- "--direct" ,
269- "--format" ,
270- "compact-json" ,
271- "--max-depth" ,
272- "1" ,
273- ] ,
296+ await measuredStep (
297+ "post-erase describe-ui" ,
298+ async ( ) => {
299+ assertRoots (
300+ await retrySimdeckJson (
301+ [
302+ "describe-ui" ,
303+ simulatorUDID ,
304+ "--direct" ,
305+ "--format" ,
306+ "compact-json" ,
307+ "--max-depth" ,
308+ "1" ,
309+ ] ,
310+ "post-erase describe-ui" ,
311+ ) ,
274312 "post-erase describe-ui" ,
275- ) ,
276- "post-erase describe-ui" ,
277- ) ;
278- } ) ;
313+ ) ;
314+ } ,
315+ { phase : phaseSimulatorLifecycle } ,
316+ ) ;
279317
280318 console . log ( "SimDeck CLI integration suite passed" ) ;
281319}
@@ -1389,6 +1427,7 @@ function runText(command, args, options = {}) {
13891427 ) ;
13901428 }
13911429 const elapsedMs = Date . now ( ) - startedAt ;
1430+ recordCommandTiming ( command , args , elapsedMs ) ;
13921431 if ( options . maxElapsedMs && elapsedMs > options . maxElapsedMs ) {
13931432 throw new Error (
13941433 `${ command } ${ args . join ( " " ) } took ${ elapsedMs } ms, above ${ options . maxElapsedMs } ms budget` ,
@@ -1413,6 +1452,7 @@ function runBuffer(command, args, options = {}) {
14131452 ) ;
14141453 }
14151454 const elapsedMs = Date . now ( ) - startedAt ;
1455+ recordCommandTiming ( command , args , elapsedMs ) ;
14161456 if ( options . maxElapsedMs && elapsedMs > options . maxElapsedMs ) {
14171457 throw new Error (
14181458 `${ command } ${ args . join ( " " ) } took ${ elapsedMs } ms, above ${ options . maxElapsedMs } ms budget` ,
@@ -1422,6 +1462,16 @@ function runBuffer(command, args, options = {}) {
14221462 return result . stdout ;
14231463}
14241464
1465+ function recordCommandTiming ( command , args , elapsedMs ) {
1466+ if ( ! activeTiming ) {
1467+ return ;
1468+ }
1469+ activeTiming . commandMs += elapsedMs ;
1470+ if ( command === simdeck && args . includes ( "describe-ui" ) ) {
1471+ activeTiming . describeUiMs += elapsedMs ;
1472+ }
1473+ }
1474+
14251475async function httpJson ( method , requestPath , body , options = { } ) {
14261476 const buffer = await httpBuffer ( method , requestPath , body , options ) ;
14271477 return JSON . parse ( buffer . toString ( "utf8" ) ) ;
@@ -1659,13 +1709,16 @@ function hasUsableFrame(node) {
16591709 ) ;
16601710}
16611711
1662- async function measuredStep ( label , fn ) {
1712+ async function measuredStep ( label , fn , options = { } ) {
16631713 const parentTiming = activeTiming ;
16641714 const timing = {
16651715 label,
1716+ phase : options . phase ?? phaseTest ,
16661717 startedAt : Date . now ( ) ,
16671718 elapsedMs : 0 ,
16681719 sleepMs : 0 ,
1720+ describeUiMs : 0 ,
1721+ commandMs : 0 ,
16691722 ok : false ,
16701723 } ;
16711724 activeTiming = timing ;
@@ -1696,28 +1749,64 @@ function printTimingSummary() {
16961749 }
16971750 const rows = stepTimings . map ( ( timing ) => ( {
16981751 label : timing . label ,
1752+ phase : timing . phase ,
16991753 activeMs : Math . max ( 0 , timing . elapsedMs - timing . sleepMs ) ,
17001754 elapsedMs : timing . elapsedMs ,
17011755 sleepMs : timing . sleepMs ,
1756+ describeUiMs : timing . describeUiMs ,
1757+ commandMs : timing . commandMs ,
17021758 ok : timing . ok ,
17031759 } ) ) ;
17041760 const totalActiveMs = rows . reduce ( ( sum , row ) => sum + row . activeMs , 0 ) ;
17051761 const totalElapsedMs = rows . reduce ( ( sum , row ) => sum + row . elapsedMs , 0 ) ;
17061762 const totalSleepMs = rows . reduce ( ( sum , row ) => sum + row . sleepMs , 0 ) ;
1763+ const totalDescribeUiMs = rows . reduce (
1764+ ( sum , row ) => sum + row . describeUiMs ,
1765+ 0 ,
1766+ ) ;
1767+ const phaseTotals = new Map ( ) ;
1768+ for ( const row of rows ) {
1769+ const totals = phaseTotals . get ( row . phase ) ?? {
1770+ activeMs : 0 ,
1771+ elapsedMs : 0 ,
1772+ sleepMs : 0 ,
1773+ describeUiMs : 0 ,
1774+ } ;
1775+ totals . activeMs += row . activeMs ;
1776+ totals . elapsedMs += row . elapsedMs ;
1777+ totals . sleepMs += row . sleepMs ;
1778+ totals . describeUiMs += row . describeUiMs ;
1779+ phaseTotals . set ( row . phase , totals ) ;
1780+ }
17071781
17081782 console . log (
17091783 "\nIntegration timing summary (artificial delays excluded from active):" ,
17101784 ) ;
1711- console . log ( "active\twall\tdelay\tstatus\tstep" ) ;
1785+ console . log ( "active\twall\tdelay\tdescribe-ui\tphase\ tstatus\tstep" ) ;
17121786 for ( const row of rows . toSorted (
17131787 ( left , right ) => right . activeMs - left . activeMs ,
17141788 ) ) {
17151789 console . log (
1716- `${ formatDuration ( row . activeMs ) } \t${ formatDuration ( row . elapsedMs ) } \t${ formatDuration ( row . sleepMs ) } \t${ row . ok ? "ok" : "fail" } \t${ row . label } ` ,
1790+ `${ formatDuration ( row . activeMs ) } \t${ formatDuration ( row . elapsedMs ) } \t${ formatDuration ( row . sleepMs ) } \t${ formatDuration ( row . describeUiMs ) } \t${ row . phase } \t${ row . ok ? "ok" : "fail" } \t${ row . label } ` ,
1791+ ) ;
1792+ }
1793+ console . log ( "\nPhase totals:" ) ;
1794+ for ( const [ phase , totals ] of [ ...phaseTotals . entries ( ) ] . sort ( ) ) {
1795+ console . log (
1796+ `${ phase } : active ${ formatDuration ( totals . activeMs ) } / wall ${ formatDuration ( totals . elapsedMs ) } / artificial delay ${ formatDuration ( totals . sleepMs ) } / describe-ui ${ formatDuration ( totals . describeUiMs ) } ` ,
17171797 ) ;
17181798 }
1799+ const testTotals = phaseTotals . get ( phaseTest ) ?? {
1800+ activeMs : 0 ,
1801+ elapsedMs : 0 ,
1802+ sleepMs : 0 ,
1803+ describeUiMs : 0 ,
1804+ } ;
1805+ console . log (
1806+ `test body active ${ formatDuration ( testTotals . activeMs ) } / wall ${ formatDuration ( testTotals . elapsedMs ) } / artificial delay ${ formatDuration ( testTotals . sleepMs ) } / describe-ui ${ formatDuration ( testTotals . describeUiMs ) } ` ,
1807+ ) ;
17191808 console . log (
1720- `total active ${ formatDuration ( totalActiveMs ) } / wall ${ formatDuration ( totalElapsedMs ) } / artificial delay ${ formatDuration ( totalSleepMs ) } ` ,
1809+ `total active ${ formatDuration ( totalActiveMs ) } / wall ${ formatDuration ( totalElapsedMs ) } / artificial delay ${ formatDuration ( totalSleepMs ) } / describe-ui ${ formatDuration ( totalDescribeUiMs ) } ` ,
17211810 ) ;
17221811}
17231812
0 commit comments