| 1 | // Partial Copyright Jerome Benoit. 2021-2023. All Rights Reserved. |
| 2 | |
| 3 | import { type PerformanceEntry, PerformanceObserver, performance } from 'node:perf_hooks'; |
| 4 | import type { URL } from 'node:url'; |
| 5 | import { parentPort } from 'node:worker_threads'; |
| 6 | |
| 7 | import { secondsToMilliseconds } from 'date-fns'; |
| 8 | |
| 9 | import { |
| 10 | ConfigurationSection, |
| 11 | type IncomingRequestCommand, |
| 12 | type LogConfiguration, |
| 13 | MessageType, |
| 14 | type RequestCommand, |
| 15 | type Statistics, |
| 16 | type StorageConfiguration, |
| 17 | type TimestampedData, |
| 18 | } from '../types'; |
| 19 | import { |
| 20 | CircularArray, |
| 21 | Configuration, |
| 22 | Constants, |
| 23 | JSONStringifyWithMapSupport, |
| 24 | average, |
| 25 | buildPerformanceStatisticsMessage, |
| 26 | extractTimeSeriesValues, |
| 27 | formatDurationSeconds, |
| 28 | generateUUID, |
| 29 | logPrefix, |
| 30 | logger, |
| 31 | max, |
| 32 | median, |
| 33 | min, |
| 34 | nthPercentile, |
| 35 | stdDeviation, |
| 36 | } from '../utils'; |
| 37 | |
| 38 | export class PerformanceStatistics { |
| 39 | private static readonly instances: Map<string, PerformanceStatistics> = new Map< |
| 40 | string, |
| 41 | PerformanceStatistics |
| 42 | >(); |
| 43 | |
| 44 | private readonly objId: string; |
| 45 | private readonly objName: string; |
| 46 | private performanceObserver!: PerformanceObserver; |
| 47 | private readonly statistics: Statistics; |
| 48 | private displayInterval?: NodeJS.Timeout; |
| 49 | |
| 50 | private constructor(objId: string, objName: string, uri: URL) { |
| 51 | this.objId = objId; |
| 52 | this.objName = objName; |
| 53 | this.initializePerformanceObserver(); |
| 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(), |
| 59 | statisticsData: new Map(), |
| 60 | }; |
| 61 | } |
| 62 | |
| 63 | public static getInstance( |
| 64 | objId: string, |
| 65 | objName: string, |
| 66 | uri: URL, |
| 67 | ): PerformanceStatistics | undefined { |
| 68 | if (!PerformanceStatistics.instances.has(objId)) { |
| 69 | PerformanceStatistics.instances.set(objId, new PerformanceStatistics(objId, objName, uri)); |
| 70 | } |
| 71 | return PerformanceStatistics.instances.get(objId); |
| 72 | } |
| 73 | |
| 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; |
| 78 | } |
| 79 | |
| 80 | public static endMeasure(name: string, markId: string): void { |
| 81 | performance.measure(name, markId); |
| 82 | performance.clearMarks(markId); |
| 83 | performance.clearMeasures(name); |
| 84 | } |
| 85 | |
| 86 | public addRequestStatistic( |
| 87 | command: RequestCommand | IncomingRequestCommand, |
| 88 | messageType: MessageType, |
| 89 | ): void { |
| 90 | switch (messageType) { |
| 91 | case MessageType.CALL_MESSAGE: |
| 92 | if ( |
| 93 | this.statistics.statisticsData.has(command) && |
| 94 | this.statistics.statisticsData.get(command)?.requestCount |
| 95 | ) { |
| 96 | ++this.statistics.statisticsData.get(command)!.requestCount!; |
| 97 | } else { |
| 98 | this.statistics.statisticsData.set(command, { |
| 99 | ...this.statistics.statisticsData.get(command), |
| 100 | requestCount: 1, |
| 101 | }); |
| 102 | } |
| 103 | break; |
| 104 | case MessageType.CALL_RESULT_MESSAGE: |
| 105 | if ( |
| 106 | this.statistics.statisticsData.has(command) && |
| 107 | this.statistics.statisticsData.get(command)?.responseCount |
| 108 | ) { |
| 109 | ++this.statistics.statisticsData.get(command)!.responseCount!; |
| 110 | } else { |
| 111 | this.statistics.statisticsData.set(command, { |
| 112 | ...this.statistics.statisticsData.get(command), |
| 113 | responseCount: 1, |
| 114 | }); |
| 115 | } |
| 116 | break; |
| 117 | case MessageType.CALL_ERROR_MESSAGE: |
| 118 | if ( |
| 119 | this.statistics.statisticsData.has(command) && |
| 120 | this.statistics.statisticsData.get(command)?.errorCount |
| 121 | ) { |
| 122 | ++this.statistics.statisticsData.get(command)!.errorCount!; |
| 123 | } else { |
| 124 | this.statistics.statisticsData.set(command, { |
| 125 | ...this.statistics.statisticsData.get(command), |
| 126 | errorCount: 1, |
| 127 | }); |
| 128 | } |
| 129 | break; |
| 130 | default: |
| 131 | // eslint-disable-next-line @typescript-eslint/restrict-template-expressions |
| 132 | logger.error(`${this.logPrefix()} wrong message type ${messageType}`); |
| 133 | break; |
| 134 | } |
| 135 | } |
| 136 | |
| 137 | public start(): void { |
| 138 | this.startLogStatisticsInterval(); |
| 139 | const performanceStorageConfiguration = |
| 140 | Configuration.getConfigurationSection<StorageConfiguration>( |
| 141 | ConfigurationSection.performanceStorage, |
| 142 | ); |
| 143 | if (performanceStorageConfiguration.enabled) { |
| 144 | logger.info( |
| 145 | `${this.logPrefix()} storage enabled: type ${performanceStorageConfiguration.type}, uri: ${ |
| 146 | performanceStorageConfiguration.uri |
| 147 | }`, |
| 148 | ); |
| 149 | } |
| 150 | } |
| 151 | |
| 152 | public stop(): void { |
| 153 | this.stopLogStatisticsInterval(); |
| 154 | performance.clearMarks(); |
| 155 | performance.clearMeasures(); |
| 156 | this.performanceObserver?.disconnect(); |
| 157 | } |
| 158 | |
| 159 | public restart(): void { |
| 160 | this.stop(); |
| 161 | this.start(); |
| 162 | } |
| 163 | |
| 164 | private initializePerformanceObserver(): void { |
| 165 | this.performanceObserver = new PerformanceObserver((performanceObserverList) => { |
| 166 | const lastPerformanceEntry = performanceObserverList.getEntries()[0]; |
| 167 | // logger.debug( |
| 168 | // `${this.logPrefix()} '${lastPerformanceEntry.name}' performance entry: %j`, |
| 169 | // lastPerformanceEntry, |
| 170 | // ); |
| 171 | this.addPerformanceEntryToStatistics(lastPerformanceEntry); |
| 172 | }); |
| 173 | this.performanceObserver.observe({ entryTypes: ['measure'] }); |
| 174 | } |
| 175 | |
| 176 | private logStatistics(): void { |
| 177 | logger.info(`${this.logPrefix()}`, { |
| 178 | ...this.statistics, |
| 179 | statisticsData: JSONStringifyWithMapSupport(this.statistics.statisticsData), |
| 180 | }); |
| 181 | } |
| 182 | |
| 183 | private startLogStatisticsInterval(): void { |
| 184 | const logConfiguration = Configuration.getConfigurationSection<LogConfiguration>( |
| 185 | ConfigurationSection.log, |
| 186 | ); |
| 187 | const logStatisticsInterval = logConfiguration.enabled |
| 188 | ? logConfiguration.statisticsInterval! |
| 189 | : 0; |
| 190 | if (logStatisticsInterval > 0 && !this.displayInterval) { |
| 191 | this.displayInterval = setInterval(() => { |
| 192 | this.logStatistics(); |
| 193 | }, secondsToMilliseconds(logStatisticsInterval)); |
| 194 | logger.info( |
| 195 | `${this.logPrefix()} logged every ${formatDurationSeconds(logStatisticsInterval)}`, |
| 196 | ); |
| 197 | } else if (this.displayInterval) { |
| 198 | logger.info( |
| 199 | `${this.logPrefix()} already logged every ${formatDurationSeconds(logStatisticsInterval)}`, |
| 200 | ); |
| 201 | } else if (logConfiguration.enabled) { |
| 202 | logger.info( |
| 203 | `${this.logPrefix()} log interval is set to ${logStatisticsInterval}. Not logging statistics`, |
| 204 | ); |
| 205 | } |
| 206 | } |
| 207 | |
| 208 | private stopLogStatisticsInterval(): void { |
| 209 | if (this.displayInterval) { |
| 210 | clearInterval(this.displayInterval); |
| 211 | delete this.displayInterval; |
| 212 | } |
| 213 | } |
| 214 | |
| 215 | private addPerformanceEntryToStatistics(entry: PerformanceEntry): void { |
| 216 | // Initialize command statistics |
| 217 | if (!this.statistics.statisticsData.has(entry.name)) { |
| 218 | this.statistics.statisticsData.set(entry.name, {}); |
| 219 | } |
| 220 | // Update current statistics |
| 221 | this.statistics.statisticsData.get(entry.name)!.timeMeasurementCount = |
| 222 | (this.statistics.statisticsData.get(entry.name)?.timeMeasurementCount ?? 0) + 1; |
| 223 | this.statistics.statisticsData.get(entry.name)!.currentTimeMeasurement = entry.duration; |
| 224 | this.statistics.statisticsData.get(entry.name)!.minTimeMeasurement = min( |
| 225 | entry.duration, |
| 226 | this.statistics.statisticsData.get(entry.name)?.minTimeMeasurement ?? Infinity, |
| 227 | ); |
| 228 | this.statistics.statisticsData.get(entry.name)!.maxTimeMeasurement = max( |
| 229 | entry.duration, |
| 230 | this.statistics.statisticsData.get(entry.name)?.maxTimeMeasurement ?? -Infinity, |
| 231 | ); |
| 232 | this.statistics.statisticsData.get(entry.name)!.totalTimeMeasurement = |
| 233 | (this.statistics.statisticsData.get(entry.name)?.totalTimeMeasurement ?? 0) + entry.duration; |
| 234 | this.statistics.statisticsData.get(entry.name)?.measurementTimeSeries instanceof CircularArray |
| 235 | ? this.statistics.statisticsData |
| 236 | .get(entry.name) |
| 237 | ?.measurementTimeSeries?.push({ timestamp: entry.startTime, value: entry.duration }) |
| 238 | : (this.statistics.statisticsData.get(entry.name)!.measurementTimeSeries = |
| 239 | new CircularArray<TimestampedData>(Constants.DEFAULT_CIRCULAR_BUFFER_CAPACITY, { |
| 240 | timestamp: entry.startTime, |
| 241 | value: entry.duration, |
| 242 | })); |
| 243 | const timeMeasurementValues = extractTimeSeriesValues( |
| 244 | this.statistics.statisticsData.get(entry.name)!.measurementTimeSeries!, |
| 245 | ); |
| 246 | this.statistics.statisticsData.get(entry.name)!.avgTimeMeasurement = |
| 247 | average(timeMeasurementValues); |
| 248 | this.statistics.statisticsData.get(entry.name)!.medTimeMeasurement = |
| 249 | median(timeMeasurementValues); |
| 250 | this.statistics.statisticsData.get(entry.name)!.ninetyFiveThPercentileTimeMeasurement = |
| 251 | nthPercentile(timeMeasurementValues, 95); |
| 252 | this.statistics.statisticsData.get(entry.name)!.stdDevTimeMeasurement = stdDeviation( |
| 253 | timeMeasurementValues, |
| 254 | this.statistics.statisticsData.get(entry.name)!.avgTimeMeasurement, |
| 255 | ); |
| 256 | this.statistics.updatedAt = new Date(); |
| 257 | if ( |
| 258 | Configuration.getConfigurationSection<StorageConfiguration>( |
| 259 | ConfigurationSection.performanceStorage, |
| 260 | ).enabled |
| 261 | ) { |
| 262 | parentPort?.postMessage(buildPerformanceStatisticsMessage(this.statistics)); |
| 263 | } |
| 264 | } |
| 265 | |
| 266 | private logPrefix = (): string => { |
| 267 | return logPrefix(` ${this.objName} | Performance statistics`); |
| 268 | }; |
| 269 | } |