Skip to content
This repository has been archived by the owner on May 3, 2024. It is now read-only.

fix(configureRequestLog): use default when configured with undefined #1029

Merged
merged 4 commits into from
Jun 21, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
95 changes: 95 additions & 0 deletions __tests__/server/utils/logging/fastifyPlugin.spec.js
Original file line number Diff line number Diff line change
Expand Up @@ -728,5 +728,100 @@ describe('fastifyPlugin', () => {
});
});
});

it('catches and logs errors', async () => {
const errorSpy = jest.spyOn(console, 'error').mockImplementation(() => {});

const request = {
headers: {},
};
const reply = {
getHeader: jest.fn(),
raw: {},
};

const fastify = {
decorateRequest: jest.fn((name, fn) => {
fastify[name] = fn;
}),
addHook: jest.fn((name, fn) => {
if (!fastify[name]) {
fastify[name] = fn;
}
}),
};

fastifyPlugin(fastify, null, jest.fn());
const boomError = new Error('boom');
setConfigureRequestLog(() => {
throw boomError;
});
await expect(() => fastify.onResponse(request, reply)).rejects.toEqual(boomError);
expect(errorSpy).toHaveBeenCalledWith(boomError);
});
});

describe('setConfigureRequestLog', () => {
it('resets to default', async () => {
const request = {
headers: {},
};
const reply = {
getHeader: jest.fn(),
raw: {},
};

const fastify = {
decorateRequest: jest.fn((name, fn) => {
fastify[name] = fn;
}),
addHook: jest.fn((name, fn) => {
if (!fastify[name]) {
fastify[name] = fn;
}
}),
};

fastifyPlugin(fastify, null, jest.fn());
setConfigureRequestLog(() => {
throw new Error('shh');
});
setConfigureRequestLog();

await fastify.onResponse(request, reply);

expect(logger.info.mock.calls[0][0]).toMatchInlineSnapshot(`
{
"request": {
"address": {
"uri": "",
},
"direction": "in",
"metaData": {
"correlationId": undefined,
"forwarded": null,
"forwardedFor": null,
"host": null,
"locale": undefined,
"location": undefined,
"method": undefined,
"referrer": null,
"userAgent": null,
},
"protocol": undefined,
"statusCode": undefined,
"statusText": undefined,
"timings": {
"duration": 0,
"requestOverhead": NaN,
"responseBuilder": 0,
"routeHandler": NaN,
"ttfb": 0,
},
},
"type": "request",
}
`);
});
});
});
22 changes: 14 additions & 8 deletions src/server/utils/logging/fastifyPlugin.js
Original file line number Diff line number Diff line change
Expand Up @@ -35,8 +35,9 @@ export const $RequestOverhead = Symbol('$RequestOverhead');
export const $RouteHandler = Symbol('$RouteHandler');
export const $ResponseBuilder = Symbol('$ResponseBuilder');

const passThrough = ({ log }) => log;
const UTILS = {
configureRequestLog: ({ log }) => log,
configureRequestLog: passThrough,
};

const getLocale = (req) => {
Expand Down Expand Up @@ -137,7 +138,7 @@ const logClientRequest = (request, reply) => {
logger.info(configuredLog);
};

export const setConfigureRequestLog = (newConfigureRequestLog) => {
export const setConfigureRequestLog = (newConfigureRequestLog = passThrough) => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why would somebody call setConfigureRequestLog without passing an argument?

Copy link
Contributor Author

@JAdshead JAdshead Jun 20, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why should this be allowed to fail when called without an argument ? It's called every time during onModule load. This is also how its handled in 5.x.x and should not have been removed.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

because it shouldn't be called without an argument

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It shouldn't but it is. I don't see the issue having a default to improve resiliency

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I won't block it but it's a bad practice. The function by starting with the word set lets the developer know that it "sets" something, and the data will always be expected (you cannot set something with no data, otherwise would be like a reset). That's the reason why all functions, like the write from fs will throw an error if data is not provided. If we want a set to be "safe" I would rename it to something like safeSetConfigureRequestLog, but, still, ideally, the user should always pass data

UTILS.configureRequestLog = newConfigureRequestLog;
};

Expand Down Expand Up @@ -200,12 +201,17 @@ const fastifyPlugin = (fastify, _opts, done) => {
});

fastify.addHook('onResponse', async (request, reply) => {
endTimer(request, $ResponseBuilder);
// same as 'reply.getResponseTime()' but our approach
// helps us to make the code cleaner
endTimer(request, $RequestFullDuration);

logClientRequest(request, reply);
try {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why is the try/catch needed here? it catches the error, logs it, and throws it, meaning that we only need to log it right? Fastify handles uncaught errors for us (https://www.fastify.io/docs/latest/Reference/Errors/) so no need for a try/catch

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not for onResponse hooks, this currently fails silently

endTimer(request, $ResponseBuilder);
// same as 'reply.getResponseTime()' but our approach
// helps us to make the code cleaner
endTimer(request, $RequestFullDuration);

logClientRequest(request, reply);
} catch (error) {
console.error(error);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

shouldn't we use the logger here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

throw error;
}
});

done();
Expand Down