diff --git a/flow-typed/npm/@isaacs/ttlcache_1.x.x.js b/flow-typed/npm/@isaacs/ttlcache_1.x.x.js new file mode 100644 index 00000000000..d39c43742b2 --- /dev/null +++ b/flow-typed/npm/@isaacs/ttlcache_1.x.x.js @@ -0,0 +1,227 @@ +/** + * @flow strict-local + * @format + */ + +declare module '@isaacs/ttlcache' { + declare export default class TTLCache implements Iterable<[K, V]> { + constructor(options?: TTLCache$Options): void; + + ttl: number; + max: number; + updateAgeOnGet: boolean; + checkAgeOnGet: boolean; + noUpdateTTL: boolean; + noDisposeOnSet: boolean; + + /** + * The total number of items held in the cache at the current moment. + */ + +size: number; + + /** + * Add a value to the cache. + */ + set(key: K, value: V, options?: TTLCache$SetOptions): this; + + /** + * Return a value from the cache. + * If the key is not found, `get()` will return `undefined`. + * This can be confusing when setting values specifically to `undefined`, + * as in `cache.set(key, undefined)`. Use `cache.has()` to determine + * whether a key is present in the cache at all. + */ + get(key: K, options?: TTLCache$GetOptions): T | void; + + /** + * Check if a key is in the cache. + * Will return false if the item is stale, even though it is technically + * in the cache. + */ + has(key: K): boolean; + + /** + * Deletes a key out of the cache. + * Returns true if the key was deleted, false otherwise. + */ + delete(key: K): boolean; + + /** + * Clear the cache entirely, throwing away all values. + */ + clear(): void; + + /** + * Delete any stale entries. Returns true if anything was removed, false + * otherwise. + */ + purgeStale(): boolean; + + /** + * Return the remaining time before an item expires. + * Returns 0 if the item is not found in the cache or is already expired. + */ + getRemainingTTL(key: K): number; + + /** + * Set the ttl explicitly to a value, defaulting to the TTL set on the ctor + */ + setTTL(key: K, ttl?: number): void; + + /** + * Return a generator yielding `[key, value]` pairs, from soonest expiring + * to latest expiring. (Items expiring at the same time are walked in insertion order.) + */ + entries(): Generator<[K, V], void, void>; + + /** + * Return a generator yielding the keys in the cache, + * from soonest expiring to latest expiring. + */ + keys(): Generator; + + /** + * Return a generator yielding the values in the cache, + * from soonest expiring to latest expiring. + */ + values(): Generator; + + /** + * Iterating over the cache itself yields the same results as + * `cache.entries()` + */ + @@iterator(): Iterator<[K, V]>; + + /** + * Cancel the timer and stop automatically expiring entries. + * This allows the process to gracefully exit where Timer.unref() + * is not available. + */ + cancelTimer(): void; + } + + declare type TTLCache$DisposeReason = 'evict' | 'set' | 'delete' | 'stale'; + + declare type TTLCache$Disposer = ( + value: V, + key: K, + reason: TTLCache$DisposeReason, + ) => void; + + declare type TTLCache$TTLOptions = { + /** + * Max time in milliseconds for items to live in cache before they are + * considered stale. Note that stale items are NOT preemptively removed + * by default, and MAY live in the cache, contributing to max, + * long after they have expired. + * + * Must be an integer number of ms, or Infinity. Defaults to `undefined`, + * meaning that a TTL must be set explicitly for each set() + */ + ttl?: number, + + /** + * Boolean flag to tell the cache to not update the TTL when + * setting a new value for an existing key (ie, when updating a value + * rather than inserting a new value). Note that the TTL value is + * _always_ set when adding a new entry into the cache. + * + * @default false + */ + noUpdateTTL?: boolean, + }; + + declare type TTLCache$Options = { + /** + * The number of items to keep. + * + * @default Infinity + */ + max?: number, + + /** + * Update the age of items on cache.get(), renewing their TTL + * + * @default false + */ + updateAgeOnGet?: boolean, + + /** + * In the event that an item's expiration timer hasn't yet fired, + * and an attempt is made to get() it, then return undefined and + * delete it, rather than returning the cached value. + * + * By default, items are only expired when their timer fires, so there's + * a bit of a "best effort" expiration, and the cache will return a value + * if it has one, even if it's technically stale. + * + * @default false + */ + checkAgeOnGet?: boolean, + + /** + * Do not call dispose() function when overwriting a key with a new value + * + * @default false + */ + noDisposeOnSet?: boolean, + + /** + * Function that is called on items when they are dropped from the cache. + * This can be handy if you want to close file descriptors or do other + * cleanup tasks when items are no longer accessible. Called with `key, + * value`. It's called before actually removing the item from the + * internal cache, so it is *NOT* safe to re-add them. + * Use `disposeAfter` if you wish to dispose items after they have been + * full removed, when it is safe to add them back to the cache. + */ + dispose?: TTLCache$Disposer, + ...TTLCache$TTLOptions, + }; + + declare type TTLCache$SetOptions = { + /** + * Do not call dispose() function when overwriting a key with a new value + * Overrides the value set in the constructor. + */ + noDisposeOnSet?: boolean, + + /** + * Do not update the TTL when overwriting an existing item. + */ + noUpdateTTL?: boolean, + + /** + * Override the default TTL for this one set() operation. + * Required if a TTL was not set in the constructor options. + */ + ttl?: number, + }; + + declare type TTLCache$GetOptions = { + /** + * Update the age of items on cache.get(), renewing their TTL + * + * @default false + */ + updateAgeOnGet?: boolean, + + /** + * In the event that an item's expiration timer hasn't yet fired, + * and an attempt is made to get() it, then return undefined and + * delete it, rather than returning the cached value. + * + * By default, items are only expired when their timer fires, so there's + * a bit of a "best effort" expiration, and the cache will return a value + * if it has one, even if it's technically stale. + * + * @default false + */ + checkAgeOnGet?: boolean, + + /** + * Set new TTL, applied only when `updateAgeOnGet` is true + */ + ttl?: number, + }; +} diff --git a/packages/dev-middleware/package.json b/packages/dev-middleware/package.json index f32f164ebb6..1d7767aef02 100644 --- a/packages/dev-middleware/package.json +++ b/packages/dev-middleware/package.json @@ -22,6 +22,7 @@ "dist" ], "dependencies": { + "@isaacs/ttlcache": "^1.4.1", "chrome-launcher": "^0.15.2", "connect": "^3.6.5", "debug": "^2.2.0", diff --git a/packages/dev-middleware/src/inspector-proxy/Device.js b/packages/dev-middleware/src/inspector-proxy/Device.js index 253aa573790..3879cf6bcfa 100644 --- a/packages/dev-middleware/src/inspector-proxy/Device.js +++ b/packages/dev-middleware/src/inspector-proxy/Device.js @@ -20,6 +20,7 @@ import type { SetBreakpointByUrlRequest, } from './types'; +import DeviceEventReporter from './DeviceEventReporter'; import * as fs from 'fs'; import * as path from 'path'; import fetch from 'node-fetch'; @@ -90,7 +91,7 @@ export default class Device { // Root of the project used for relative to absolute source path conversion. _projectRoot: string; - _eventReporter: ?EventReporter; + _deviceEventReporter: ?DeviceEventReporter; constructor( id: string, @@ -106,7 +107,9 @@ export default class Device { this._pages = []; this._deviceSocket = socket; this._projectRoot = projectRoot; - this._eventReporter = eventReporter; + this._deviceEventReporter = eventReporter + ? new DeviceEventReporter(eventReporter) + : null; // $FlowFixMe[incompatible-call] this._deviceSocket.on('message', (message: string) => { @@ -126,6 +129,7 @@ export default class Device { this._handleMessageFromDevice(parsedMessage); }); this._deviceSocket.on('close', () => { + this._deviceEventReporter?.logDisconnection('device'); // Device disconnected - close debugger connection. if (this._debuggerConnection) { this._debuggerConnection.socket.close(); @@ -163,10 +167,7 @@ export default class Device { // 2. Forwards all messages from the debugger to device as wrappedEvent // 3. Sends disconnect event to device when debugger connection socket closes. handleDebuggerConnection(socket: WS, pageId: string) { - this._eventReporter?.logEvent({ - type: 'connect_debugger_frontend', - status: 'success', - }); + this._deviceEventReporter?.logConnection('debugger'); // Disconnect current debugger if we already have debugger connected. if (this._debuggerConnection) { this._debuggerConnection.socket.close(); @@ -189,10 +190,14 @@ export default class Device { }, }); + // Clear any commands we were waiting on. + this._deviceEventReporter?.logDisconnection('debugger'); + // $FlowFixMe[incompatible-call] socket.on('message', (message: string) => { debug('(Debugger) -> (Proxy) (Device): ' + message); const debuggerRequest = JSON.parse(message); + this._deviceEventReporter?.logRequest(debuggerRequest, 'debugger'); const handled = this._interceptMessageFromDebugger( debuggerRequest, debuggerInfo, @@ -211,6 +216,7 @@ export default class Device { }); socket.on('close', () => { debug(`Debugger for page ${pageId} and ${this._name} disconnected.`); + this._deviceEventReporter?.logDisconnection('debugger'); this._sendMessageToDevice({ event: 'disconnect', payload: { @@ -315,6 +321,9 @@ export default class Device { } const parsedPayload = JSON.parse(message.payload.wrappedEvent); + if ('id' in parsedPayload) { + this._deviceEventReporter?.logResponse(parsedPayload, 'device'); + } if (this._debuggerConnection) { // Wrapping just to make flow happy :) @@ -392,6 +401,7 @@ export default class Device { ]; for (const message of toSend) { + this._deviceEventReporter?.logRequest(message, 'proxy'); this._sendMessageToDevice({ event: 'wrappedEvent', payload: { @@ -484,11 +494,13 @@ export default class Device { // // This is not an issue in VSCode/Nuclide where the IDE knows to resume // at its convenience. + const resumeMessage = {method: 'Debugger.resume', id: 0}; + this._deviceEventReporter?.logRequest(resumeMessage, 'proxy'); this._sendMessageToDevice({ event: 'wrappedEvent', payload: { pageId: this._mapToDevicePageId(debuggerInfo.pageId), - wrappedEvent: JSON.stringify({method: 'Debugger.resume', id: 0}), + wrappedEvent: JSON.stringify(resumeMessage), }, }); @@ -548,15 +560,19 @@ export default class Device { _processDebuggerGetScriptSource(req: GetScriptSourceRequest, socket: WS) { const sendSuccessResponse = (scriptSource: string) => { const result: GetScriptSourceResponse = {scriptSource}; - socket.send(JSON.stringify({id: req.id, result})); + const response = {id: req.id, result}; + socket.send(JSON.stringify(response)); + this._deviceEventReporter?.logResponse(response, 'proxy'); }; const sendErrorResponse = (error: string) => { // Tell the client that the request failed const result: ErrorResponse = {error: {message: error}}; - socket.send(JSON.stringify({id: req.id, result})); + const response = {id: req.id, result}; + socket.send(JSON.stringify(response)); // Send to the console as well, so the user can see it this._sendErrorToDebugger(error); + this._deviceEventReporter?.logResponse(response, 'proxy'); }; const pathToSource = this._scriptIdToSourcePathMapping.get( diff --git a/packages/dev-middleware/src/inspector-proxy/DeviceEventReporter.js b/packages/dev-middleware/src/inspector-proxy/DeviceEventReporter.js new file mode 100644 index 00000000000..b42a8b14745 --- /dev/null +++ b/packages/dev-middleware/src/inspector-proxy/DeviceEventReporter.js @@ -0,0 +1,147 @@ +/** + * Copyright (c) Meta Platforms, Inc. and affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + * + * @flow strict-local + * @format + */ + +import type {EventReporter} from '../types/EventReporter'; +import TTLCache from '@isaacs/ttlcache'; + +type PendingCommand = { + method: string, + requestOrigin: 'proxy' | 'debugger', + requestTime: number, +}; + +class DeviceEventReporter { + _eventReporter: EventReporter; + + _pendingCommands: TTLCache = new TTLCache({ + ttl: 10000, + dispose: ( + command: PendingCommand, + id: number, + reason: 'evict' | 'set' | 'delete' | 'stale', + ) => { + if (reason === 'delete' || reason === 'set') { + // TODO: Report clobbering ('set') using a dedicated error code + return; + } + this._logExpiredCommand(command); + }, + }); + + constructor(eventReporter: EventReporter) { + this._eventReporter = eventReporter; + } + + logRequest( + req: $ReadOnly<{id: number, method: string, ...}>, + origin: 'debugger' | 'proxy', + ): void { + this._pendingCommands.set(req.id, { + method: req.method, + requestOrigin: origin, + requestTime: Date.now(), + }); + } + + logResponse( + res: $ReadOnly<{ + id: number, + error?: {message: string, data?: mixed}, + ... + }>, + origin: 'device' | 'proxy', + ): void { + const pendingCommand = this._pendingCommands.get(res.id); + if (!pendingCommand) { + this._eventReporter.logEvent({ + type: 'debugger_command', + protocol: 'CDP', + requestOrigin: null, + method: null, + status: 'coded_error', + errorCode: 'UNMATCHED_REQUEST_ID', + responseOrigin: 'proxy', + timeSinceStart: null, + }); + return; + } + const timeSinceStart = Date.now() - pendingCommand.requestTime; + this._pendingCommands.delete(res.id); + if (res.error) { + let {message} = res.error; + if ('data' in res.error) { + message += ` (${String(res.error.data)})`; + } + this._eventReporter.logEvent({ + type: 'debugger_command', + requestOrigin: pendingCommand.requestOrigin, + method: pendingCommand.method, + protocol: 'CDP', + status: 'coded_error', + errorCode: 'PROTOCOL_ERROR', + errorDetails: message, + responseOrigin: origin, + timeSinceStart, + }); + return; + } + this._eventReporter.logEvent({ + type: 'debugger_command', + protocol: 'CDP', + requestOrigin: pendingCommand.requestOrigin, + method: pendingCommand.method, + status: 'success', + responseOrigin: origin, + timeSinceStart, + }); + } + + logConnection(connectedEntity: 'debugger') { + this._eventReporter?.logEvent({ + type: 'connect_debugger_frontend', + status: 'success', + }); + } + + logDisconnection(disconnectedEntity: 'device' | 'debugger') { + const errorCode = + disconnectedEntity === 'device' + ? 'DEVICE_DISCONNECTED' + : 'DEBUGGER_DISCONNECTED'; + for (const pendingCommand of this._pendingCommands.values()) { + this._eventReporter.logEvent({ + type: 'debugger_command', + protocol: 'CDP', + requestOrigin: pendingCommand.requestOrigin, + method: pendingCommand.method, + status: 'coded_error', + errorCode, + responseOrigin: 'proxy', + timeSinceStart: Date.now() - pendingCommand.requestTime, + }); + } + this._pendingCommands.clear(); + } + + _logExpiredCommand(pendingCommand: PendingCommand): void { + this._eventReporter.logEvent({ + type: 'debugger_command', + protocol: 'CDP', + requestOrigin: pendingCommand.requestOrigin, + method: pendingCommand.method, + status: 'coded_error', + errorCode: 'TIMED_OUT', + responseOrigin: 'proxy', + timeSinceStart: Date.now() - pendingCommand.requestTime, + }); + } +} + +export default DeviceEventReporter; diff --git a/packages/dev-middleware/src/types/EventReporter.js b/packages/dev-middleware/src/types/EventReporter.js index ef1757a4041..3f097989d6d 100644 --- a/packages/dev-middleware/src/types/EventReporter.js +++ b/packages/dev-middleware/src/types/EventReporter.js @@ -35,6 +35,24 @@ export type ReportableEvent = | { type: 'connect_debugger_frontend', ...SuccessResult | ErrorResult, + } + | { + type: 'debugger_command', + protocol: 'CDP', + // With some errors, the method might not be known + method: string | null, + requestOrigin: 'proxy' | 'debugger' | null, + responseOrigin: 'proxy' | 'device', + timeSinceStart: number | null, + ... + | SuccessResult + | CodedErrorResult< + | 'TIMED_OUT' + | 'DEVICE_DISCONNECTED' + | 'DEBUGGER_DISCONNECTED' + | 'UNMATCHED_REQUEST_ID' + | 'PROTOCOL_ERROR', + >, }; /** diff --git a/yarn.lock b/yarn.lock index e4002925d2c..37db24adfe2 100644 --- a/yarn.lock +++ b/yarn.lock @@ -2061,6 +2061,11 @@ wrap-ansi "^8.1.0" wrap-ansi-cjs "npm:wrap-ansi@^7.0.0" +"@isaacs/ttlcache@^1.4.1": + version "1.4.1" + resolved "https://registry.yarnpkg.com/@isaacs/ttlcache/-/ttlcache-1.4.1.tgz#21fb23db34e9b6220c6ba023a0118a2dd3461ea2" + integrity sha512-RQgQ4uQ+pLbqXfOmieB91ejmLwvSgv9nLx6sT6sD83s7umBypgg+OIBOBbEUiJXrfpnp9j0mRhYYdzp9uqq3lA== + "@istanbuljs/load-nyc-config@^1.0.0": version "1.1.0" resolved "https://registry.yarnpkg.com/@istanbuljs/load-nyc-config/-/load-nyc-config-1.1.0.tgz#fd3db1d59ecf7cf121e80650bb86712f9b55eced"