use structured logging for email utils (#5230)

* use structured logging for email utils
* add module name mapping for uuid and jest

---------

Co-authored-by: Vincent <git@vincenttunru.com>
This commit is contained in:
Robert Helmer 2024-10-25 13:25:23 -07:00 коммит произвёл GitHub
Родитель 1af5c46f05
Коммит 77df206d0a
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: B5690EEEBB952194
4 изменённых файлов: 44 добавлений и 22 удалений

Просмотреть файл

@ -113,7 +113,10 @@ const customJestConfig = {
// ],
// A map from regular expressions to module names or to arrays of module names that allow to stub out resources with a single module
// moduleNameMapper: {},
moduleNameMapper: {
// Force module uuid to resolve with the CJS entry point, because Jest does not support package.json.exports. See https://github.com/uuidjs/uuid/issues/451
uuid: require.resolve("uuid"),
},
// An array of regexp pattern strings, matched against all module paths before considered 'visible' to the module loader
modulePathIgnorePatterns: ["e2e/"],

Просмотреть файл

@ -16,6 +16,7 @@ export const logger = createLogger({
level: "info",
// In GCP environments, use cloud logging instead of stdout.
// FIXME https://mozilla-hub.atlassian.net/browse/MNTOR-2401 - enable for stage and production
/* c8 ignore next 3 - cannot test this outside of GCP currently */
transports: ["gcpdev"].includes(process.env.APP_ENV ?? "local")
? [loggingWinston]
: [new transports.Console()],

Просмотреть файл

@ -5,6 +5,7 @@
import { test, expect, jest } from "@jest/globals";
import type { createTransport, Transporter } from "nodemailer";
import { randomToken } from "./email";
import type * as loggerModule from "../app/functions/server/logging";
jest.mock("nodemailer", () => {
return {
@ -12,6 +13,16 @@ jest.mock("nodemailer", () => {
};
});
jest.mock("../app/functions/server/logging", () => {
return {
logger: {
info: jest.fn(),
warn: jest.fn(),
error: jest.fn(),
},
};
});
test("EmailUtils.sendEmail before .init() fails", async () => {
expect.assertions(1);
@ -25,9 +36,9 @@ test("EmailUtils.sendEmail before .init() fails", async () => {
});
test("EmailUtils.init with empty host uses jsonTransport", async () => {
const mockedConsoleInfo = jest
.spyOn(console, "info")
.mockImplementation(() => undefined);
const mockedLoggerModule = jest.requireMock<typeof loggerModule>(
"../app/functions/server/logging",
);
const mockedNodemailer: {
createTransport: jest.MockedFunction<typeof createTransport>;
} = jest.requireMock("nodemailer");
@ -37,7 +48,7 @@ test("EmailUtils.init with empty host uses jsonTransport", async () => {
expect(mockedNodemailer.createTransport).toHaveBeenCalledWith({
jsonTransport: true,
});
expect(mockedConsoleInfo).toHaveBeenCalledWith("smtpUrl-empty", {
expect(mockedLoggerModule.logger.info).toHaveBeenCalledWith("smtpUrl-empty", {
message: "EmailUtils will log a JSON response instead of sending emails.",
});
});
@ -65,9 +76,9 @@ test("EmailUtils.sendEmail with recipient, subject, template, context calls gTra
const mockedNodemailer: {
createTransport: jest.MockedFunction<typeof createTransport>;
} = jest.requireMock("nodemailer");
const mockedConsoleInfo = jest
.spyOn(console, "info")
.mockImplementation(() => undefined);
const mockedLoggerModule = jest.requireMock<typeof loggerModule>(
"../app/functions/server/logging",
);
const { initEmail, sendEmail } = await import("./email");
const testSmtpUrl = "smtps://test:test@test:1";
@ -86,13 +97,16 @@ test("EmailUtils.sendEmail with recipient, subject, template, context calls gTra
expect(
await sendEmail("test@example.com", "subject", "<html>test</html>"),
).toBe(sendMailInfo);
expect(mockedConsoleInfo).toHaveBeenCalledWith("sent_email", sendMailInfo);
expect(mockedLoggerModule.logger.info).toHaveBeenCalledWith(
"sent_email",
sendMailInfo,
);
});
test("EmailUtils.sendEmail rejects with error", async () => {
const mockedConsoleError = jest
.spyOn(console, "error")
.mockImplementation(() => undefined);
const mockedLoggerModule = jest.requireMock<typeof loggerModule>(
"../app/functions/server/logging",
);
const mockedNodemailer: {
createTransport: jest.MockedFunction<typeof createTransport>;
} = jest.requireMock("nodemailer");
@ -109,16 +123,16 @@ test("EmailUtils.sendEmail rejects with error", async () => {
await expect(() =>
sendEmail("test@example.com", "subject", "<html>test</html>"),
).rejects.toThrow("error");
expect(mockedConsoleError).toHaveBeenCalled();
expect(mockedLoggerModule.logger.error).toHaveBeenCalled();
});
test("EmailUtils.init with empty host uses jsonTransport. logs messages", async () => {
const mockedNodemailer: {
createTransport: jest.MockedFunction<typeof createTransport>;
} = jest.requireMock("nodemailer");
const mockedConsoleInfo = jest
.spyOn(console, "info")
.mockImplementation(() => undefined);
const mockedLoggerModule = jest.requireMock<typeof loggerModule>(
"../app/functions/server/logging",
);
const { initEmail, sendEmail } = await import("./email");
const sendMailInfo = { messageId: "test id", response: "test response" };
@ -134,7 +148,10 @@ test("EmailUtils.init with empty host uses jsonTransport. logs messages", async
expect(
await sendEmail("test@example.com", "subject", "<html>test</html>"),
).toBe(sendMailInfo);
expect(mockedConsoleInfo).toHaveBeenCalledWith("sent_email", sendMailInfo);
expect(mockedLoggerModule.logger.info).toHaveBeenCalledWith(
"sent_email",
sendMailInfo,
);
});
test("randomToken returns a random token of 2xlength (because of hex)", () => {

Просмотреть файл

@ -7,6 +7,7 @@ import crypto from "crypto";
import { SentMessageInfo } from "nodemailer/lib/smtp-transport/index.js";
import { getEnvVarsOrThrow } from "../envVars";
import { logger } from "../app/functions/server/logging";
// The SMTP transport object. This is initialized to a nodemailer transport
// object while reading SMTP credentials, or to a dummy function in debug mode.
@ -17,7 +18,7 @@ const envVars = getEnvVarsOrThrow(["SMTP_URL", "EMAIL_FROM", "SES_CONFIG_SET"]);
async function initEmail(smtpUrl = envVars.SMTP_URL) {
// Allow a debug mode that will log JSON instead of sending emails.
if (!smtpUrl) {
console.info("smtpUrl-empty", {
logger.info("smtpUrl-empty", {
message: "EmailUtils will log a JSON response instead of sending emails.",
});
gTransporter = createTransport({ jsonTransport: true });
@ -62,24 +63,24 @@ async function sendEmail(
/* c8 ignore next 5 */
if (gTransporter.transporter.name === "JSONTransport") {
// @ts-ignore Added typing later, but it disagrees with actual use:
console.info("JSONTransport", { message: info.message.toString() });
logger.info("JSONTransport", { message: info.message.toString() });
return info;
}
console.info("sent_email", {
logger.info("sent_email", {
messageId: info.messageId,
response: info.response,
});
return info;
} catch (e) {
if (e instanceof Error) {
console.error("error_sending_email", {
logger.error("error_sending_email", {
message: e.message,
stack: e.stack,
});
/* c8 ignore next 3 */
} else {
console.error("error_sending_email", { message: JSON.stringify(e) });
logger.error("error_sending_email", { message: JSON.stringify(e) });
}
throw e;
}