diff --git a/services/web/app/src/Features/LinkedFiles/LinkedFilesController.mjs b/services/web/app/src/Features/LinkedFiles/LinkedFilesController.mjs index c0f982b0e5..d146968442 100644 --- a/services/web/app/src/Features/LinkedFiles/LinkedFilesController.mjs +++ b/services/web/app/src/Features/LinkedFiles/LinkedFilesController.mjs @@ -12,6 +12,7 @@ */ import SessionManager from '../Authentication/SessionManager.mjs' import Settings from '@overleaf/settings' +import logger from '@overleaf/logger' import _ from 'lodash' import AnalyticsManager from '../../../../app/src/Features/Analytics/AnalyticsManager.mjs' import LinkedFilesHandler from './LinkedFilesHandler.mjs' @@ -162,6 +163,35 @@ const refreshLinkedFileFallbackSchema = z.object({ }), }) +// Keys whose values are safe to log as-is. Every other key is kept (so the shape of the data stays visible in the log) but its value is replaced. +const LINKED_FILE_DATA_ALLOW_LIST = [ + 'provider', + 'importedAt', + 'source_project_id', + 'v1_source_doc_id', + 'source_entity_path', + 'source_output_file_path', + 'format', + 'group_id', + 'clsiServerId', +] + +function redactLinkedFileData(data) { + return Object.fromEntries( + Object.entries(data).map(([key, value]) => { + if (LINKED_FILE_DATA_ALLOW_LIST.includes(key)) return [key, value] + if (key === 'url') { + try { + return [key, new URL(value).origin + '/'] + } catch { + return [key, ''] + } + } + return [key, ''] + }) + ) +} + async function createLinkedFile(req, res, next) { const { params, body } = parseReq(req, createLinkedFileSchema, { fallbackSchema: createLinkedFileFallbackSchema, @@ -201,7 +231,14 @@ async function createLinkedFile(req, res, next) { } return res.json({ new_file_id: newFileId }) } catch (err) { - return LinkedFilesController.handleError(err, req, res, next) + return LinkedFilesController.handleError( + err, + { projectId, userId, parentFolderId }, + data, + req, + res, + next + ) } } @@ -257,7 +294,14 @@ async function refreshLinkedFile(req, res, next) { historySource ) } catch (err) { - return LinkedFilesController.handleError(err, req, res, next) + return LinkedFilesController.handleError( + err, + { projectId, userId, parentFolderId }, + linkedFileData, + req, + res, + next + ) } if (shouldReindexReferences) { @@ -309,7 +353,16 @@ export default LinkedFilesController = { refreshLinkedFile: expressify(refreshLinkedFile), - handleError(error, req, res, next) { + handleError(error, info, linkedFileData, req, res, next) { + logger.warn( + { + error, + req, + ...info, + linkedFileData: redactLinkedFileData(linkedFileData), + }, + 'failed to create/refresh linked file' + ) if (error instanceof AccessDeniedError) { res.status(403) plainTextResponse( diff --git a/services/web/test/unit/src/LinkedFiles/LinkedFilesController.test.mjs b/services/web/test/unit/src/LinkedFiles/LinkedFilesController.test.mjs index 9d12416e41..c40e58df83 100644 --- a/services/web/test/unit/src/LinkedFiles/LinkedFilesController.test.mjs +++ b/services/web/test/unit/src/LinkedFiles/LinkedFilesController.test.mjs @@ -52,7 +52,15 @@ describe('LinkedFilesController', function () { ctx.ProjectLocator = {} ctx.logger = { error: sinon.stub(), + warn: sinon.stub(), } + // parseReq logs through the same stub, so find the call this suite is about + // rather than assuming it is the only one. + ctx.lastLinkedFileWarning = () => + ctx.logger.warn + .getCalls() + .filter(call => call.args[1] === 'failed to create/refresh linked file') + .pop()?.args[0] ctx.settings = { enabledLinkedFileTypes: [] } ctx.SplitTestHandler = { promises: { featureFlagEnabled: sinon.stub().resolves(false) }, @@ -237,6 +245,32 @@ describe('LinkedFilesController', function () { expect(ctx.next.firstCall.args[0]?.name).to.equal('InvalidRequestError') expect(ctx.Agent.promises.createLinkedFile).to.not.have.been.called }) + + it('logs the failure with the linked file data redacted', async function (ctx) { + const error = new Error('agent failed') + ctx.Agent.promises.createLinkedFile.rejects(error) + ctx.req.body.data = { url: 'https://example.com/foo?token=secret' } + + await new Promise(resolve => { + ctx.next = sinon.stub().callsFake(() => resolve()) + ctx.res = { json: () => resolve(), sendStatus: () => resolve() } + ctx.LinkedFilesController.createLinkedFile(ctx.req, ctx.res, ctx.next) + }) + + expect(ctx.next).to.have.been.calledWith(error) + expect(ctx.lastLinkedFileWarning()).to.deep.equal({ + error, + req: ctx.req, + projectId: ctx.projectId, + userId: ctx.userId, + parentFolderId: ctx.parentFolderId, + linkedFileData: { + provider: ctx.provider, + url: 'https://example.com/', + importedAt: ctx.fakeTime.toISOString(), + }, + }) + }) }) describe('refreshLinkedFiles', function () { beforeEach(function (ctx) { @@ -310,6 +344,32 @@ describe('LinkedFilesController', function () { expect(ctx.Agent.promises.refreshLinkedFile).to.not.have.been.called }) + it('logs the failure with the linked file data redacted', async function (ctx) { + const error = new Error('agent failed') + ctx.Agent.promises.refreshLinkedFile.rejects(error) + ctx.file.linkedFileData.url = 'https://example.com/foo?token=secret' + + await new Promise(resolve => { + ctx.next = sinon.stub().callsFake(() => resolve()) + ctx.res = { json: () => resolve(), sendStatus: () => resolve() } + ctx.LinkedFilesController.refreshLinkedFile(ctx.req, ctx.res, ctx.next) + }) + + expect(ctx.next).to.have.been.calledWith(error) + expect(ctx.lastLinkedFileWarning()).to.deep.equal({ + error, + req: ctx.req, + projectId: ctx.projectId, + userId: ctx.userId, + parentFolderId: 'parent-folder-id', + linkedFileData: { + provider: ctx.provider, + url: 'https://example.com/', + importedAt: ctx.fakeTime.toISOString(), + }, + }) + }) + describe('when bib file re-indexing is required', function () { const clientId = 'client-id' beforeEach(function (ctx) { @@ -347,4 +407,71 @@ describe('LinkedFilesController', function () { }) }) }) + describe('handleError', function () { + function redactedDataFor(ctx, linkedFileData) { + ctx.LinkedFilesController.handleError( + new Error('agent failed'), + {}, + linkedFileData, + {}, + {}, + sinon.stub() + ) + return ctx.lastLinkedFileWarning().linkedFileData + } + + it('keeps only the origin of a url', function (ctx) { + expect( + redactedDataFor(ctx, { + provider: 'url', + url: 'https://example.com/secret/path?token=secret', + }) + ).to.deep.equal({ + provider: 'url', + url: 'https://example.com/', + }) + }) + + it('reports a url it cannot parse, leaving the input alone', function (ctx) { + const linkedFileData = { provider: 'url', url: 'not-a-url' } + + expect(redactedDataFor(ctx, linkedFileData)).to.deep.equal({ + provider: 'url', + url: '', + }) + expect(linkedFileData.url).to.equal('not-a-url') + }) + + it('redacts the build id of an output file', function (ctx) { + expect( + redactedDataFor(ctx, { + provider: 'project_output_file', + source_project_id: ctx.projectId, + source_output_file_path: 'output.pdf', + build_id: '1234abcd-5678ef90', + clsiServerId: 'clsi-server-id', + }) + ).to.deep.equal({ + provider: 'project_output_file', + source_project_id: ctx.projectId, + source_output_file_path: 'output.pdf', + build_id: '', + clsiServerId: 'clsi-server-id', + }) + }) + + it('redacts the value of a field it does not know', function (ctx) { + expect( + redactedDataFor(ctx, { + provider: 'project_file', + source_entity_path: 'refs/linked.bib', + new_secret_field: 'hunter2', + }) + ).to.deep.equal({ + provider: 'project_file', + source_entity_path: 'refs/linked.bib', + new_secret_field: '', + }) + }) + }) })