diff --git a/packages/core/src/measurements/context.ts b/packages/core/src/measurements/context.ts index 0f4d406285..57a862ce9d 100644 --- a/packages/core/src/measurements/context.ts +++ b/packages/core/src/measurements/context.ts @@ -23,25 +23,35 @@ export class MeasureMetricsContext implements MeasureContext { this.name = name this.params = params this.metrics = metrics - this.done = measure(metrics, params, fullParams) + this.done = measure(metrics, params, fullParams, (spend) => { + this.logger.logOperation(this.name, spend, { ...params, ...fullParams }) + }) this.logger = logger ?? { info: (msg, args) => { - console.info(msg, ...args) + console.info(msg, ...Object.entries(args ?? {}).map((it) => `${it[0]}=${JSON.stringify(it[1])}`)) }, error: (msg, args) => { - console.error(msg, ...args) - } + console.error(msg, ...Object.entries(args ?? {}).map((it) => `${it[0]}=${JSON.stringify(it[1])}`)) + }, + close: async () => {}, + logOperation: (operation, time, params) => {} } } measure (name: string, value: number): void { - const c = new MeasureMetricsContext('#' + name, {}, {}, childMetrics(this.metrics, ['#' + name])) + const c = new MeasureMetricsContext('#' + name, {}, {}, childMetrics(this.metrics, ['#' + name]), this.logger) c.done(value) } newChild (name: string, params: ParamsType, fullParams?: FullParamsType, logger?: MeasureLogger): MeasureContext { - return new MeasureMetricsContext(name, params, fullParams ?? {}, childMetrics(this.metrics, [name]), logger) + return new MeasureMetricsContext( + name, + params, + fullParams ?? {}, + childMetrics(this.metrics, [name]), + logger ?? this.logger + ) } async with<T>( @@ -50,7 +60,7 @@ export class MeasureMetricsContext implements MeasureContext { op: (ctx: MeasureContext) => T | Promise<T>, fullParams?: ParamsType ): Promise<T> { - const c = this.newChild(name, params, fullParams) + const c = this.newChild(name, params, fullParams, this.logger) try { let value = op(c) if (value instanceof Promise) { @@ -64,12 +74,24 @@ export class MeasureMetricsContext implements MeasureContext { } } - async error (message: string, ...args: any[]): Promise<void> { - this.logger.error(message, args) + async withLog<T>( + name: string, + params: ParamsType, + op: (ctx: MeasureContext) => T | Promise<T>, + fullParams?: ParamsType + ): Promise<T> { + const st = Date.now() + const r = await this.with(name, params, op, fullParams) + this.logger.logOperation(name, Date.now() - st, { ...params, ...fullParams }) + return r } - async info (message: string, ...args: any[]): Promise<void> { - this.logger.info(message, args) + async error (message: string, args?: Record<string, any>): Promise<void> { + this.logger.error(message, { ...this.params, ...args }) + } + + async info (message: string, args?: Record<string, any>): Promise<void> { + this.logger.info(message, { ...this.params, ...args }) } end (): void { diff --git a/packages/core/src/measurements/metrics.ts b/packages/core/src/measurements/metrics.ts index 047a083797..1d8f8c7882 100644 --- a/packages/core/src/measurements/metrics.ts +++ b/packages/core/src/measurements/metrics.ts @@ -45,7 +45,12 @@ function getUpdatedTopResult ( * Measure with tree expansion. Operation counter will be added only to leaf's. * @public */ -export function measure (metrics: Metrics, params: ParamsType, fullParams: FullParamsType = {}): () => void { +export function measure ( + metrics: Metrics, + params: ParamsType, + fullParams: FullParamsType = {}, + endOp?: (spend: number) => void +): () => void { const st = Date.now() return (value?: number) => { const ed = Date.now() @@ -75,6 +80,7 @@ export function measure (metrics: Metrics, params: ParamsType, fullParams: FullP metrics.operations++ metrics.topResult = getUpdatedTopResult(metrics.topResult, ed - st, fullParams) + endOp?.(ed - st) } } diff --git a/packages/core/src/measurements/types.ts b/packages/core/src/measurements/types.ts index 2052948d7f..29757705eb 100644 --- a/packages/core/src/measurements/types.ts +++ b/packages/core/src/measurements/types.ts @@ -37,8 +37,14 @@ export interface Metrics extends MetricsData { * @public */ export interface MeasureLogger { - info: (message: string, ...args: any[]) => void - error: (message: string, ...args: any[]) => void + info: (message: string, obj?: Record<string, any>) => void + error: (message: string, obj?: Record<string, any>) => void + + logOperation: (operation: string, time: number, params: ParamsType) => void + + childLogger?: (name: string, params: Record<string, any>) => MeasureLogger + + close: () => Promise<void> } /** * @public @@ -54,13 +60,20 @@ export interface MeasureContext { fullParams?: FullParamsType ) => Promise<T> + withLog: <T>( + name: string, + params: ParamsType, + op: (ctx: MeasureContext) => T | Promise<T>, + fullParams?: FullParamsType + ) => Promise<T> + logger: MeasureLogger measure: (name: string, value: number) => void // Capture error - error: (message: string, ...args: any[]) => Promise<void> - info: (message: string, ...args: any[]) => Promise<void> + error: (message: string, obj?: Record<string, any>) => Promise<void> + info: (message: string, obj?: Record<string, any>) => Promise<void> // Mark current context as complete // If no value is passed, time difference will be used. diff --git a/server/server/src/apm.ts b/server/server/src/apm.ts index b232e19fab..754a19b035 100644 --- a/server/server/src/apm.ts +++ b/server/server/src/apm.ts @@ -1,4 +1,4 @@ -import { MeasureContext, MeasureLogger, ParamType } from '@hcengineering/core' +import { MeasureContext, MeasureLogger, ParamType, ParamsType } from '@hcengineering/core' import apm, { Agent, Span, Transaction } from 'elastic-apm-node' /** @@ -37,11 +37,13 @@ export class APMMeasureContext implements MeasureContext { this.parent = parent this.logger = { info: (msg, args) => { - agent.logger.info(msg, args) + agent.logger.info({ message: msg, ...args }) }, error: (msg, args) => { - agent.logger.error(msg, args) - } + agent.logger.error({ message: msg, ...args }) + }, + logOperation (operation, time, params) {}, + close: async () => {} } if (!(noTransaction ?? false)) { if (this.parent === undefined) { @@ -63,8 +65,9 @@ export class APMMeasureContext implements MeasureContext { async with<T>( name: string, - params: Record<string, ParamType>, - op: (ctx: MeasureContext) => T | Promise<T> + params: ParamsType, + op: (ctx: MeasureContext) => T | Promise<T>, + fullParams?: ParamsType ): Promise<T> { const c = this.newChild(name, params) try { @@ -80,6 +83,18 @@ export class APMMeasureContext implements MeasureContext { } } + async withLog<T>( + name: string, + params: ParamsType, + op: (ctx: MeasureContext) => T | Promise<T>, + fullParams?: ParamsType + ): Promise<T> { + const st = Date.now() + const r = await this.with(name, params, op, fullParams) + this.logger.logOperation(name, Date.now() - st, { ...params, ...fullParams }) + return r + } + async error (message: string, ...args: any[]): Promise<void> { this.logger.error(message, args)