Skip to content

Commit ab18bad

Browse files
sergicalsergical
committed
build timer
1 parent 91c4f27 commit ab18bad

File tree

4 files changed

+251
-3
lines changed

4 files changed

+251
-3
lines changed

‎app/[[...path]]/page.tsx‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ import {Metadata} from 'next';
44
import {notFound} from 'next/navigation';
55

66
import {apiCategories} from 'sentry-docs/build/resolveOpenAPI';
7+
import {BuildTimer, logBuildInfo} from 'sentry-docs/buildTimer';
78
import {ApiCategoryPage} from 'sentry-docs/components/apiCategoryPage';
89
import {ApiPage} from 'sentry-docs/components/apiPage';
910
import {DocPage} from 'sentry-docs/components/docPage';
@@ -31,12 +32,15 @@ import {PaginationNavNode} from 'sentry-docs/types/paginationNavNode';
3132
import {stripVersion} from 'sentry-docs/versioning';
3233

3334
export async function generateStaticParams() {
35+
const timer = new BuildTimer('generateStaticParams');
3436
const docs = await (isDeveloperDocs ? getDevDocsFrontMatter() : getDocsFrontMatter());
3537
const paths: {path: string[] | undefined}[] = docs.map(doc => {
3638
const path = doc.slug.split('/');
3739
return {path};
3840
});
3941
paths.push({path: undefined}); // the home page
42+
logBuildInfo(`Generated ${paths.length} static paths for build`);
43+
timer.end();
4044
return paths;
4145
}
4246

‎src/buildTimer.ts‎

Lines changed: 206 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,206 @@
1+
/**
2+
* Build timing utility for tracking performance of build operations
3+
*/
4+
5+
const PREFIX = '[BUILD_TIMER]';
6+
7+
// Global tracking for build summary
8+
const buildPhases: {duration: number; name: string}[] = [];
9+
10+
/**
11+
* Format duration in seconds with 1 decimal place
12+
*/
13+
function formatDuration(ms: number): string {
14+
const seconds = ms / 1000;
15+
if (seconds < 60) {
16+
return `${seconds.toFixed(1)}s`;
17+
}
18+
const minutes = Math.floor(seconds / 60);
19+
const remainingSeconds = seconds % 60;
20+
return `${minutes}m ${remainingSeconds.toFixed(1)}s`;
21+
}
22+
23+
/**
24+
* Simple timer class for tracking operation duration
25+
*/
26+
export class BuildTimer {
27+
private startTime: number;
28+
private name: string;
29+
30+
constructor(name: string, autoStart = true) {
31+
this.name = name;
32+
this.startTime = 0;
33+
if (autoStart) {
34+
this.start();
35+
}
36+
}
37+
38+
start(): void {
39+
this.startTime = Date.now();
40+
// eslint-disable-next-line no-console
41+
console.log(`${PREFIX} 🕐 Starting: ${this.name}`);
42+
}
43+
44+
end(silent = false): number {
45+
const duration = Date.now() - this.startTime;
46+
if (!silent) {
47+
// eslint-disable-next-line no-console
48+
console.log(
49+
`${PREFIX} ✓ Completed: ${this.name} (took ${formatDuration(duration)})`
50+
);
51+
}
52+
// Track for summary
53+
buildPhases.push({name: this.name, duration});
54+
return duration;
55+
}
56+
57+
/**
58+
* Get elapsed time without ending the timer
59+
*/
60+
elapsed(): number {
61+
return Date.now() - this.startTime;
62+
}
63+
}
64+
65+
/**
66+
* Log a simple message with the BUILD_TIMER prefix
67+
*/
68+
export function logBuildInfo(message: string): void {
69+
// eslint-disable-next-line no-console
70+
console.log(`${PREFIX} ${message}`);
71+
}
72+
73+
/**
74+
* Log a warning about a slow operation
75+
*/
76+
export function logSlowOperation(name: string, duration: number): void {
77+
// eslint-disable-next-line no-console
78+
console.log(`${PREFIX} ⚠️ Slow operation: ${name} (took ${formatDuration(duration)})`);
79+
}
80+
81+
/**
82+
* Log progress with statistics
83+
*/
84+
export function logProgress(message: string): void {
85+
// eslint-disable-next-line no-console
86+
console.log(`${PREFIX} 📊 ${message}`);
87+
}
88+
89+
/**
90+
* Aggregator for tracking multiple operations of the same type
91+
*/
92+
export class OperationAggregator {
93+
private count = 0;
94+
private totalDuration = 0;
95+
private name: string;
96+
private slowThreshold: number;
97+
private progressInterval: number;
98+
private lastProgressLog = 0;
99+
100+
constructor(
101+
name: string,
102+
options: {progressInterval?: number; slowThreshold?: number} = {}
103+
) {
104+
this.name = name;
105+
this.slowThreshold = options.slowThreshold ?? 2000; // 2 seconds default
106+
this.progressInterval = options.progressInterval ?? 100; // log every 100 operations
107+
}
108+
109+
/**
110+
* Track a single operation
111+
*/
112+
track(operationName: string, duration: number): void {
113+
this.count++;
114+
this.totalDuration += duration;
115+
116+
// Log slow operations
117+
if (duration > this.slowThreshold) {
118+
logSlowOperation(operationName, duration);
119+
}
120+
121+
// Log progress at intervals
122+
if (this.count - this.lastProgressLog >= this.progressInterval) {
123+
this.logStats();
124+
this.lastProgressLog = this.count;
125+
}
126+
}
127+
128+
/**
129+
* Log current statistics
130+
*/
131+
logStats(final = false): void {
132+
const avg = this.count > 0 ? this.totalDuration / this.count : 0;
133+
if (final) {
134+
// Final summary - more detailed
135+
logProgress(
136+
`${this.name}: ${this.count} operations (avg ${formatDuration(avg)}/op, total ${formatDuration(this.totalDuration)})`
137+
);
138+
} else {
139+
// Progress update - more concise
140+
logProgress(`${this.name}: ${this.count} ops (${formatDuration(avg)}/op avg)`);
141+
}
142+
}
143+
144+
/**
145+
* Get current statistics
146+
*/
147+
getStats(): {average: number; count: number; total: number} {
148+
return {
149+
average: this.count > 0 ? this.totalDuration / this.count : 0,
150+
count: this.count,
151+
total: this.totalDuration,
152+
};
153+
}
154+
155+
/**
156+
* Log final summary
157+
*/
158+
logFinalSummary(): void {
159+
this.logStats(true);
160+
}
161+
}
162+
163+
/**
164+
* Print a summary of all build phases
165+
*/
166+
export function logBuildSummary(): void {
167+
if (buildPhases.length === 0) {
168+
return;
169+
}
170+
171+
// eslint-disable-next-line no-console
172+
console.log(`\n${PREFIX} ═══════════════════════════════════════════════════════`);
173+
// eslint-disable-next-line no-console
174+
console.log(`${PREFIX} 📊 BUILD TIMING SUMMARY`);
175+
// eslint-disable-next-line no-console
176+
console.log(`${PREFIX} ═══════════════════════════════════════════════════════`);
177+
178+
// Sort by duration descending
179+
const sorted = [...buildPhases].sort((a, b) => b.duration - a.duration);
180+
181+
const totalTime = sorted.reduce((sum, phase) => sum + phase.duration, 0);
182+
183+
sorted.forEach(phase => {
184+
const percentage = ((phase.duration / totalTime) * 100).toFixed(1);
185+
const bar = '█'.repeat(Math.floor((phase.duration / totalTime) * 30));
186+
// eslint-disable-next-line no-console
187+
console.log(
188+
`${PREFIX} ${formatDuration(phase.duration).padStart(8)} ${percentage.padStart(5)}% ${bar.padEnd(30)} ${phase.name}`
189+
);
190+
});
191+
192+
// eslint-disable-next-line no-console
193+
console.log(`${PREFIX} ───────────────────────────────────────────────────────`);
194+
// eslint-disable-next-line no-console
195+
console.log(`${PREFIX} Total tracked: ${formatDuration(totalTime)}`);
196+
// eslint-disable-next-line no-console
197+
console.log(`${PREFIX} ═══════════════════════════════════════════════════════\n`);
198+
}
199+
200+
// Automatically log build summary when the process exits
201+
// This ensures the summary is shown even if the build script doesn't explicitly call it
202+
if (typeof process !== 'undefined') {
203+
process.on('beforeExit', () => {
204+
logBuildSummary();
205+
});
206+
}

‎src/docTree.ts‎

Lines changed: 10 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import {BuildTimer} from './buildTimer';
12
import {isDeveloperDocs} from './isDeveloperDocs';
23
import {getDevDocsFrontMatter, getDocsFrontMatter} from './mdx';
34
import {platformsData} from './platformsData';
@@ -39,9 +40,13 @@ export function getDocsRootNode(): Promise<DocNode> {
3940
}
4041

4142
async function getDocsRootNodeUncached(): Promise<DocNode> {
42-
return frontmatterToTree(
43-
await (isDeveloperDocs ? getDevDocsFrontMatter() : getDocsFrontMatter())
44-
);
43+
const timer = new BuildTimer('Building doc tree');
44+
const frontmatter = await (isDeveloperDocs
45+
? getDevDocsFrontMatter()
46+
: getDocsFrontMatter());
47+
const tree = frontmatterToTree(frontmatter);
48+
timer.end();
49+
return tree;
4550
}
4651

4752
const sidebarOrderSorter = (a: FrontMatter, b: FrontMatter) => {
@@ -57,6 +62,7 @@ const sidebarOrderSorter = (a: FrontMatter, b: FrontMatter) => {
5762
};
5863

5964
function frontmatterToTree(frontmatter: FrontMatter[]): DocNode {
65+
const timer = new BuildTimer('Sorting and building tree');
6066
const sortedDocs = frontmatter.sort(sidebarOrderSorter);
6167

6268
const rootNode: DocNode = {
@@ -128,6 +134,7 @@ function frontmatterToTree(frontmatter: FrontMatter[]): DocNode {
128134
}
129135
});
130136

137+
timer.end(true); // Silent - shown in summary
131138
return rootNode;
132139
}
133140

‎src/mdx.ts‎

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@ import remarkMdxImages from 'remark-mdx-images';
2626
import getAppRegistry from './build/appRegistry';
2727
import getPackageRegistry from './build/packageRegistry';
2828
import {apiCategories} from './build/resolveOpenAPI';
29+
import {BuildTimer, logBuildInfo, OperationAggregator} from './buildTimer';
2930
import getAllFilesRecursively from './files';
3031
import remarkDefList from './mdx-deflist';
3132
import rehypeOnboardingLines from './rehype-onboarding-lines';
@@ -65,6 +66,12 @@ if (process.env.CI) {
6566
mkdirSync(CACHE_DIR, {recursive: true});
6667
}
6768

69+
// Track MDX compilation performance
70+
const mdxCompilationAggregator = new OperationAggregator('MDX Compilation', {
71+
progressInterval: 500, // log every 500 compilations (less verbose)
72+
slowThreshold: 3000, // 3 seconds (only really slow pages)
73+
});
74+
6875
const md5 = (data: BinaryLike) => createHash('md5').update(data).digest('hex');
6976

7077
async function readCacheFile<T>(file: string): Promise<T> {
@@ -222,10 +229,12 @@ export function getDevDocsFrontMatter(): Promise<FrontMatter[]> {
222229
}
223230

224231
async function getAllFilesFrontMatter(): Promise<FrontMatter[]> {
232+
const timer = new BuildTimer('getAllFilesFrontMatter');
225233
const docsPath = path.join(root, 'docs');
226234
const files = await getAllFilesRecursively(docsPath);
227235
const allFrontMatter: FrontMatter[] = [];
228236

237+
const readFilesTimer = new BuildTimer('Reading MDX frontmatter');
229238
await Promise.all(
230239
files.map(
231240
limitFunction(
@@ -251,8 +260,10 @@ async function getAllFilesFrontMatter(): Promise<FrontMatter[]> {
251260
)
252261
)
253262
);
263+
readFilesTimer.end(true); // Silent - we'll show in summary
254264

255265
// Add all `common` files in the right place.
266+
const commonFilesTimer = new BuildTimer('Processing common platform files');
256267
const platformsPath = path.join(docsPath, 'platforms');
257268
for await (const platform of await opendir(platformsPath)) {
258269
if (platform.isFile()) {
@@ -396,6 +407,8 @@ async function getAllFilesFrontMatter(): Promise<FrontMatter[]> {
396407
);
397408
}
398409
}
410+
commonFilesTimer.end(true); // Silent - we'll show in summary
411+
timer.end();
399412
return allFrontMatter;
400413
}
401414

@@ -433,6 +446,8 @@ export const addVersionToFilePath = (filePath: string, version: string) => {
433446
};
434447

435448
export async function getFileBySlug(slug: string): Promise<SlugFile> {
449+
const compileStart = Date.now();
450+
436451
// no versioning on a config file
437452
const configPath = path.join(root, slug.split(VERSION_INDICATOR)[0], 'config.yml');
438453

@@ -708,9 +723,25 @@ export async function getFileBySlug(slug: string): Promise<SlugFile> {
708723
});
709724
}
710725

726+
// Track compilation time
727+
const compileDuration = Date.now() - compileStart;
728+
mdxCompilationAggregator.track(slug, compileDuration);
729+
711730
return resultObj;
712731
}
713732

733+
// Log final MDX compilation stats when process exits
734+
if (typeof process !== 'undefined') {
735+
process.on('beforeExit', () => {
736+
const stats = mdxCompilationAggregator.getStats();
737+
if (stats.count > 0) {
738+
logBuildInfo('━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━');
739+
mdxCompilationAggregator.logFinalSummary();
740+
logBuildInfo('━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━');
741+
}
742+
});
743+
}
744+
714745
const fileBySlugCache = new Map<string, Promise<SlugFile>>();
715746

716747
/**

0 commit comments

Comments
 (0)