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