Commit | Line | Data |
---|---|---|
a19b897d | 1 | // Partial Copyright Jerome Benoit. 2021-2024. All Rights Reserved. |
c8eeb62b | 2 | |
4c3f6c20 | 3 | import { performance, type PerformanceEntry, PerformanceObserver } from 'node:perf_hooks' |
66a7748d JB |
4 | import type { URL } from 'node:url' |
5 | import { parentPort } from 'node:worker_threads' | |
63b48f77 | 6 | |
66a7748d | 7 | import { secondsToMilliseconds } from 'date-fns' |
840ca85d | 8 | import { CircularBuffer } from 'mnemonist' |
8a4f882a | 9 | import { is, mean, median } from 'rambda' |
be4c6702 | 10 | |
2466918c | 11 | import { BaseError } from '../exception/index.js' |
268a74bb | 12 | import { |
5d049829 | 13 | ConfigurationSection, |
268a74bb | 14 | type IncomingRequestCommand, |
5d049829 | 15 | type LogConfiguration, |
276e05ae | 16 | MapStringifyFormat, |
268a74bb JB |
17 | MessageType, |
18 | type RequestCommand, | |
19 | type Statistics, | |
94032f3e | 20 | type StatisticsData, |
5d049829 | 21 | type StorageConfiguration, |
66a7748d JB |
22 | type TimestampedData |
23 | } from '../types/index.js' | |
7671fa0b | 24 | import { |
4c3f6c20 | 25 | buildPerformanceStatisticsMessage, |
7671fa0b JB |
26 | Configuration, |
27 | Constants, | |
da55bd34 | 28 | extractTimeSeriesValues, |
9bf0ef23 JB |
29 | formatDurationSeconds, |
30 | generateUUID, | |
276e05ae | 31 | JSONStringify, |
7671fa0b | 32 | logger, |
4c3f6c20 | 33 | logPrefix, |
5adf6ca4 | 34 | max, |
5adf6ca4 | 35 | min, |
4884b8d3 | 36 | nthPercentile, |
66a7748d JB |
37 | stdDeviation |
38 | } from '../utils/index.js' | |
7dde0b73 | 39 | |
268a74bb | 40 | export class PerformanceStatistics { |
e7aeea18 | 41 | private static readonly instances: Map<string, PerformanceStatistics> = new Map< |
66a7748d JB |
42 | string, |
43 | PerformanceStatistics | |
44 | >() | |
10068088 | 45 | |
5199f9fd JB |
46 | private readonly objId: string | undefined |
47 | private readonly objName: string | undefined | |
66a7748d JB |
48 | private performanceObserver!: PerformanceObserver |
49 | private readonly statistics: Statistics | |
50 | private displayInterval?: NodeJS.Timeout | |
560bcf5b | 51 | |
2466918c JB |
52 | private constructor (objId: string, objName: string, uri: URL) { |
53 | this.objId = objId | |
54 | this.objName = objName | |
66a7748d | 55 | this.initializePerformanceObserver() |
e7aeea18 | 56 | this.statistics = { |
5199f9fd JB |
57 | id: this.objId, |
58 | name: this.objName, | |
e7aeea18 JB |
59 | uri: uri.toString(), |
60 | createdAt: new Date(), | |
66a7748d JB |
61 | statisticsData: new Map() |
62 | } | |
9f2e3130 JB |
63 | } |
64 | ||
66a7748d | 65 | public static getInstance ( |
2466918c JB |
66 | objId: string | undefined, |
67 | objName: string | undefined, | |
68 | uri: URL | undefined | |
844e496b | 69 | ): PerformanceStatistics | undefined { |
2466918c JB |
70 | if (objId == null) { |
71 | const errMsg = 'Cannot get performance statistics instance without specifying object id' | |
09e5a7a8 | 72 | logger.error(`${PerformanceStatistics.logPrefix()} ${errMsg}`) |
2466918c JB |
73 | throw new BaseError(errMsg) |
74 | } | |
75 | if (objName == null) { | |
76 | const errMsg = 'Cannot get performance statistics instance without specifying object name' | |
09e5a7a8 | 77 | logger.error(`${PerformanceStatistics.logPrefix()} ${errMsg}`) |
2466918c JB |
78 | throw new BaseError(errMsg) |
79 | } | |
80 | if (uri == null) { | |
81 | const errMsg = 'Cannot get performance statistics instance without specifying object uri' | |
09e5a7a8 | 82 | logger.error(`${PerformanceStatistics.logPrefix()} ${errMsg}`) |
2466918c JB |
83 | throw new BaseError(errMsg) |
84 | } | |
9f2e3130 | 85 | if (!PerformanceStatistics.instances.has(objId)) { |
66a7748d | 86 | PerformanceStatistics.instances.set(objId, new PerformanceStatistics(objId, objName, uri)) |
9f2e3130 | 87 | } |
66a7748d | 88 | return PerformanceStatistics.instances.get(objId) |
560bcf5b JB |
89 | } |
90 | ||
09e5a7a8 JB |
91 | public static deleteInstance (objId: string | undefined): boolean { |
92 | if (objId == null) { | |
93 | const errMsg = 'Cannot delete performance statistics instance without specifying object id' | |
94 | logger.error(`${PerformanceStatistics.logPrefix()} ${errMsg}`) | |
95 | throw new BaseError(errMsg) | |
96 | } | |
97 | return PerformanceStatistics.instances.delete(objId) | |
98 | } | |
99 | ||
66a7748d JB |
100 | public static beginMeasure (id: string): string { |
101 | const markId = `${id.charAt(0).toUpperCase()}${id.slice(1)}~${generateUUID()}` | |
102 | performance.mark(markId) | |
103 | return markId | |
57939a9d JB |
104 | } |
105 | ||
66a7748d | 106 | public static endMeasure (name: string, markId: string): void { |
b1bd4a15 | 107 | try { |
66a7748d | 108 | performance.measure(name, markId) |
b1bd4a15 | 109 | } catch (error) { |
8a4f882a | 110 | if (is(Error, error) && error.message.includes('performance mark has not been set')) { |
1fb21482 | 111 | /* Ignore */ |
b1bd4a15 | 112 | } else { |
66a7748d | 113 | throw error |
b1bd4a15 JB |
114 | } |
115 | } | |
66a7748d JB |
116 | performance.clearMarks(markId) |
117 | performance.clearMeasures(name) | |
aef1b33a JB |
118 | } |
119 | ||
66a7748d | 120 | public addRequestStatistic ( |
e7aeea18 | 121 | command: RequestCommand | IncomingRequestCommand, |
66a7748d | 122 | messageType: MessageType |
e7aeea18 | 123 | ): void { |
7f134aca | 124 | switch (messageType) { |
d2a64eb5 | 125 | case MessageType.CALL_MESSAGE: |
e7aeea18 JB |
126 | if ( |
127 | this.statistics.statisticsData.has(command) && | |
66a7748d | 128 | this.statistics.statisticsData.get(command)?.requestCount != null |
e7aeea18 | 129 | ) { |
66a7748d JB |
130 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
131 | ++this.statistics.statisticsData.get(command)!.requestCount! | |
7dde0b73 | 132 | } else { |
71910904 JB |
133 | this.statistics.statisticsData.set(command, { |
134 | ...this.statistics.statisticsData.get(command), | |
66a7748d JB |
135 | requestCount: 1 |
136 | }) | |
7f134aca | 137 | } |
66a7748d | 138 | break |
d2a64eb5 | 139 | case MessageType.CALL_RESULT_MESSAGE: |
e7aeea18 JB |
140 | if ( |
141 | this.statistics.statisticsData.has(command) && | |
66a7748d | 142 | this.statistics.statisticsData.get(command)?.responseCount != null |
e7aeea18 | 143 | ) { |
66a7748d JB |
144 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
145 | ++this.statistics.statisticsData.get(command)!.responseCount! | |
7f134aca | 146 | } else { |
71910904 JB |
147 | this.statistics.statisticsData.set(command, { |
148 | ...this.statistics.statisticsData.get(command), | |
66a7748d JB |
149 | responseCount: 1 |
150 | }) | |
7dde0b73 | 151 | } |
66a7748d | 152 | break |
d2a64eb5 | 153 | case MessageType.CALL_ERROR_MESSAGE: |
e7aeea18 JB |
154 | if ( |
155 | this.statistics.statisticsData.has(command) && | |
66a7748d | 156 | this.statistics.statisticsData.get(command)?.errorCount != null |
e7aeea18 | 157 | ) { |
66a7748d JB |
158 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
159 | ++this.statistics.statisticsData.get(command)!.errorCount! | |
7f134aca | 160 | } else { |
71910904 JB |
161 | this.statistics.statisticsData.set(command, { |
162 | ...this.statistics.statisticsData.get(command), | |
66a7748d JB |
163 | errorCount: 1 |
164 | }) | |
7f134aca | 165 | } |
66a7748d | 166 | break |
7f134aca | 167 | default: |
9534e74e | 168 | // eslint-disable-next-line @typescript-eslint/restrict-template-expressions |
66a7748d JB |
169 | logger.error(`${this.logPrefix()} wrong message type ${messageType}`) |
170 | break | |
7dde0b73 JB |
171 | } |
172 | } | |
173 | ||
66a7748d JB |
174 | public start (): void { |
175 | this.startLogStatisticsInterval() | |
864e5f8d | 176 | const performanceStorageConfiguration = |
5d049829 | 177 | Configuration.getConfigurationSection<StorageConfiguration>( |
66a7748d JB |
178 | ConfigurationSection.performanceStorage |
179 | ) | |
180 | if (performanceStorageConfiguration.enabled === true) { | |
e7aeea18 | 181 | logger.info( |
48847bc0 JB |
182 | `${this.logPrefix()} storage enabled: type ${ |
183 | performanceStorageConfiguration.type | |
184 | }, uri: ${performanceStorageConfiguration.uri}` | |
66a7748d | 185 | ) |
72f041bd | 186 | } |
7dde0b73 JB |
187 | } |
188 | ||
66a7748d JB |
189 | public stop (): void { |
190 | this.stopLogStatisticsInterval() | |
191 | performance.clearMarks() | |
192 | performance.clearMeasures() | |
5199f9fd | 193 | this.performanceObserver.disconnect() |
087a502d JB |
194 | } |
195 | ||
66a7748d JB |
196 | public restart (): void { |
197 | this.stop() | |
198 | this.start() | |
136c90ba JB |
199 | } |
200 | ||
66a7748d | 201 | private initializePerformanceObserver (): void { |
a974c8e4 | 202 | this.performanceObserver = new PerformanceObserver(performanceObserverList => { |
66a7748d | 203 | const lastPerformanceEntry = performanceObserverList.getEntries()[0] |
9d1dc4b1 JB |
204 | // logger.debug( |
205 | // `${this.logPrefix()} '${lastPerformanceEntry.name}' performance entry: %j`, | |
66a7748d JB |
206 | // lastPerformanceEntry |
207 | // ) | |
208 | this.addPerformanceEntryToStatistics(lastPerformanceEntry) | |
209 | }) | |
210 | this.performanceObserver.observe({ entryTypes: ['measure'] }) | |
aef1b33a JB |
211 | } |
212 | ||
66a7748d | 213 | private logStatistics (): void { |
5199f9fd | 214 | logger.info(this.logPrefix(), { |
c60af6ca | 215 | ...this.statistics, |
94032f3e | 216 | statisticsData: JSON.parse( |
276e05ae | 217 | JSONStringify(this.statistics.statisticsData, undefined, MapStringifyFormat.object) |
94032f3e | 218 | ) as Map<string | RequestCommand | IncomingRequestCommand, StatisticsData> |
66a7748d | 219 | }) |
7dde0b73 JB |
220 | } |
221 | ||
66a7748d | 222 | private startLogStatisticsInterval (): void { |
864e5f8d | 223 | const logConfiguration = Configuration.getConfigurationSection<LogConfiguration>( |
66a7748d JB |
224 | ConfigurationSection.log |
225 | ) | |
226 | const logStatisticsInterval = | |
227 | logConfiguration.enabled === true | |
228 | ? // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
229 | logConfiguration.statisticsInterval! | |
230 | : 0 | |
231 | if (logStatisticsInterval > 0 && this.displayInterval == null) { | |
aef1b33a | 232 | this.displayInterval = setInterval(() => { |
66a7748d JB |
233 | this.logStatistics() |
234 | }, secondsToMilliseconds(logStatisticsInterval)) | |
e7aeea18 | 235 | logger.info( |
66a7748d JB |
236 | `${this.logPrefix()} logged every ${formatDurationSeconds(logStatisticsInterval)}` |
237 | ) | |
238 | } else if (this.displayInterval != null) { | |
dfe81c8f | 239 | logger.info( |
66a7748d JB |
240 | `${this.logPrefix()} already logged every ${formatDurationSeconds(logStatisticsInterval)}` |
241 | ) | |
242 | } else if (logConfiguration.enabled === true) { | |
e7aeea18 | 243 | logger.info( |
66a7748d JB |
244 | `${this.logPrefix()} log interval is set to ${logStatisticsInterval}. Not logging statistics` |
245 | ) | |
7dde0b73 JB |
246 | } |
247 | } | |
248 | ||
66a7748d JB |
249 | private stopLogStatisticsInterval (): void { |
250 | if (this.displayInterval != null) { | |
251 | clearInterval(this.displayInterval) | |
252 | delete this.displayInterval | |
8f953431 JB |
253 | } |
254 | } | |
255 | ||
66a7748d | 256 | private addPerformanceEntryToStatistics (entry: PerformanceEntry): void { |
7ec46a9a | 257 | // Initialize command statistics |
d71b025f | 258 | if (!this.statistics.statisticsData.has(entry.name)) { |
66a7748d | 259 | this.statistics.statisticsData.set(entry.name, {}) |
7ec46a9a | 260 | } |
b49422c6 | 261 | // Update current statistics |
66a7748d | 262 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
d71b025f | 263 | this.statistics.statisticsData.get(entry.name)!.timeMeasurementCount = |
66a7748d JB |
264 | (this.statistics.statisticsData.get(entry.name)?.timeMeasurementCount ?? 0) + 1 |
265 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
266 | this.statistics.statisticsData.get(entry.name)!.currentTimeMeasurement = entry.duration | |
267 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
d71b025f | 268 | this.statistics.statisticsData.get(entry.name)!.minTimeMeasurement = min( |
a8735ef9 | 269 | entry.duration, |
cffc32b7 | 270 | this.statistics.statisticsData.get(entry.name)?.minTimeMeasurement ?? Number.POSITIVE_INFINITY |
66a7748d JB |
271 | ) |
272 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
d71b025f | 273 | this.statistics.statisticsData.get(entry.name)!.maxTimeMeasurement = max( |
a8735ef9 | 274 | entry.duration, |
cffc32b7 | 275 | this.statistics.statisticsData.get(entry.name)?.maxTimeMeasurement ?? Number.NEGATIVE_INFINITY |
66a7748d JB |
276 | ) |
277 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
d71b025f | 278 | this.statistics.statisticsData.get(entry.name)!.totalTimeMeasurement = |
66a7748d | 279 | (this.statistics.statisticsData.get(entry.name)?.totalTimeMeasurement ?? 0) + entry.duration |
840ca85d JB |
280 | if ( |
281 | !( | |
282 | this.statistics.statisticsData.get(entry.name)?.measurementTimeSeries instanceof | |
283 | CircularBuffer | |
284 | ) | |
285 | ) { | |
286 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
287 | this.statistics.statisticsData.get(entry.name)!.measurementTimeSeries = | |
288 | new CircularBuffer<TimestampedData>( | |
289 | Array<TimestampedData>, | |
290 | Constants.DEFAULT_CIRCULAR_BUFFER_CAPACITY | |
291 | ) | |
292 | } | |
48847bc0 JB |
293 | this.statistics.statisticsData.get(entry.name)?.measurementTimeSeries?.push({ |
294 | timestamp: entry.startTime, | |
295 | value: entry.duration | |
296 | }) | |
d4004f32 | 297 | const timeMeasurementValues = extractTimeSeriesValues( |
66a7748d | 298 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
1c818bd3 JB |
299 | this.statistics.statisticsData.get(entry.name)! |
300 | .measurementTimeSeries as CircularBuffer<TimestampedData> | |
66a7748d JB |
301 | ) |
302 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
c17a8d29 | 303 | this.statistics.statisticsData.get(entry.name)!.avgTimeMeasurement = mean(timeMeasurementValues) |
66a7748d | 304 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
d71b025f | 305 | this.statistics.statisticsData.get(entry.name)!.medTimeMeasurement = |
66a7748d JB |
306 | median(timeMeasurementValues) |
307 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
d71b025f | 308 | this.statistics.statisticsData.get(entry.name)!.ninetyFiveThPercentileTimeMeasurement = |
66a7748d JB |
309 | nthPercentile(timeMeasurementValues, 95) |
310 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion | |
d71b025f | 311 | this.statistics.statisticsData.get(entry.name)!.stdDevTimeMeasurement = stdDeviation( |
d4004f32 | 312 | timeMeasurementValues, |
66a7748d JB |
313 | // eslint-disable-next-line @typescript-eslint/no-non-null-assertion |
314 | this.statistics.statisticsData.get(entry.name)!.avgTimeMeasurement | |
315 | ) | |
316 | this.statistics.updatedAt = new Date() | |
5d049829 JB |
317 | if ( |
318 | Configuration.getConfigurationSection<StorageConfiguration>( | |
66a7748d JB |
319 | ConfigurationSection.performanceStorage |
320 | ).enabled === true | |
5d049829 | 321 | ) { |
66a7748d | 322 | parentPort?.postMessage(buildPerformanceStatisticsMessage(this.statistics)) |
72f041bd | 323 | } |
7ec46a9a JB |
324 | } |
325 | ||
09e5a7a8 JB |
326 | private static readonly logPrefix = (): string => { |
327 | return logPrefix(' Performance statistics') | |
328 | } | |
329 | ||
66a7748d JB |
330 | private readonly logPrefix = (): string => { |
331 | return logPrefix(` ${this.objName} | Performance statistics`) | |
332 | } | |
7dde0b73 | 333 | } |