|
| 1 | +'use strict' |
| 2 | + |
| 3 | +/** |
| 4 | + * This code is based on `latency-monitor` (https://github.com/mlucool/latency-monitor) by `mlucool` (https://github.com/mlucool), available under Apache License 2.0 (https://github.com/mlucool/latency-monitor/blob/master/LICENSE) |
| 5 | + */ |
| 6 | + |
| 7 | +/* global window */ |
| 8 | +const globalThis = require('ipfs-utils/src/globalthis') |
| 9 | +const EventEmitter = require('events') |
| 10 | +const VisibilityChangeEmitter = require('./visibility-change-emitter') |
| 11 | +const debug = require('debug')('latency-monitor:LatencyMonitor') |
| 12 | + |
| 13 | +/** |
| 14 | + * @typedef {Object} SummaryObject |
| 15 | + * @property {Number} events How many events were called |
| 16 | + * @property {Number} minMS What was the min time for a cb to be called |
| 17 | + * @property {Number} maxMS What was the max time for a cb to be called |
| 18 | + * @property {Number} avgMs What was the average time for a cb to be called |
| 19 | + * @property {Number} lengthMs How long this interval was in ms |
| 20 | + */ |
| 21 | + |
| 22 | +/** |
| 23 | + * A class to monitor latency of any async function which works in a browser or node. This works by periodically calling |
| 24 | + * the asyncTestFn and timing how long it takes the callback to be called. It can also periodically emit stats about this. |
| 25 | + * This can be disabled and stats can be pulled via setting dataEmitIntervalMs = 0. |
| 26 | + * |
| 27 | + * The default implementation is an event loop latency monitor. This works by firing periodic events into the event loop |
| 28 | + * and timing how long it takes to get back. |
| 29 | + * |
| 30 | + * @example |
| 31 | + * const monitor = new LatencyMonitor(); |
| 32 | + * monitor.on('data', (summary) => console.log('Event Loop Latency: %O', summary)); |
| 33 | + * |
| 34 | + * @example |
| 35 | + * const monitor = new LatencyMonitor({latencyCheckIntervalMs: 1000, dataEmitIntervalMs: 60000, asyncTestFn:ping}); |
| 36 | + * monitor.on('data', (summary) => console.log('Ping Pong Latency: %O', summary)); |
| 37 | + */ |
| 38 | +class LatencyMonitor extends EventEmitter { |
| 39 | + /** |
| 40 | + * @param {Number} [latencyCheckIntervalMs=500] How often to add a latency check event (ms) |
| 41 | + * @param {Number} [dataEmitIntervalMs=5000] How often to summarize latency check events. null or 0 disables event firing |
| 42 | + * @param {function} [asyncTestFn] What cb-style async function to use |
| 43 | + * @param {Number} [latencyRandomPercentage=5] What percent (+/-) of latencyCheckIntervalMs should we randomly use? This helps avoid alignment to other events. |
| 44 | + */ |
| 45 | + constructor ({ latencyCheckIntervalMs, dataEmitIntervalMs, asyncTestFn, latencyRandomPercentage } = {}) { |
| 46 | + super() |
| 47 | + const that = this |
| 48 | + |
| 49 | + // 0 isn't valid here, so its ok to use || |
| 50 | + that.latencyCheckIntervalMs = latencyCheckIntervalMs || 500 // 0.5s |
| 51 | + that.latencyRandomPercentage = latencyRandomPercentage || 10 |
| 52 | + that._latecyCheckMultiply = 2 * (that.latencyRandomPercentage / 100.0) * that.latencyCheckIntervalMs |
| 53 | + that._latecyCheckSubtract = that._latecyCheckMultiply / 2 |
| 54 | + |
| 55 | + that.dataEmitIntervalMs = (dataEmitIntervalMs === null || dataEmitIntervalMs === 0) ? undefined |
| 56 | + : dataEmitIntervalMs || 5 * 1000 // 5s |
| 57 | + debug('latencyCheckIntervalMs: %s dataEmitIntervalMs: %s', |
| 58 | + that.latencyCheckIntervalMs, that.dataEmitIntervalMs) |
| 59 | + if (that.dataEmitIntervalMs) { |
| 60 | + debug('Expecting ~%s events per summary', that.latencyCheckIntervalMs / that.dataEmitIntervalMs) |
| 61 | + } else { |
| 62 | + debug('Not emitting summaries') |
| 63 | + } |
| 64 | + |
| 65 | + that.asyncTestFn = asyncTestFn // If there is no asyncFn, we measure latency |
| 66 | + |
| 67 | + // If process: use high resolution timer |
| 68 | + if (globalThis.process && globalThis.process.hrtime) { |
| 69 | + debug('Using process.hrtime for timing') |
| 70 | + that.now = globalThis.process.hrtime |
| 71 | + that.getDeltaMS = (startTime) => { |
| 72 | + const hrtime = that.now(startTime) |
| 73 | + return (hrtime[0] * 1000) + (hrtime[1] / 1000000) |
| 74 | + } |
| 75 | + // Let's try for a timer that only monotonically increases |
| 76 | + } else if (typeof window !== 'undefined' && window.performance && window.performance.now) { |
| 77 | + debug('Using performance.now for timing') |
| 78 | + that.now = window.performance.now.bind(window.performance) |
| 79 | + that.getDeltaMS = (startTime) => Math.round(that.now() - startTime) |
| 80 | + } else { |
| 81 | + debug('Using Date.now for timing') |
| 82 | + that.now = Date.now |
| 83 | + that.getDeltaMS = (startTime) => that.now() - startTime |
| 84 | + } |
| 85 | + |
| 86 | + that._latencyData = that._initLatencyData() |
| 87 | + |
| 88 | + // We check for isBrowser because of browsers set max rates of timeouts when a page is hidden, |
| 89 | + // so we fall back to another library |
| 90 | + // See: http://stackoverflow.com/questions/6032429/chrome-timeouts-interval-suspended-in-background-tabs |
| 91 | + if (isBrowser()) { |
| 92 | + that._visibilityChangeEmitter = new VisibilityChangeEmitter() |
| 93 | + that._visibilityChangeEmitter.on('visibilityChange', (pageInFocus) => { |
| 94 | + if (pageInFocus) { |
| 95 | + that._startTimers() |
| 96 | + } else { |
| 97 | + that._emitSummary() |
| 98 | + that._stopTimers() |
| 99 | + } |
| 100 | + }) |
| 101 | + } |
| 102 | + |
| 103 | + if (!that._visibilityChangeEmitter || that._visibilityChangeEmitter.isVisible()) { |
| 104 | + that._startTimers() |
| 105 | + } |
| 106 | + } |
| 107 | + |
| 108 | + /** |
| 109 | + * Start internal timers |
| 110 | + * @private |
| 111 | + */ |
| 112 | + _startTimers () { |
| 113 | + // Timer already started, ignore this |
| 114 | + if (this._checkLatencyID) { |
| 115 | + return |
| 116 | + } |
| 117 | + this._checkLatency() |
| 118 | + if (this.dataEmitIntervalMs) { |
| 119 | + this._emitIntervalID = setInterval(() => this._emitSummary(), this.dataEmitIntervalMs) |
| 120 | + if (typeof this._emitIntervalID.unref === 'function') { |
| 121 | + this._emitIntervalID.unref() // Doesn't block exit |
| 122 | + } |
| 123 | + } |
| 124 | + } |
| 125 | + |
| 126 | + /** |
| 127 | + * Stop internal timers |
| 128 | + * @private |
| 129 | + */ |
| 130 | + _stopTimers () { |
| 131 | + if (this._checkLatencyID) { |
| 132 | + clearTimeout(this._checkLatencyID) |
| 133 | + this._checkLatencyID = undefined |
| 134 | + } |
| 135 | + if (this._emitIntervalID) { |
| 136 | + clearInterval(this._emitIntervalID) |
| 137 | + this._emitIntervalID = undefined |
| 138 | + } |
| 139 | + } |
| 140 | + |
| 141 | + /** |
| 142 | + * Emit summary only if there were events. It might not have any events if it was forced via a page hidden/show |
| 143 | + * @private |
| 144 | + */ |
| 145 | + _emitSummary () { |
| 146 | + const summary = this.getSummary() |
| 147 | + if (summary.events > 0) { |
| 148 | + this.emit('data', summary) |
| 149 | + } |
| 150 | + } |
| 151 | + |
| 152 | + /** |
| 153 | + * Calling this function will end the collection period. If a timing event was already fired and somewhere in the queue, |
| 154 | + * it will not count for this time period |
| 155 | + * @returns {SummaryObject} |
| 156 | + */ |
| 157 | + getSummary () { |
| 158 | + // We might want to adjust for the number of expected events |
| 159 | + // Example: first 1 event it comes back, then such a long blocker that the next emit check comes |
| 160 | + // Then this fires - looks like no latency!! |
| 161 | + const latency = { |
| 162 | + events: this._latencyData.events, |
| 163 | + minMs: this._latencyData.minMs, |
| 164 | + maxMs: this._latencyData.maxMs, |
| 165 | + avgMs: this._latencyData.events ? this._latencyData.totalMs / this._latencyData.events |
| 166 | + : Number.POSITIVE_INFINITY, |
| 167 | + lengthMs: this.getDeltaMS(this._latencyData.startTime) |
| 168 | + } |
| 169 | + this._latencyData = this._initLatencyData() // Clear |
| 170 | + |
| 171 | + debug('Summary: %O', latency) |
| 172 | + return latency |
| 173 | + } |
| 174 | + |
| 175 | + /** |
| 176 | + * Randomly calls an async fn every roughly latencyCheckIntervalMs (plus some randomness). If no async fn is found, |
| 177 | + * it will simply report on event loop latency. |
| 178 | + * |
| 179 | + * @private |
| 180 | + */ |
| 181 | + _checkLatency () { |
| 182 | + const that = this |
| 183 | + // Randomness is needed to avoid alignment by accident to regular things in the event loop |
| 184 | + const randomness = (Math.random() * that._latecyCheckMultiply) - that._latecyCheckSubtract |
| 185 | + |
| 186 | + // We use this to ensure that in case some overlap somehow, we don't take the wrong startTime/offset |
| 187 | + const localData = { |
| 188 | + deltaOffset: Math.ceil(that.latencyCheckIntervalMs + randomness), |
| 189 | + startTime: that.now() |
| 190 | + } |
| 191 | + |
| 192 | + const cb = () => { |
| 193 | + // We are already stopped, ignore this datapoint |
| 194 | + if (!this._checkLatencyID) { |
| 195 | + return |
| 196 | + } |
| 197 | + const deltaMS = that.getDeltaMS(localData.startTime) - localData.deltaOffset |
| 198 | + that._checkLatency() // Start again ASAP |
| 199 | + |
| 200 | + // Add the data point. If this gets complex, refactor it |
| 201 | + that._latencyData.events++ |
| 202 | + that._latencyData.minMs = Math.min(that._latencyData.minMs, deltaMS) |
| 203 | + that._latencyData.maxMs = Math.max(that._latencyData.maxMs, deltaMS) |
| 204 | + that._latencyData.totalMs += deltaMS |
| 205 | + debug('MS: %s Data: %O', deltaMS, that._latencyData) |
| 206 | + } |
| 207 | + debug('localData: %O', localData) |
| 208 | + |
| 209 | + this._checkLatencyID = setTimeout(() => { |
| 210 | + // This gets rid of including event loop |
| 211 | + if (that.asyncTestFn) { |
| 212 | + // Clear timing related things |
| 213 | + localData.deltaOffset = 0 |
| 214 | + localData.startTime = that.now() |
| 215 | + that.asyncTestFn(cb) |
| 216 | + } else { |
| 217 | + // setTimeout is not more accurate than 1ms, so this will ensure positive numbers. Add 1 to emitted data to remove. |
| 218 | + // This is not the best, but for now it'll be just fine. This isn't meant to be sub ms accurate. |
| 219 | + localData.deltaOffset -= 1 |
| 220 | + // If there is no function to test, we mean check latency which is a special case that is really cb => cb() |
| 221 | + // We avoid that for the few extra function all overheads. Also, we want to keep the timers different |
| 222 | + cb() |
| 223 | + } |
| 224 | + }, localData.deltaOffset) |
| 225 | + |
| 226 | + if (typeof this._checkLatencyID.unref === 'function') { |
| 227 | + this._checkLatencyID.unref() // Doesn't block exit |
| 228 | + } |
| 229 | + } |
| 230 | + |
| 231 | + _initLatencyData () { |
| 232 | + return { |
| 233 | + startTime: this.now(), |
| 234 | + minMs: Number.POSITIVE_INFINITY, |
| 235 | + maxMs: Number.NEGATIVE_INFINITY, |
| 236 | + events: 0, |
| 237 | + totalMs: 0 |
| 238 | + } |
| 239 | + } |
| 240 | +} |
| 241 | + |
| 242 | +function isBrowser () { |
| 243 | + return typeof window !== 'undefined' |
| 244 | +} |
| 245 | + |
| 246 | +module.exports = LatencyMonitor |
0 commit comments