UBERF-9663: Improve mail logging (#8290)

Signed-off-by: Artem Savchenko <armisav@gmail.com>
This commit is contained in:
Artyom Savchenko 2025-03-20 11:38:03 +07:00 committed by GitHub
parent 372c5d78af
commit d6cc7774bd
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
6 changed files with 103 additions and 34 deletions

View File

@ -117,7 +117,7 @@ export async function sendEmailNotification (
return return
} }
const mailAuth: string | undefined = getMetadata(serverNotification.metadata.MailAuthToken) const mailAuth: string | undefined = getMetadata(serverNotification.metadata.MailAuthToken)
await fetch(concatLink(mailURL, '/send'), { const response = await fetch(concatLink(mailURL, '/send'), {
method: 'post', method: 'post',
keepalive: true, keepalive: true,
headers: { headers: {
@ -131,6 +131,9 @@ export async function sendEmailNotification (
to: [receiver] to: [receiver]
}) })
}) })
if (!response.ok) {
ctx.error(`Failed to send email notification: ${response.statusText}`)
}
} catch (err) { } catch (err) {
ctx.error('Could not send email notification', { err, receiver }) ctx.error('Could not send email notification', { err, receiver })
} }

View File

@ -179,7 +179,7 @@ async function getAccountInfo (
return toAccountInfo(account) return toAccountInfo(account)
} }
async function sendOtpEmail (branding: Branding | null, otp: string, email: string): Promise<void> { async function sendOtpEmail (ctx: MeasureContext, branding: Branding | null, otp: string, email: string): Promise<void> {
const mailURL = getMetadata(accountPlugin.metadata.MAIL_URL) const mailURL = getMetadata(accountPlugin.metadata.MAIL_URL)
if (mailURL === undefined || mailURL === '') { if (mailURL === undefined || mailURL === '') {
console.info('Please provide email service url to enable email otp.') console.info('Please provide email service url to enable email otp.')
@ -194,7 +194,7 @@ async function sendOtpEmail (branding: Branding | null, otp: string, email: stri
const subject = await translate(accountPlugin.string.OtpSubject, { code: otp, app }, lang) const subject = await translate(accountPlugin.string.OtpSubject, { code: otp, app }, lang)
const to = email const to = email
await fetch(concatLink(mailURL, '/send'), { const response = await fetch(concatLink(mailURL, '/send'), {
method: 'POST', method: 'POST',
headers: { headers: {
'Content-Type': 'application/json' 'Content-Type': 'application/json'
@ -206,6 +206,12 @@ async function sendOtpEmail (branding: Branding | null, otp: string, email: stri
to to
}) })
}) })
if (!response.ok) {
ctx.error('Failed to send OTP email', {
email,
error: response.statusText
})
}
} }
export async function getAccountInfoByToken ( export async function getAccountInfoByToken (
@ -318,7 +324,7 @@ export async function sendOtp (
const expires = now + timeToLive const expires = now + timeToLive
const otp = await getNewOtp(db) const otp = await getNewOtp(db)
await sendOtpEmail(branding, otp, email) await sendOtpEmail(ctx, branding, otp, email)
await db.otp.insertOne({ account: account._id, otp, expires, createdOn: now }) await db.otp.insertOne({ account: account._id, otp, expires, createdOn: now })
return { sent: true, retryOn: now + retryDelay * 1000 } return { sent: true, retryOn: now + retryDelay * 1000 }
@ -2299,7 +2305,7 @@ export async function requestPassword (
const subject = await translate(accountPlugin.string.RecoverySubject, {}, lang) const subject = await translate(accountPlugin.string.RecoverySubject, {}, lang)
const to = account.email const to = account.email
await fetch(concatLink(mailURL, '/send'), { const response = await fetch(concatLink(mailURL, '/send'), {
method: 'post', method: 'post',
headers: { headers: {
'Content-Type': 'application/json' 'Content-Type': 'application/json'
@ -2311,7 +2317,15 @@ export async function requestPassword (
to to
}) })
}) })
if (response.ok) {
ctx.info('recovery email sent', { email, accountEmail: account.email }) ctx.info('recovery email sent', { email, accountEmail: account.email })
} else {
ctx.error('Failed to send reset password email', {
email,
accountEmail: account.email,
error: response.statusText
})
}
} }
/** /**
@ -2561,7 +2575,7 @@ export async function sendInvite (
const subject = await translate(accountPlugin.string.InviteSubject, { ws }, lang) const subject = await translate(accountPlugin.string.InviteSubject, { ws }, lang)
const to = email const to = email
await fetch(concatLink(mailURL, '/send'), { const response = await fetch(concatLink(mailURL, '/send'), {
method: 'post', method: 'post',
headers: { headers: {
'Content-Type': 'application/json' 'Content-Type': 'application/json'
@ -2573,7 +2587,16 @@ export async function sendInvite (
to to
}) })
}) })
if (response.ok) {
ctx.info('Invite sent', { email, workspace, link }) ctx.info('Invite sent', { email, workspace, link })
} else {
ctx.error('Failed to send invite email', {
email,
workspace,
link,
error: response.statusText
})
}
} }
async function checkSendRateLimit (currentAccount: Account, workspace: string, db: AccountDB): Promise<void> { async function checkSendRateLimit (currentAccount: Account, workspace: string, db: AccountDB): Promise<void> {
@ -2645,7 +2668,7 @@ export async function resendInvite (
const subject = await translate(accountPlugin.string.ResendInviteSubject, { ws }, lang) const subject = await translate(accountPlugin.string.ResendInviteSubject, { ws }, lang)
const to = emailMask const to = emailMask
await fetch(concatLink(mailURL, '/send'), { const response = await fetch(concatLink(mailURL, '/send'), {
method: 'post', method: 'post',
headers: { headers: {
'Content-Type': 'application/json' 'Content-Type': 'application/json'
@ -2657,7 +2680,16 @@ export async function resendInvite (
to to
}) })
}) })
if (response.ok) {
ctx.info('Invite resend and email sent', { email: emailMask, workspace: wsPromise.workspace, link }) ctx.info('Invite resend and email sent', { email: emailMask, workspace: wsPromise.workspace, link })
} else {
ctx.error('Failed to send invite resend email', {
email: emailMask,
workspace: wsPromise.workspace,
link,
error: response.statusText
})
}
} }
async function deactivatePersonAccount ( async function deactivatePersonAccount (

View File

@ -55,6 +55,9 @@
"dependencies": { "dependencies": {
"@aws-sdk/client-ses": "^3.738.0", "@aws-sdk/client-ses": "^3.738.0",
"@types/nodemailer": "^6.4.17", "@types/nodemailer": "^6.4.17",
"@hcengineering/analytics-service": "^0.6.0",
"@hcengineering/core": "^0.6.32",
"@hcengineering/server-core": "^0.6.1",
"cors": "^2.8.5", "cors": "^2.8.5",
"dotenv": "~16.0.0", "dotenv": "~16.0.0",
"express": "^4.21.2", "express": "^4.21.2",

View File

@ -14,6 +14,7 @@
// //
import { Request, Response } from 'express' import { Request, Response } from 'express'
import { type MeasureContext } from '@hcengineering/core'
import { MailClient } from '../mail' import { MailClient } from '../mail'
import { handleSendMail } from '../main' import { handleSendMail } from '../main'
@ -31,6 +32,7 @@ describe('handleSendMail', () => {
let res: Response let res: Response
let sendMailMock: jest.Mock let sendMailMock: jest.Mock
let mailClient: MailClient let mailClient: MailClient
let mockCtx: MeasureContext
beforeEach(() => { beforeEach(() => {
// eslint-disable-next-line @typescript-eslint/consistent-type-assertions // eslint-disable-next-line @typescript-eslint/consistent-type-assertions
@ -49,12 +51,16 @@ describe('handleSendMail', () => {
mailClient = new MailClient() mailClient = new MailClient()
sendMailMock = (mailClient.sendMessage as jest.Mock).mockResolvedValue({}) sendMailMock = (mailClient.sendMessage as jest.Mock).mockResolvedValue({})
mockCtx = {
info: jest.fn(),
error: jest.fn()
} as unknown as MeasureContext
}) })
it('should return 400 if text is missing', async () => { it('should return 400 if text is missing', async () => {
req.body.text = undefined req.body.text = undefined
await handleSendMail(new MailClient(), req, res) await handleSendMail(new MailClient(), req, res, mockCtx)
// eslint-disable-next-line @typescript-eslint/unbound-method // eslint-disable-next-line @typescript-eslint/unbound-method
expect(res.status).toHaveBeenCalledWith(400) expect(res.status).toHaveBeenCalledWith(400)
@ -64,7 +70,7 @@ describe('handleSendMail', () => {
it('should return 400 if subject is missing', async () => { it('should return 400 if subject is missing', async () => {
req.body.subject = undefined req.body.subject = undefined
await handleSendMail(new MailClient(), req, res) await handleSendMail(new MailClient(), req, res, mockCtx)
// eslint-disable-next-line @typescript-eslint/unbound-method // eslint-disable-next-line @typescript-eslint/unbound-method
expect(res.status).toHaveBeenCalledWith(400) expect(res.status).toHaveBeenCalledWith(400)
@ -74,7 +80,7 @@ describe('handleSendMail', () => {
it('should return 400 if to is missing', async () => { it('should return 400 if to is missing', async () => {
req.body.to = undefined req.body.to = undefined
await handleSendMail(new MailClient(), req, res) await handleSendMail(new MailClient(), req, res, mockCtx)
// eslint-disable-next-line @typescript-eslint/unbound-method // eslint-disable-next-line @typescript-eslint/unbound-method
expect(res.status).toHaveBeenCalledWith(400) expect(res.status).toHaveBeenCalledWith(400)
@ -84,13 +90,13 @@ describe('handleSendMail', () => {
it('handles errors thrown by MailClient', async () => { it('handles errors thrown by MailClient', async () => {
sendMailMock.mockRejectedValue(new Error('Email service error')) sendMailMock.mockRejectedValue(new Error('Email service error'))
await handleSendMail(new MailClient(), req, res) await handleSendMail(new MailClient(), req, res, mockCtx)
expect(res.send).toHaveBeenCalled() // Check that a response is still sent expect(res.send).toHaveBeenCalled() // Check that a response is still sent
}) })
it('should use source from config if from is not provided', async () => { it('should use source from config if from is not provided', async () => {
await handleSendMail(mailClient, req, res) await handleSendMail(mailClient, req, res, mockCtx)
expect(sendMailMock).toHaveBeenCalledWith( expect(sendMailMock).toHaveBeenCalledWith(
expect.objectContaining({ expect.objectContaining({
@ -98,13 +104,14 @@ describe('handleSendMail', () => {
to: 'test@example.com', to: 'test@example.com',
subject: 'Test Subject', subject: 'Test Subject',
text: 'Hello, world!' text: 'Hello, world!'
}) }),
mockCtx
) )
}) })
it('should use from if it is provided', async () => { it('should use from if it is provided', async () => {
req.body.from = 'test.from@example.com' req.body.from = 'test.from@example.com'
await handleSendMail(mailClient, req, res) await handleSendMail(mailClient, req, res, mockCtx)
expect(sendMailMock).toHaveBeenCalledWith( expect(sendMailMock).toHaveBeenCalledWith(
expect.objectContaining({ expect.objectContaining({
@ -112,13 +119,14 @@ describe('handleSendMail', () => {
to: 'test@example.com', to: 'test@example.com',
subject: 'Test Subject', subject: 'Test Subject',
text: 'Hello, world!' text: 'Hello, world!'
}) }),
mockCtx
) )
}) })
it('should send to multiple addresses', async () => { it('should send to multiple addresses', async () => {
req.body.to = ['test1@example.com', 'test2@example.com'] req.body.to = ['test1@example.com', 'test2@example.com']
await handleSendMail(mailClient, req, res) await handleSendMail(mailClient, req, res, mockCtx)
expect(sendMailMock).toHaveBeenCalledWith( expect(sendMailMock).toHaveBeenCalledWith(
expect.objectContaining({ expect.objectContaining({
@ -126,7 +134,8 @@ describe('handleSendMail', () => {
to: ['test1@example.com', 'test2@example.com'], // Verify that multiple addresses are passed to: ['test1@example.com', 'test2@example.com'], // Verify that multiple addresses are passed
subject: 'Test Subject', subject: 'Test Subject',
text: 'Hello, world!' text: 'Hello, world!'
}) }),
mockCtx
) )
}) })
}) })

View File

@ -13,6 +13,7 @@
// limitations under the License. // limitations under the License.
// //
import { type SendMailOptions, type Transporter } from 'nodemailer' import { type SendMailOptions, type Transporter } from 'nodemailer'
import { MeasureContext } from '@hcengineering/core'
import config from './config' import config from './config'
import { getTransport } from './transport' import { getTransport } from './transport'
@ -24,14 +25,13 @@ export class MailClient {
this.transporter = getTransport(config) this.transporter = getTransport(config)
} }
async sendMessage (message: SendMailOptions): Promise<void> { async sendMessage (message: SendMailOptions, ctx: MeasureContext): Promise<void> {
this.transporter.sendMail(message, (err, info) => { this.transporter.sendMail(message, (err, info) => {
const messageInfo = `(from: ${message.from as string}, to: ${message.to as string})` const messageInfo = `(from: ${message.from as string}, to: ${message.to as string})`
if (err !== null) { if (err !== null) {
console.error(`Failed to send email ${messageInfo}: `, err.message) ctx.error(`Failed to send email ${messageInfo}: ${err.message}`)
console.log('Failed message details: ', message)
} else { } else {
console.log(`Email request ${messageInfo} sent: ${info?.response}`) ctx.info(`Email request ${messageInfo} sent: ${info?.response}`)
} }
}) })
} }

View File

@ -16,6 +16,10 @@
import { type SendMailOptions } from 'nodemailer' import { type SendMailOptions } from 'nodemailer'
import { Request, Response } from 'express' import { Request, Response } from 'express'
import Mail from 'nodemailer/lib/mailer' import Mail from 'nodemailer/lib/mailer'
import { initStatisticsContext } from '@hcengineering/server-core'
import { MeasureContext, MeasureMetricsContext, newMetrics } from '@hcengineering/core'
import { SplitLogger } from '@hcengineering/analytics-service'
import { join } from 'path'
import config from './config' import config from './config'
import { createServer, listen } from './server' import { createServer, listen } from './server'
@ -23,15 +27,28 @@ import { MailClient } from './mail'
import { Endpoint } from './types' import { Endpoint } from './types'
export const main = async (): Promise<void> => { export const main = async (): Promise<void> => {
const measureCtx = initStatisticsContext('mail', {
factory: () =>
new MeasureMetricsContext(
'mail',
{},
{},
newMetrics(),
new SplitLogger('mail', {
root: join(process.cwd(), 'logs'),
enableConsole: (process.env.ENABLE_CONSOLE ?? 'true') === 'true'
})
)
})
const client = new MailClient() const client = new MailClient()
console.log('Mail service has been started') measureCtx.info('Mail service has been started')
const endpoints: Endpoint[] = [ const endpoints: Endpoint[] = [
{ {
endpoint: '/send', endpoint: '/send',
type: 'post', type: 'post',
handler: async (req, res) => { handler: async (req, res) => {
await handleSendMail(client, req, res) await handleSendMail(client, req, res, measureCtx)
} }
} }
] ]
@ -46,15 +63,20 @@ export const main = async (): Promise<void> => {
process.on('SIGINT', shutdown) process.on('SIGINT', shutdown)
process.on('SIGTERM', shutdown) process.on('SIGTERM', shutdown)
process.on('uncaughtException', (e) => { process.on('uncaughtException', (e: any) => {
console.error(e) measureCtx.error(e.message)
}) })
process.on('unhandledRejection', (e) => { process.on('unhandledRejection', (e: any) => {
console.error(e) measureCtx.error(e.message)
}) })
} }
export async function handleSendMail (client: MailClient, req: Request, res: Response): Promise<void> { export async function handleSendMail (
client: MailClient,
req: Request,
res: Response,
ctx: MeasureContext
): Promise<void> {
// Skip auth check, since service should be internal // Skip auth check, since service should be internal
const { from, to, subject, text, html, attachments } = req.body const { from, to, subject, text, html, attachments } = req.body
const fromAddress = from ?? config.source const fromAddress = from ?? config.source
@ -87,9 +109,9 @@ export async function handleSendMail (client: MailClient, req: Request, res: Res
message.attachments = getAttachments(attachments) message.attachments = getAttachments(attachments)
} }
try { try {
await client.sendMessage(message) await client.sendMessage(message, ctx)
} catch (err) { } catch (err: any) {
console.log(err) ctx.error(err.message)
} }
res.send() res.send()