Skip to content

Commit c6de684

Browse files
mrlubosmrlubos
authored
Merge pull request #2884 from hey-api/copilot/fix-performance-mark-issue
Fix performance mark crash when using DEBUG=true
2 parents f475ce7 + d5c0a1c commit c6de684

File tree

3 files changed

+153
-50
lines changed

3 files changed

+153
-50
lines changed

‎.changeset/pink-chefs-collect.md‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
---
2+
"@hey-api/openapi-ts": patch
3+
---
4+
5+
fix: gracefully handle errors in debug reports

‎packages/openapi-ts/src/utils/__tests__/logger.test.ts‎

Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,67 @@
1+
import { describe, expect, it } from 'vitest';
2+
3+
import { Logger } from '../logger';
4+
5+
describe('Logger', () => {
6+
describe('report', () => {
7+
it('should handle unended events gracefully', () => {
8+
const logger = new Logger();
9+
10+
// Create an event but don't end it
11+
logger.timeEvent('test-event-1');
12+
13+
// Create another event and end it
14+
const event2 = logger.timeEvent('test-event-2');
15+
event2.timeEnd();
16+
17+
// report() should not throw even though event1 was never ended
18+
expect(() => logger.report(false)).not.toThrow();
19+
20+
const measure = logger.report(false);
21+
expect(measure).toBeDefined();
22+
expect(measure?.duration).toBeGreaterThanOrEqual(0);
23+
});
24+
25+
it('should handle nested unended events', () => {
26+
const logger = new Logger();
27+
28+
const parent = logger.timeEvent('parent');
29+
logger.timeEvent('child1');
30+
// Don't end child1
31+
32+
const child2 = logger.timeEvent('child2');
33+
child2.timeEnd();
34+
35+
parent.timeEnd();
36+
37+
// report() should not throw even though child1 was never ended
38+
expect(() => logger.report(false)).not.toThrow();
39+
40+
const measure = logger.report(false);
41+
expect(measure).toBeDefined();
42+
});
43+
44+
it('should handle all events properly ended', () => {
45+
const logger = new Logger();
46+
47+
const event1 = logger.timeEvent('event1');
48+
const event2 = logger.timeEvent('event2');
49+
50+
event1.timeEnd();
51+
event2.timeEnd();
52+
53+
expect(() => logger.report(false)).not.toThrow();
54+
55+
const measure = logger.report(false);
56+
expect(measure).toBeDefined();
57+
expect(measure?.duration).toBeGreaterThanOrEqual(0);
58+
});
59+
60+
it('should return undefined when no events exist', () => {
61+
const logger = new Logger();
62+
63+
const measure = logger.report(false);
64+
expect(measure).toBeUndefined();
65+
});
66+
});
67+
});

‎packages/openapi-ts/src/utils/logger.ts‎

Lines changed: 81 additions & 50 deletions
Original file line numberDiff line numberDiff line change
@@ -71,29 +71,55 @@ export class Logger {
7171
}
7272
}
7373

74+
/**
75+
* Recursively end all unended events in the event tree.
76+
* This ensures all events have end marks before measuring.
77+
*/
78+
private endAllEvents(events: Array<LoggerEvent>): void {
79+
for (const event of events) {
80+
if (!event.end) {
81+
event.end = performance.mark(idEnd(event.id));
82+
}
83+
if (event.events.length > 0) {
84+
this.endAllEvents(event.events);
85+
}
86+
}
87+
}
88+
7489
report(print: boolean = true): PerformanceMeasure | undefined {
7590
const firstEvent = this.events[0];
7691
if (!firstEvent) return;
92+
93+
// Ensure all events are ended before reporting
94+
this.endAllEvents(this.events);
95+
7796
const lastEvent = this.events[this.events.length - 1]!;
7897
const name = 'root';
7998
const id = nameToId(name);
80-
const measure = performance.measure(
81-
idLength(id),
82-
idStart(firstEvent.id),
83-
idEnd(lastEvent.id),
84-
);
85-
if (print) {
86-
this.reportEvent({
87-
end: lastEvent.end,
88-
events: this.events,
89-
id,
90-
indent: 0,
91-
measure,
92-
name,
93-
start: firstEvent!.start,
94-
});
99+
100+
try {
101+
const measure = performance.measure(
102+
idLength(id),
103+
idStart(firstEvent.id),
104+
idEnd(lastEvent.id),
105+
);
106+
if (print) {
107+
this.reportEvent({
108+
end: lastEvent.end,
109+
events: this.events,
110+
id,
111+
indent: 0,
112+
measure,
113+
name,
114+
start: firstEvent!.start,
115+
});
116+
}
117+
return measure;
118+
} catch {
119+
// If measuring fails (e.g., marks don't exist), silently skip reporting
120+
// to avoid crashing the application
121+
return;
95122
}
96-
return measure;
97123
}
98124

99125
private reportEvent({
@@ -107,41 +133,46 @@ export class Logger {
107133
const lastIndex = parent.events.length - 1;
108134

109135
parent.events.forEach((event, index) => {
110-
const measure = performance.measure(
111-
idLength(event.id),
112-
idStart(event.id),
113-
idEnd(event.id),
114-
);
115-
const duration = Math.ceil(measure.duration * 100) / 100;
116-
const percentage =
117-
Math.ceil((measure.duration / parent.measure.duration) * 100 * 100) /
118-
100;
119-
const severity = indent ? getSeverity(duration, percentage) : undefined;
120-
121-
let durationLabel = `${duration.toFixed(2).padStart(8)}ms`;
122-
if (severity?.type === 'duration') {
123-
durationLabel = severity.color(durationLabel);
124-
}
125-
126-
const branch = index === lastIndex ? '└─ ' : '├─ ';
127-
const prefix = !indent ? '' : '│ '.repeat(indent - 1) + branch;
128-
const maxLength = 38 - prefix.length;
129-
130-
const percentageBranch = !indent ? '' : '↳ ';
131-
const percentagePrefix = indent
132-
? ' '.repeat(indent - 1) + percentageBranch
133-
: '';
134-
let percentageLabel = `${percentagePrefix}${percentage.toFixed(2)}%`;
135-
if (severity?.type === 'percentage') {
136-
percentageLabel = severity.color(percentageLabel);
136+
try {
137+
const measure = performance.measure(
138+
idLength(event.id),
139+
idStart(event.id),
140+
idEnd(event.id),
141+
);
142+
const duration = Math.ceil(measure.duration * 100) / 100;
143+
const percentage =
144+
Math.ceil((measure.duration / parent.measure.duration) * 100 * 100) /
145+
100;
146+
const severity = indent ? getSeverity(duration, percentage) : undefined;
147+
148+
let durationLabel = `${duration.toFixed(2).padStart(8)}ms`;
149+
if (severity?.type === 'duration') {
150+
durationLabel = severity.color(durationLabel);
151+
}
152+
153+
const branch = index === lastIndex ? '└─ ' : '├─ ';
154+
const prefix = !indent ? '' : '│ '.repeat(indent - 1) + branch;
155+
const maxLength = 38 - prefix.length;
156+
157+
const percentageBranch = !indent ? '' : '↳ ';
158+
const percentagePrefix = indent
159+
? ' '.repeat(indent - 1) + percentageBranch
160+
: '';
161+
let percentageLabel = `${percentagePrefix}${percentage.toFixed(2)}%`;
162+
if (severity?.type === 'percentage') {
163+
percentageLabel = severity.color(percentageLabel);
164+
}
165+
const jobPrefix = colors.gray('[root] ');
166+
console.log(
167+
`${jobPrefix}${colors.gray(prefix)}${color(
168+
`${event.name.padEnd(maxLength)} ${durationLabel} (${percentageLabel})`,
169+
)}`,
170+
);
171+
this.reportEvent({ ...event, indent: indent + 1, measure });
172+
} catch {
173+
// If measuring fails (e.g., marks don't exist), silently skip this event
174+
// to avoid crashing the application
137175
}
138-
const jobPrefix = colors.gray('[root] ');
139-
console.log(
140-
`${jobPrefix}${colors.gray(prefix)}${color(
141-
`${event.name.padEnd(maxLength)} ${durationLabel} (${percentageLabel})`,
142-
)}`,
143-
);
144-
this.reportEvent({ ...event, indent: indent + 1, measure });
145176
});
146177
}
147178

0 commit comments

Comments
 (0)