diff --git a/app/client/lib/telemetry.ts b/app/client/lib/telemetry.ts index 84dd51a8..9e1a8ad2 100644 --- a/app/client/lib/telemetry.ts +++ b/app/client/lib/telemetry.ts @@ -2,10 +2,10 @@ import {logError} from 'app/client/models/errors'; import {TelemetryEventName} from 'app/common/Telemetry'; import {fetchFromHome, pageHasHome} from 'app/common/urlUtils'; -export async function logTelemetryEvent(name: TelemetryEventName, metadata?: Record) { +export function logTelemetryEvent(name: TelemetryEventName, metadata?: Record) { if (!pageHasHome()) { return; } - await fetchFromHome('/api/telemetry', { + fetchFromHome('/api/telemetry', { method: 'POST', body: JSON.stringify({ name, diff --git a/app/client/ui/OpenVideoTour.ts b/app/client/ui/OpenVideoTour.ts index bfc6adcb..e970461a 100644 --- a/app/client/ui/OpenVideoTour.ts +++ b/app/client/ui/OpenVideoTour.ts @@ -36,7 +36,7 @@ const VIDEO_TOUR_YOUTUBE_EMBED_ID = 'qnr2Pfnxdlc'; owner.onDispose(async () => { if (youtubePlayer.isLoading()) { return; } - await logTelemetryEvent('watchedVideoTour', { + logTelemetryEvent('watchedVideoTour', { watchTimeSeconds: Math.floor(youtubePlayer.getCurrentTime()), }); }); diff --git a/app/common/hashingUtils.ts b/app/common/hashingUtils.ts new file mode 100644 index 00000000..91d2199d --- /dev/null +++ b/app/common/hashingUtils.ts @@ -0,0 +1,12 @@ +import {createHash} from 'crypto'; + +/** + * Returns a hash of `id` prefixed with the first 4 characters of `id`. + * + * Useful for situations where potentially sensitive identifiers are logged, such as + * doc ids (like those that have public link sharing enabled). The first 4 characters + * are included to assist with troubleshooting. + */ +export function hashId(id: string): string { + return `${id.slice(0, 4)}:${createHash('sha256').update(id.slice(4)).digest('base64')}`; +} diff --git a/app/gen-server/entity/Document.ts b/app/gen-server/entity/Document.ts index 74817b4a..0d4bf08e 100644 --- a/app/gen-server/entity/Document.ts +++ b/app/gen-server/entity/Document.ts @@ -1,5 +1,6 @@ import {ApiError} from 'app/common/ApiError'; import {DocumentUsage} from 'app/common/DocUsage'; +import {hashId} from 'app/common/hashingUtils'; import {Role} from 'app/common/roles'; import {DocumentOptions, DocumentProperties, documentPropertyKeys, DocumentType, NEW_DOCUMENT_CODE, TutorialMetadata} from "app/common/UserAPI"; @@ -164,8 +165,8 @@ export class Document extends Resource { ? Math.floor((lastSlideIndex / numSlides) * 100) : undefined; dbManager?.emit('tutorialProgressChange', { - tutorialForkId: this.id, - tutorialTrunkId: this.trunkId, + tutorialForkIdDigest: hashId(this.id), + tutorialTrunkIdDigest: this.trunkId ? hashId(this.trunkId) : undefined, lastSlideIndex, numSlides, percentComplete, diff --git a/app/gen-server/lib/Housekeeper.ts b/app/gen-server/lib/Housekeeper.ts index 1deaa6e5..2796d413 100644 --- a/app/gen-server/lib/Housekeeper.ts +++ b/app/gen-server/lib/Housekeeper.ts @@ -17,7 +17,8 @@ import fetch from 'node-fetch'; import * as Fetch from 'node-fetch'; import { EntityManager } from 'typeorm'; -const HOUSEKEEPER_PERIOD_MS = 1 * 60 * 60 * 1000; // operate every 1 hour +const DELETE_TRASH_PERIOD_MS = 1 * 60 * 60 * 1000; // operate every 1 hour +const LOG_METRICS_PERIOD_MS = 24 * 60 * 60 * 1000; // operate every day const AGE_THRESHOLD_OFFSET = '-30 days'; // should be an interval known by postgres + sqlite /** @@ -33,7 +34,8 @@ const AGE_THRESHOLD_OFFSET = '-30 days'; // should be an interval kno * multiple home servers, there will be no competition or duplication of effort. */ export class Housekeeper { - private _interval?: NodeJS.Timeout; + private _deleteTrashinterval?: NodeJS.Timeout; + private _logMetricsInterval?: NodeJS.Timeout; private _electionKey?: string; public constructor(private _dbManager: HomeDBManager, private _server: GristServer, @@ -45,34 +47,35 @@ export class Housekeeper { */ public async start() { await this.stop(); - this._interval = setInterval(() => { - this.doHousekeepingExclusively().catch(log.warn.bind(log)); - }, HOUSEKEEPER_PERIOD_MS); + this._deleteTrashinterval = setInterval(() => { + this.deleteTrashExclusively().catch(log.warn.bind(log)); + }, DELETE_TRASH_PERIOD_MS); + this._logMetricsInterval = setInterval(() => { + this.logMetricsExclusively().catch(log.warn.bind(log)); + }, LOG_METRICS_PERIOD_MS); } /** * Stop scheduling housekeeping tasks. Note: doesn't wait for any housekeeping task in progress. */ public async stop() { - if (this._interval) { - clearInterval(this._interval); - this._interval = undefined; + for (const interval of ['_deleteTrashinterval', '_logMetricsInterval'] as const) { + clearInterval(this[interval]); + this[interval] = undefined; } } /** - * Deletes old trash and logs metrics if no other server is working on it or worked on it - * recently. + * Deletes old trash if no other server is working on it or worked on it recently. */ - public async doHousekeepingExclusively(): Promise { - const electionKey = await this._electionStore.getElection('housekeeping', HOUSEKEEPER_PERIOD_MS / 2.0); + public async deleteTrashExclusively(): Promise { + const electionKey = await this._electionStore.getElection('housekeeping', DELETE_TRASH_PERIOD_MS / 2.0); if (!electionKey) { - log.info('Skipping housekeeping since another server is working on it or worked on it recently'); + log.info('Skipping deleteTrash since another server is working on it or worked on it recently'); return false; } this._electionKey = electionKey; await this.deleteTrash(); - await this.logMetrics(); return true; } @@ -152,6 +155,20 @@ export class Housekeeper { } } + /** + * Logs metrics if no other server is working on it or worked on it recently. + */ + public async logMetricsExclusively(): Promise { + const electionKey = await this._electionStore.getElection('logMetrics', LOG_METRICS_PERIOD_MS / 2.0); + if (!electionKey) { + log.info('Skipping logMetrics since another server is working on it or worked on it recently'); + return false; + } + this._electionKey = electionKey; + await this.logMetrics(); + return true; + } + /** * Logs metrics regardless of what other servers may be doing. */ @@ -163,7 +180,7 @@ export class Housekeeper { telemetryManager?.logEvent('siteUsage', { siteId: summary.site_id, siteType: summary.site_type, - inGoodStanding: summary.in_good_standing, + inGoodStanding: Boolean(summary.in_good_standing), stripePlanId: summary.stripe_plan_id, numDocs: Number(summary.num_docs), numWorkspaces: Number(summary.num_workspaces), diff --git a/app/server/lib/ActiveDoc.ts b/app/server/lib/ActiveDoc.ts index ea20f508..107d3e82 100644 --- a/app/server/lib/ActiveDoc.ts +++ b/app/server/lib/ActiveDoc.ts @@ -68,6 +68,7 @@ import {FormulaProperties, getFormulaProperties} from 'app/common/GranularAccess import {isHiddenCol} from 'app/common/gristTypes'; import {commonUrls, parseUrlId} from 'app/common/gristUrls'; import {byteString, countIf, retryOnce, safeJsonParse} from 'app/common/gutil'; +import {hashId} from 'app/common/hashingUtils'; import {InactivityTimer} from 'app/common/InactivityTimer'; import {Interval} from 'app/common/Interval'; import * as roles from 'app/common/roles'; @@ -131,10 +132,12 @@ import {createAttachmentsIndex, DocStorage, REMOVE_UNUSED_ATTACHMENTS_DELAY} fro import {expandQuery} from './ExpandedQuery'; import {GranularAccess, GranularAccessForBundle} from './GranularAccess'; import {OnDemandActions} from './OnDemandActions'; -import {getLogMetaFromDocSession, getPubSubPrefix, timeoutReached} from './serverUtils'; +import {getLogMetaFromDocSession, getPubSubPrefix, getTelemetryMetaFromDocSession, + timeoutReached} from './serverUtils'; import {findOrAddAllEnvelope, Sharing} from './Sharing'; import cloneDeep = require('lodash/cloneDeep'); import flatten = require('lodash/flatten'); +import merge = require('lodash/merge'); import pick = require('lodash/pick'); import remove = require('lodash/remove'); import sum = require('lodash/sum'); @@ -1389,10 +1392,9 @@ export class ActiveDoc extends EventEmitter implements AssistanceDoc { // TODO: Need a more precise way to identify a template. (This org now also has tutorials.) const isTemplate = TEMPLATES_ORG_DOMAIN === doc.workspace.org.domain && doc.type !== 'tutorial'; this.logTelemetryEvent(docSession, 'documentForked', { - forkId: forkIds.forkId, - forkDocId: forkIds.docId, - forkUrlId: forkIds.urlId, - trunkId: doc.trunkId, + forkIdDigest: hashId(forkIds.forkId), + forkDocIdDigest: hashId(forkIds.docId), + trunkIdDigest: doc.trunkId ? hashId(doc.trunkId) : undefined, isTemplate, lastActivity: doc.updatedAt, }); @@ -2314,7 +2316,6 @@ export class ActiveDoc extends EventEmitter implements AssistanceDoc { private _logDocMetrics(docSession: OptDocSession, triggeredBy: 'docOpen' | 'interval'| 'docClose') { this.logTelemetryEvent(docSession, 'documentUsage', { triggeredBy, - access: this._doc?.access, isPublic: ((this._doc as unknown) as APIDocument)?.public ?? false, rowCount: this._docUsage?.rowCount?.total, dataSizeBytes: this._docUsage?.dataSizeBytes, @@ -2434,22 +2435,22 @@ export class ActiveDoc extends EventEmitter implements AssistanceDoc { private _getCustomWidgetMetrics() { const viewSections = this.docData?.getMetaTable('_grist_Views_section'); const viewSectionRecords = viewSections?.getRecords() ?? []; - const customWidgetUrls: string[] = []; + const customWidgetIds: string[] = []; for (const r of viewSectionRecords) { const {customView} = safeJsonParse(r.options, {}); if (!customView) { continue; } - const {url} = safeJsonParse(customView, {}); + const {pluginId, url} = safeJsonParse(customView, {}); if (!url) { continue; } - const isGristUrl = url.startsWith(commonUrls.gristLabsCustomWidgets); - customWidgetUrls.push(isGristUrl ? url : 'externalURL'); + const isGristLabsWidget = url.startsWith(commonUrls.gristLabsCustomWidgets); + customWidgetIds.push(isGristLabsWidget ? pluginId : 'externalId'); } - const numCustomWidgets = customWidgetUrls.length; + const numCustomWidgets = customWidgetIds.length; return { numCustomWidgets, - customWidgetUrls, + customWidgetIds, }; } @@ -2511,15 +2512,16 @@ export class ActiveDoc extends EventEmitter implements AssistanceDoc { } private _getTelemetryMeta(docSession: OptDocSession|null) { - return { - ...(docSession ? { - ...getLogMetaFromDocSession(docSession), - altSessionId: getDocSessionAltSessionId(docSession), - } : {}), - docId: this._docName, - siteId: this._doc?.workspace.org.id, - siteType: this._product?.name, - }; + const altSessionId = docSession ? getDocSessionAltSessionId(docSession) : undefined; + return merge( + docSession ? getTelemetryMetaFromDocSession(docSession) : {}, + altSessionId ? {altSessionId} : undefined, + { + docIdDigest: hashId(this._docName), + siteId: this._doc?.workspace.org.id, + siteType: this._product?.name, + }, + ); } /** diff --git a/app/server/lib/AppEndpoint.ts b/app/server/lib/AppEndpoint.ts index 5a766a07..adf14bde 100644 --- a/app/server/lib/AppEndpoint.ts +++ b/app/server/lib/AppEndpoint.ts @@ -9,6 +9,7 @@ import fetch, {Response as FetchResponse, RequestInit} from 'node-fetch'; import {ApiError} from 'app/common/ApiError'; import {getSlugIfNeeded, parseSubdomainStrictly, parseUrlId} from 'app/common/gristUrls'; import {removeTrailingSlash} from 'app/common/gutil'; +import {hashId} from 'app/common/hashingUtils'; import {LocalPlugin} from "app/common/plugin"; import {TelemetryTemplateSignupCookieName} from 'app/common/Telemetry'; import {Document as APIDocument} from 'app/common/UserAPI'; @@ -308,7 +309,7 @@ export function attachAppEndpoint(options: AttachOptions): void { const isTemplate = TEMPLATES_ORG_DOMAIN === doc.workspace.org.domain && doc.type !== 'tutorial'; if (isPublic || isTemplate) { gristServer.getTelemetryManager()?.logEvent('documentOpened', { - docId, + docIdDigest: hashId(docId), siteId: doc.workspace.org.id, siteType: doc.workspace.org.billingAccount.product.name, userId: mreq.userId, diff --git a/app/server/lib/Authorizer.ts b/app/server/lib/Authorizer.ts index c56e8694..7a745f98 100644 --- a/app/server/lib/Authorizer.ts +++ b/app/server/lib/Authorizer.ts @@ -397,7 +397,8 @@ export async function addRequestUser(dbManager: HomeDBManager, permitStore: IPer log.rawDebug(`Auth[${meta.method}]: ${meta.host} ${meta.path}`, meta); if (hasApiKey) { options.gristServer.getTelemetryManager()?.logEvent('apiUsage', { - ...meta, + method: mreq.method, + userId: mreq.userId, userAgent: req.headers['user-agent'], }); } diff --git a/app/server/lib/Client.ts b/app/server/lib/Client.ts index fc780daa..730b030d 100644 --- a/app/server/lib/Client.ts +++ b/app/server/lib/Client.ts @@ -433,6 +433,16 @@ export class Client { return meta; } + public getFullTelemetryMeta() { + const meta: Record = {}; + // We assume the _userId has already been cached, which will be true always (for all practical + // purposes) because it's set when the Authorizer checks this client. + if (this._userId) { meta.userId = this._userId; } + const altSessionId = this.getAltSessionId(); + if (altSessionId) { meta.altSessionId = altSessionId; } + return meta; + } + private async _refreshUser(dbManager: HomeDBManager) { if (this._profile) { const user = await this._fetchUser(dbManager); diff --git a/app/server/lib/DocApi.ts b/app/server/lib/DocApi.ts index 6e905270..b685f5f6 100644 --- a/app/server/lib/DocApi.ts +++ b/app/server/lib/DocApi.ts @@ -11,6 +11,7 @@ import { import {isRaisedException} from "app/common/gristTypes"; import {buildUrlId, parseUrlId} from "app/common/gristUrls"; import {isAffirmative} from "app/common/gutil"; +import {hashId} from "app/common/hashingUtils"; import {SchemaTypes} from "app/common/schema"; import {SortFunc} from 'app/common/SortFunc'; import {Sort} from 'app/common/SortSpec'; @@ -915,9 +916,8 @@ export class DocWorkerApi { }); const {forkId} = parseUrlId(scope.urlId); activeDoc.logTelemetryEvent(docSession, 'tutorialRestarted', { - tutorialForkId: forkId, - tutorialForkUrlId: scope.urlId, - tutorialTrunkId, + tutorialForkIdDigest: forkId ? hashId(forkId) : undefined, + tutorialTrunkIdDigest: hashId(tutorialTrunkId), }); } } diff --git a/app/server/lib/FlexServer.ts b/app/server/lib/FlexServer.ts index be2eeb47..a16daa86 100644 --- a/app/server/lib/FlexServer.ts +++ b/app/server/lib/FlexServer.ts @@ -697,9 +697,7 @@ export class FlexServer implements GristServer { const name = stringParam(req.body.name, 'name', TelemetryEventNames); this._telemetryManager?.logEvent(name as TelemetryEventName, { userId: mreq.userId, - email: mreq.user?.loginEmail, altSessionId: mreq.altSessionId, - site: mreq.org, ...req.body.metadata, }); return resp.status(200).send(); diff --git a/app/server/lib/Triggers.ts b/app/server/lib/Triggers.ts index de554e57..45f0a563 100644 --- a/app/server/lib/Triggers.ts +++ b/app/server/lib/Triggers.ts @@ -619,7 +619,9 @@ export class DocTriggers { await this._stats.logStatus(id, 'sending'); meta = {numEvents: batch.length, webhookId: id, host: new URL(url).host}; this._log("Sending batch of webhook events", meta); - this._activeDoc.logTelemetryEvent(null, 'sendingWebhooks', meta); + this._activeDoc.logTelemetryEvent(null, 'sendingWebhooks', { + numEvents: batch.length, + }); success = await this._sendWebhookWithRetries(id, url, body, batch.length, this._loopAbort.signal); if (this._loopAbort.signal.aborted) { continue; diff --git a/app/server/lib/serverUtils.ts b/app/server/lib/serverUtils.ts index 7c01a1d2..755bc422 100644 --- a/app/server/lib/serverUtils.ts +++ b/app/server/lib/serverUtils.ts @@ -163,6 +163,20 @@ export function getLogMetaFromDocSession(docSession: OptDocSession) { }; } +/** + * Extract telemetry metadata from session. + */ +export function getTelemetryMetaFromDocSession(docSession: OptDocSession) { + const client = docSession.client; + const access = getDocSessionAccessOrNull(docSession); + const user = getDocSessionUser(docSession); + return { + access, + ...(user ? {userId: user.id} : {}), + ...(client ? client.getFullTelemetryMeta() : {}), // Client if present will repeat and add to user info. + }; +} + /** * Only offer choices of engine on experimental deployments (staging/dev). */