From 457b9714d108ff5a74fe6a71625a9cba57793d44 Mon Sep 17 00:00:00 2001 From: Paul Fitzpatrick Date: Wed, 24 Jan 2024 12:20:47 -0500 Subject: [PATCH] (core) change ActiveDoc load and Sandbox call log messages to be aggregation-friendly Summary: Takes some numbers embedded in strings and moves them to the context, so they can be aggregated and trends inspected more easily. Test Plan: tested manually by looking at logs Reviewers: dsagal Reviewed By: dsagal Subscribers: dsagal Differential Revision: https://phab.getgrist.com/D4175 --- app/server/lib/ActiveDoc.ts | 6 +++++- app/server/lib/NSandbox.ts | 6 +++++- 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/app/server/lib/ActiveDoc.ts b/app/server/lib/ActiveDoc.ts index 3feae3a6..295122d4 100644 --- a/app/server/lib/ActiveDoc.ts +++ b/app/server/lib/ActiveDoc.ts @@ -2380,7 +2380,11 @@ export class ActiveDoc extends EventEmitter { // took longer, scale it up proportionately. const closeTimeout = Math.max(loadMs, 1000) * Deps.ACTIVEDOC_TIMEOUT; this._inactivityTimer.setDelay(closeTimeout); - this._log.debug(docSession, `loaded in ${loadMs} ms, InactivityTimer set to ${closeTimeout} ms`); + log.rawDebug('ActiveDoc load timing', { + ...this.getLogMeta(docSession), + loadMs, + closeTimeout, + }); const docUsage = getDocSessionUsage(docSession); if (!docUsage) { // This looks be the first time this installation of Grist is touching diff --git a/app/server/lib/NSandbox.ts b/app/server/lib/NSandbox.ts index 84a94339..d57aacbe 100644 --- a/app/server/lib/NSandbox.ts +++ b/app/server/lib/NSandbox.ts @@ -312,7 +312,11 @@ export class NSandbox implements ISandbox { throw new sandboxUtil.SandboxError(e.message); } finally { if (this._logTimes) { - log.rawDebug(`Sandbox pyCall[${funcName}] took ${Date.now() - startTime} ms`, this._logMeta); + log.rawDebug('NSandbox pyCall', { + ...this._logMeta, + funcName, + loadMs: Date.now() - startTime, + }); } } }