Filip/playwright
1
0
Fork 0
Code Issues Pull requests Actions Packages Projects Releases Wiki Activity

chore: move progress log into the metadata (#5411)

Browse source
This commit is contained in:
Pavel Feldman 2021-02-10 21:50:29 -08:00 committed by GitHub
parent a164f2a810
commit 6e6e36b565
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 43 additions and 41 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

8
src/dispatchers/dispatcher.ts
View file

@ -18,10 +18,11 @@ import { EventEmitter } from 'events';
import * as channels from '../protocol/channels';
import { serializeError } from '../protocol/serializers';
import { createScheme, Validator, ValidationError } from '../protocol/validator';
import { assert, createGuid, debugAssert, isUnderTest } from '../utils/utils';
import { assert, createGuid, debugAssert, isUnderTest, monotonicTime } from '../utils/utils';
import { tOptional } from '../protocol/validatorPrimitives';
import { kBrowserOrContextClosedError } from '../utils/errors';
import { CallMetadata } from '../server/instrumentation';
import { StackFrame } from '../common/types';
export const dispatcherSymbol = Symbol('dispatcher');
@ -124,7 +125,7 @@ export class DispatcherConnection {
private _rootDispatcher: Root;
onmessage = (message: object) => {};
private _validateParams: (type: string, method: string, params: any) => any;
private _validateMetadata: (metadata: any) => any;
private _validateMetadata: (metadata: any) => { stack?: StackFrame[] };
sendMessageToClient(guid: string, method: string, params: any) {
this.onmessage({ guid, method, params: this._replaceDispatchersWithGuids(params) });
@ -180,9 +181,12 @@ export class DispatcherConnection {
throw new Error(`Mismatching dispatcher: "${dispatcher._type}" does not implement "${method}"`);
const callMetadata: CallMetadata = {
...this._validateMetadata(metadata),
startTime: monotonicTime(),
endTime: 0,
type: dispatcher._type,
method,
params,
log: [],
};
const result = await (dispatcher as any)[method](validated, callMetadata);
this.onmessage({ id, result: this._replaceDispatchersWithGuids(result) });

20
src/server/instrumentation.ts
View file

@ -31,10 +31,14 @@ export type Attribution = {
};
export type CallMetadata = {
startTime: number;
endTime: number;
type: string;
method: string;
params: any;
stack?: StackFrame[];
log: string[];
error?: Error;
};
export class SdkObject extends EventEmitter {
@ -49,19 +53,13 @@ export class SdkObject extends EventEmitter {
}
}
export type ActionResult = {
logs: string[],
startTime: number,
endTime: number,
error?: Error,
};
export interface Instrumentation {
onContextCreated(context: BrowserContext): Promise<void>;
onContextWillDestroy(context: BrowserContext): Promise<void>;
onContextDidDestroy(context: BrowserContext): Promise<void>;
onActionCheckpoint(name: string, sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onAfterAction(result: ActionResult, sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onAfterAction(sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onLog(logName: string, message: string, sdkObject: SdkObject, metadata: CallMetadata): void;
}
export interface InstrumentationListener {
@ -69,7 +67,8 @@ export interface InstrumentationListener {
onContextWillDestroy?(context: BrowserContext): Promise<void>;
onContextDidDestroy?(context: BrowserContext): Promise<void>;
onActionCheckpoint?(name: string, sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onAfterAction?(result: ActionResult, sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onAfterAction?(sdkObject: SdkObject, metadata: CallMetadata): Promise<void>;
onLog?(logName: string, message: string, sdkObject: SdkObject, metadata: CallMetadata): void;
}
export function multiplexInstrumentation(listeners: InstrumentationListener[]): Instrumentation {
@ -87,8 +86,11 @@ export function multiplexInstrumentation(listeners: InstrumentationListener[]):
export function internalCallMetadata(): CallMetadata {
return {
startTime: 0,
endTime: 0,
type: 'Internal',
method: '',
params: {},
log: [],
};
}

33
src/server/progress.ts
View file

@ -17,7 +17,7 @@
import { TimeoutError } from '../utils/errors';
import { assert, monotonicTime } from '../utils/utils';
import { rewriteErrorMessage } from '../utils/stackTrace';
import { debugLogger, LogName } from '../utils/debugLogger';
import { LogName } from '../utils/debugLogger';
import { CallMetadata, Instrumentation, SdkObject } from './instrumentation';
export interface Progress {
@ -38,11 +38,10 @@ export class ProgressController {
// Cleanups to be run only in the case of abort.
private _cleanups: (() => any)[] = [];
private _logName: LogName = 'api';
private _logName = 'api';
private _state: 'before' | 'running' | 'aborted' | 'finished' = 'before';
private _deadline: number = 0;
private _timeout: number = 0;
private _logRecording: string[] = [];
readonly metadata: CallMetadata;
readonly instrumentation: Instrumentation;
readonly sdkObject: SdkObject;
@ -70,9 +69,10 @@ export class ProgressController {
const progress: Progress = {
log: message => {
if (this._state === 'running')
this._logRecording.push(message);
debugLogger.log(this._logName, message);
if (this._state === 'running') {
this.metadata.log.push(message);
this.instrumentation.onLog(this._logName, message, this.sdkObject, this.metadata);
}
},
timeUntilDeadline: () => this._deadline ? this._deadline - monotonicTime() : 2147483647, // 2^31-1 safe setTimeout in Node.
isRunning: () => this._state === 'running',
@ -93,34 +93,25 @@ export class ProgressController {
const timeoutError = new TimeoutError(`Timeout ${this._timeout}ms exceeded.`);
const timer = setTimeout(() => this._forceAbort(timeoutError), progress.timeUntilDeadline());
const startTime = monotonicTime();
try {
const promise = task(progress);
const result = await Promise.race([promise, this._forceAbortPromise]);
clearTimeout(timer);
this._state = 'finished';
await this.instrumentation.onAfterAction({
startTime,
endTime: monotonicTime(),
logs: this._logRecording,
}, this.sdkObject, this.metadata);
this._logRecording = [];
this.metadata.endTime = monotonicTime();
await this.instrumentation.onAfterAction(this.sdkObject, this.metadata);
return result;
} catch (e) {
clearTimeout(timer);
this._state = 'aborted';
await Promise.all(this._cleanups.splice(0).map(cleanup => runCleanup(cleanup)));
await this.instrumentation.onAfterAction({
startTime,
endTime: monotonicTime(),
logs: this._logRecording,
error: e,
}, this.sdkObject, this.metadata);
this.metadata.endTime = monotonicTime();
this.metadata.error = e;
await this.instrumentation.onAfterAction(this.sdkObject, this.metadata);
rewriteErrorMessage(e,
e.message +
formatLogRecording(this._logRecording) +
formatLogRecording(this.metadata.log) +
kLoggingNote);
this._logRecording = [];
throw e;
}
}

5
src/server/supplements/inspectorController.ts
View file

@ -18,6 +18,7 @@ import { BrowserContext } from '../browserContext';
import { isDebugMode } from '../../utils/utils';
import { RecorderSupplement } from './recorderSupplement';
import { InstrumentationListener } from '../instrumentation';
import { debugLogger } from '../../utils/debugLogger';
export class InspectorController implements InstrumentationListener {
async onContextCreated(context: BrowserContext): Promise<void> {
@ -28,4 +29,8 @@ export class InspectorController implements InstrumentationListener {
});
}
}
onLog(logName: string, message: string): void {
debugLogger.log(logName as any, message);
}
}

16
src/trace/tracer.ts
View file

@ -27,7 +27,7 @@ import { helper, RegisteredListener } from '../server/helper';
import { Dialog } from '../server/dialog';
import { Frame, NavigationEvent } from '../server/frames';
import { snapshotScript } from './snapshotterInjected';
import { ActionResult, CallMetadata, InstrumentationListener, SdkObject } from '../server/instrumentation';
import { CallMetadata, InstrumentationListener, SdkObject } from '../server/instrumentation';
const fsWriteFileAsync = util.promisify(fs.writeFile.bind(fs));
const fsAppendFileAsync = util.promisify(fs.appendFile.bind(fs));
@ -59,8 +59,8 @@ export class Tracer implements InstrumentationListener {
this._contextTracers.get(sdkObject.attribution.context!)?.onActionCheckpoint(name, sdkObject, metadata);
}
async onAfterAction(result: ActionResult, sdkObject: SdkObject, metadata: CallMetadata): Promise<void> {
this._contextTracers.get(sdkObject.attribution.context!)?.onAfterAction(result, sdkObject, metadata);
async onAfterAction(sdkObject: SdkObject, metadata: CallMetadata): Promise<void> {
this._contextTracers.get(sdkObject.attribution.context!)?.onAfterAction(sdkObject, metadata);
}
}
@ -160,7 +160,7 @@ class ContextTracer implements SnapshotterDelegate {
await this._snapshotter.forceSnapshot(sdkObject.attribution.page, snapshotId);
}
async onAfterAction(result: ActionResult, sdkObject: SdkObject, metadata: CallMetadata): Promise<void> {
async onAfterAction(sdkObject: SdkObject, metadata: CallMetadata): Promise<void> {
if (!sdkObject.attribution.page)
return;
const event: trace.ActionTraceEvent = {
@ -173,10 +173,10 @@ class ContextTracer implements SnapshotterDelegate {
// FIXME: filter out evaluation snippets, binary
params: metadata.params,
stack: metadata.stack,
startTime: result.startTime,
endTime: result.endTime,
logs: result.logs.slice(),
error: result.error ? result.error.stack : undefined,
startTime: metadata.startTime,
endTime: metadata.endTime,
logs: metadata.log.slice(),
error: metadata.error ? metadata.error.stack : undefined,
snapshots: snapshotsForMetadata(metadata),
};
this._appendTraceEvent(event);

2
utils/check_deps.js
View file

@ -114,7 +114,7 @@ DEPS['src/install/'] = ['src/utils/'];
// Client depends on chromium protocol for types.
DEPS['src/client/'] = ['src/common/', 'src/utils/', 'src/protocol/', 'src/server/chromium/protocol.ts'];
DEPS['src/dispatchers/'] = ['src/utils/', 'src/protocol/', 'src/server/**'];
DEPS['src/dispatchers/'] = ['src/common/', 'src/utils/', 'src/protocol/', 'src/server/**'];
// Generic dependencies for server-side code.
DEPS['src/server/'] = [