From 3c952d9c5d8383b300845b64d736862ed244c99d Mon Sep 17 00:00:00 2001 From: titanism <101466223+titanism@users.noreply.github.com> Date: Sun, 15 Oct 2023 22:06:25 -0500 Subject: [PATCH] fix: fixed tz issue, inherit server logger for IMAP/SMTP --- app/views/layout.pug | 2 +- config/meta.js | 4 +++- helpers/imap-notifier.js | 7 ++++++- helpers/imap/on-append.js | 15 +++++++-------- helpers/imap/on-copy.js | 17 ++++++++--------- helpers/imap/on-create.js | 7 +++---- helpers/imap/on-delete.js | 9 ++++----- helpers/imap/on-expunge.js | 27 +++++++++++++++------------ helpers/imap/on-fetch.js | 27 +++++++++++++-------------- helpers/imap/on-get-quota-root.js | 5 ++--- helpers/imap/on-get-quota.js | 5 ++--- helpers/imap/on-list.js | 5 ++--- helpers/imap/on-lsub.js | 5 ++--- helpers/imap/on-move.js | 21 ++++++++++----------- helpers/imap/on-open.js | 5 ++--- helpers/imap/on-rename.js | 7 +++---- helpers/imap/on-search.js | 11 +++++------ helpers/imap/on-status.js | 5 ++--- helpers/imap/on-store.js | 17 ++++++++--------- helpers/imap/on-subscribe.js | 5 ++--- helpers/imap/on-unsubscribe.js | 5 ++--- helpers/on-auth.js | 11 +++++------ imap-server.js | 15 +++++++++++---- smtp-server.js | 11 +++++++++-- test/imap/index.js | 3 ++- 25 files changed, 129 insertions(+), 122 deletions(-) diff --git a/app/views/layout.pug b/app/views/layout.pug index cf1f7c2fe2..0931c7a0bb 100644 --- a/app/views/layout.pug +++ b/app/views/layout.pug @@ -139,7 +139,7 @@ html.h-100.no-js( if ['/', '/resources', '/about', '/terms', '/about', '/faq', '/private-business-email'].includes(ctx.pathWithoutLocale) || ctx.pathWithoutLocale.startsWith('/docs') || ctx.pathWithoutLocale.startsWith('/guides') //- in order for snapshots to be consistent we need the same date to be used - - const now = config.env === "test" ? dayjs("1/1/23", "M/D/YY").toDate() : new Date(); + - const now = config.env === "test" ? dayjs.tz("2023-01-01", "America/Los_Angeles").toDate() : new Date(); meta( property="og:updated_time", content=dayjs(now).startOf("day").toDate().toISOString() diff --git a/config/meta.js b/config/meta.js index 3b2f00a4b4..e879b36ee5 100644 --- a/config/meta.js +++ b/config/meta.js @@ -28,7 +28,9 @@ const { developerDocs, nsProviders, platforms } = require('#config/utilities'); module.exports = function (config) { // in order for snapshots to be consistent we need the same date to be used const now = - config.env === 'test' ? dayjs('1/1/23', 'M/D/YY').toDate() : new Date(); + config.env === 'test' + ? dayjs.tz('2023-01-01', 'America/Los_Angeles').toDate() + : new Date(); // currently we cannot use the `|` pipe character due to this issue // diff --git a/helpers/imap-notifier.js b/helpers/imap-notifier.js index d065c177d2..53a1097928 100644 --- a/helpers/imap-notifier.js +++ b/helpers/imap-notifier.js @@ -15,6 +15,7 @@ const { EventEmitter } = require('node:events'); +const Axe = require('axe'); const _ = require('lodash'); const safeStringify = require('fast-safe-stringify'); @@ -22,8 +23,12 @@ const IMAPError = require('#helpers/imap-error'); const Journals = require('#models/journals'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); +const config = require('#config'); +const helperLogger = require('#helpers/logger'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); + +const logger = + config.env === 'development' ? helperLogger : new Axe({ silent: true }); const IMAP_REDIS_CHANNEL_NAME = 'imap_events'; diff --git a/helpers/imap/on-append.js b/helpers/imap/on-append.js index 691dda5790..4cecbccd5d 100644 --- a/helpers/imap/on-append.js +++ b/helpers/imap/on-append.js @@ -22,12 +22,11 @@ const Messages = require('#models/messages'); const Threads = require('#models/threads'); const Mailboxes = require('#models/mailboxes'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); // eslint-disable-next-line max-params async function onAppend(path, flags, date, raw, session, fn) { - logger.debug('APPEND', { path, flags, date, raw, session }); + this.logger.debug('APPEND', { path, flags, date, raw, session }); let thread; let storageUsed = 0; @@ -232,7 +231,7 @@ async function onAppend(path, flags, date, raw, session, fn) { // store the message const message = await Messages.create(data); - logger.debug('message created', { + this.logger.debug('message created', { message, path, flags, @@ -257,7 +256,7 @@ async function onAppend(path, flags, date, raw, session, fn) { }); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { path, flags, date, raw, session }); + this.logger.fatal(err, { path, flags, date, raw, session }); } const response = { @@ -270,7 +269,7 @@ async function onAppend(path, flags, date, raw, session, fn) { status: 'new' }; - logger.debug('command response', { response }); + this.logger.debug('command response', { response }); fn(null, true, response); } catch (err) { @@ -285,7 +284,7 @@ async function onAppend(path, flags, date, raw, session, fn) { this.attachmentStorage .deleteManyPromise(attachmentIds, maildata.magic) .then() - .catch((err) => logger.fatal(err, { storageUsed, session })); + .catch((err) => this.logger.fatal(err, { storageUsed, session })); // rollback storage if there was an error and storage was consumed if (storageUsed > 0) { @@ -301,7 +300,7 @@ async function onAppend(path, flags, date, raw, session, fn) { } ) .then() - .catch((err) => logger.fatal(err, { storageUsed, session })); + .catch((err) => this.logger.fatal(err, { storageUsed, session })); } // handle mongodb error @@ -309,7 +308,7 @@ async function onAppend(path, flags, date, raw, session, fn) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, flags, date, raw, session }); + this.logger.error(err, { path, flags, date, raw, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-copy.js b/helpers/imap/on-copy.js index 86b58dcc80..17dab5dd55 100644 --- a/helpers/imap/on-copy.js +++ b/helpers/imap/on-copy.js @@ -24,12 +24,11 @@ const Messages = require('#models/messages'); const ServerShutdownError = require('#helpers/server-shutdown-error'); const SocketError = require('#helpers/socket-error'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); // eslint-disable-next-line max-params async function onCopy(connection, mailboxId, update, session, fn) { - logger.debug('COPY', { connection, mailboxId, update, session }); + this.logger.debug('COPY', { connection, mailboxId, update, session }); try { const { alias } = await this.refreshSession(session, 'COPY'); @@ -90,7 +89,7 @@ async function onCopy(connection, mailboxId, update, session, fn) { .maxTimeMS(ms('2m')) .lean() .cursor()) { - logger.debug('copying message', { message }); + this.logger.debug('copying message', { message }); // check if server is in the process of shutting down if (this.server._closeTimeout) throw new ServerShutdownError(); @@ -172,7 +171,7 @@ async function onCopy(connection, mailboxId, update, session, fn) { newMessage.magic ); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -193,7 +192,7 @@ async function onCopy(connection, mailboxId, update, session, fn) { junk: newMessage.junk }); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -216,11 +215,11 @@ async function onCopy(connection, mailboxId, update, session, fn) { isCodeBug: true // admins will get an email/sms alert } ); - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } }) .catch((err) => - logger.fatal(err, { + this.logger.fatal(err, { copiedStorage, connection, mailboxId, @@ -237,7 +236,7 @@ async function onCopy(connection, mailboxId, update, session, fn) { }) .then() .catch((err) => - logger.fatal(err, { + this.logger.fatal(err, { copiedStorage, connection, mailboxId, @@ -255,7 +254,7 @@ async function onCopy(connection, mailboxId, update, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { connection, mailboxId, update, session }); + this.logger.error(err, { connection, mailboxId, update, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-create.js b/helpers/imap/on-create.js index 995be3b17f..438f33bc5f 100644 --- a/helpers/imap/on-create.js +++ b/helpers/imap/on-create.js @@ -18,11 +18,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const config = require('#config'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onCreate(path, session, fn) { - logger.debug('CREATE', { path, session }); + this.logger.debug('CREATE', { path, session }); try { const { alias } = await this.refreshSession(session, 'CREATE'); @@ -73,7 +72,7 @@ async function onCreate(path, session, fn) { }); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { path, session }); + this.logger.fatal(err, { path, session }); } fn(null, true, mailbox._id); @@ -81,7 +80,7 @@ async function onCreate(path, session, fn) { if (err.code === 11000) err.imapResponse = 'ALREADYEXISTS'; // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-delete.js b/helpers/imap/on-delete.js index a95340bbce..3f2cca8910 100644 --- a/helpers/imap/on-delete.js +++ b/helpers/imap/on-delete.js @@ -19,11 +19,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onDelete(path, session, fn) { - logger.debug('DELETE', { path, session }); + this.logger.debug('DELETE', { path, session }); try { const { alias } = await this.refreshSession(session, 'DELETE'); @@ -52,7 +51,7 @@ async function onDelete(path, session, fn) { _id: mailbox._id }); - logger.debug('deleted', { results, path, session }); + this.logger.debug('deleted', { results, path, session }); // results.deletedCount is mainly for publish/notifier if (results.deletedCount > 0) { @@ -63,7 +62,7 @@ async function onDelete(path, session, fn) { }); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { path, session }); + this.logger.fatal(err, { path, session }); } } @@ -89,7 +88,7 @@ async function onDelete(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-expunge.js b/helpers/imap/on-expunge.js index feffbdc5d6..48f650c17f 100644 --- a/helpers/imap/on-expunge.js +++ b/helpers/imap/on-expunge.js @@ -21,12 +21,11 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); // eslint-disable-next-line complexity async function onExpunge(mailboxId, update, session, fn) { - logger.debug('EXPUNGE', { mailboxId, update, session }); + this.logger.debug('EXPUNGE', { mailboxId, update, session }); try { const { alias } = await this.refreshSession(session, 'EXPUNGE'); @@ -72,13 +71,13 @@ async function onExpunge(mailboxId, update, session, fn) { .lean() .cursor(); - logger.debug('expunge query', { query }); + this.logger.debug('expunge query', { query }); let err; try { for await (const message of cursor) { - logger.debug('expunge message', { + this.logger.debug('expunge message', { message, mailboxId, update, @@ -89,7 +88,11 @@ async function onExpunge(mailboxId, update, session, fn) { // TODO: will edge cases like this in cursor() usage ever occur (?) // if (!message) { - logger.fatal('message not expunged', { mailboxId, update, session }); + this.logger.fatal('message not expunged', { + mailboxId, + update, + session + }); // write to stream if ( !update.silent && @@ -122,7 +125,7 @@ async function onExpunge(mailboxId, update, session, fn) { } catch (err) { // duplicate error (already archived) if (err.code === 11000) { - logger.fatal(err, { message. mailboxId, update, session }); + this.logger.fatal(err, { message. mailboxId, update, session }); } else { throw err; } @@ -153,7 +156,7 @@ async function onExpunge(mailboxId, update, session, fn) { .deleteManyPromise(attachmentIds, message.magic) .then() .catch((err) => - logger.fatal(err, { mailboxId, update, session }) + this.logger.fatal(err, { mailboxId, update, session }) ); // write to socket we've expunged message @@ -182,7 +185,7 @@ async function onExpunge(mailboxId, update, session, fn) { }); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } } @@ -194,14 +197,14 @@ async function onExpunge(mailboxId, update, session, fn) { try { await cursor.close(); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } // release lock try { await this.server.lock.releaseLock(lock); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } // update storage quota @@ -218,7 +221,7 @@ async function onExpunge(mailboxId, update, session, fn) { ) .then() .catch((err) => - logger.fatal(err, { storageUsed, mailboxId, update, session }) + this.logger.fatal(err, { storageUsed, mailboxId, update, session }) ); // throw error @@ -228,7 +231,7 @@ async function onExpunge(mailboxId, update, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { mailboxId, update, session }); + this.logger.error(err, { mailboxId, update, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-fetch.js b/helpers/imap/on-fetch.js index dc41fe9dab..3da7e95274 100644 --- a/helpers/imap/on-fetch.js +++ b/helpers/imap/on-fetch.js @@ -26,7 +26,6 @@ const Messages = require('#models/messages'); const ServerShutdownError = require('#helpers/server-shutdown-error'); const SocketError = require('#helpers/socket-error'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); const LIMITED_PROJECTION_KEYS = new Set(['_id', 'flags', 'modseq', 'uid']); @@ -35,8 +34,6 @@ const MAX_BULK_WRITE_SIZE = 150; // eslint-disable-next-line complexity async function getMessages(opts = {}) { - logger.debug('getting messages', opts); - const { server, session, @@ -48,6 +45,8 @@ async function getMessages(opts = {}) { attachmentStorage } = opts; + server.logger.debug('getting messages', opts); + // safeguard if (!_.isObject(query) || _.isEmpty(query)) throw new Error('Query cannot be empty'); @@ -134,7 +133,7 @@ async function getMessages(opts = {}) { }); for await (const message of cursor) { - logger.debug('fetched message', { + server.logger.debug('fetched message', { message, session, options, @@ -153,7 +152,7 @@ async function getMessages(opts = {}) { // break out of cursor if no message retrieved // TODO: does this actually occur as an edge case (?) if (!message) { - logger.fatal('message not fetched', { + server.logger.fatal('message not fetched', { session, options, query, @@ -163,7 +162,7 @@ async function getMessages(opts = {}) { try { await cursor.close(); } catch (err) { - logger.fatal(err, { session, options, query, pageQuery }); + server.logger.fatal(err, { session, options, query, pageQuery }); } // may have more pages, try to fetch more @@ -220,7 +219,7 @@ async function getMessages(opts = {}) { const values = await Promise.all( session .getQueryResponse(options.query, message, { - logger, + logger: server.logger, fetchOptions: {}, // database attachmentStorage, @@ -263,7 +262,7 @@ async function getMessages(opts = {}) { const values = await Promise.all( session .getQueryResponse(options.query, message, { - logger, + logger: server.logger, fetchOptions: {}, // database attachmentStorage, @@ -324,19 +323,19 @@ async function getMessages(opts = {}) { entries = []; server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { message, session, options, query }); + server.logger.fatal(err, { message, session, options, query }); } } } catch (err) { bulkWrite = []; entries = []; - logger.fatal(err, { message, session, options, query }); + server.logger.fatal(err, { message, session, options, query }); // close cursor for cleanup try { await cursor.close(); } catch (err) { - logger.fatal(err, { message, session, options, query }); + server.logger.fatal(err, { message, session, options, query }); } successful = false; @@ -356,7 +355,7 @@ async function getMessages(opts = {}) { } async function onFetch(mailboxId, options, session, fn) { - logger.debug('FETCH', { mailboxId, options, session }); + this.logger.debug('FETCH', { mailboxId, options, session }); try { const { alias } = await this.refreshSession(session, 'FETCH'); @@ -425,7 +424,7 @@ async function onFetch(mailboxId, options, session, fn) { await this.server.notifier.addEntries(mailbox, results.entries); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, options, session }); + this.logger.fatal(err, { mailboxId, options, session }); } } @@ -436,7 +435,7 @@ async function onFetch(mailboxId, options, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { mailboxId, options, session }); + this.logger.error(err, { mailboxId, options, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-get-quota-root.js b/helpers/imap/on-get-quota-root.js index 1bafa20e41..e5c997fa65 100644 --- a/helpers/imap/on-get-quota-root.js +++ b/helpers/imap/on-get-quota-root.js @@ -18,11 +18,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const config = require('#config'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onGetQuotaRoot(path, session, fn) { - logger.debug('GETQUOTAROOT', { path, session }); + this.logger.debug('GETQUOTAROOT', { path, session }); try { const { alias } = await this.refreshSession(session, 'GETQUOTAROOT'); @@ -49,7 +48,7 @@ async function onGetQuotaRoot(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-get-quota.js b/helpers/imap/on-get-quota.js index b01ea1989d..f8975a49a0 100644 --- a/helpers/imap/on-get-quota.js +++ b/helpers/imap/on-get-quota.js @@ -17,11 +17,10 @@ const Aliases = require('#models/aliases'); const config = require('#config'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onGetQuota(path, session, fn) { - logger.debug('GETQUOTA', { path, session }); + this.logger.debug('GETQUOTA', { path, session }); try { const { alias } = await this.refreshSession(session, 'GETQUOTA'); @@ -38,7 +37,7 @@ async function onGetQuota(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-list.js b/helpers/imap/on-list.js index 66d0855469..b2e0f53409 100644 --- a/helpers/imap/on-list.js +++ b/helpers/imap/on-list.js @@ -16,11 +16,10 @@ const ms = require('ms'); const Mailboxes = require('#models/mailboxes'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onList(query, session, fn) { - logger.debug('LIST', { query, session }); + this.logger.debug('LIST', { query, session }); try { const { alias } = await this.refreshSession(session, 'LIST'); @@ -36,7 +35,7 @@ async function onList(query, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { query, session }); + this.logger.error(err, { query, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-lsub.js b/helpers/imap/on-lsub.js index d88eb08f2a..8cdf115bf8 100644 --- a/helpers/imap/on-lsub.js +++ b/helpers/imap/on-lsub.js @@ -16,11 +16,10 @@ const ms = require('ms'); const Mailboxes = require('#models/mailboxes'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onLsub(query, session, fn) { - logger.debug('LSUB', { query, session }); + this.logger.debug('LSUB', { query, session }); try { const { alias } = await this.refreshSession(session, 'LSUB'); @@ -37,7 +36,7 @@ async function onLsub(query, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { query, session }); + this.logger.error(err, { query, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-move.js b/helpers/imap/on-move.js index d6bd206121..bab5202c20 100644 --- a/helpers/imap/on-move.js +++ b/helpers/imap/on-move.js @@ -21,14 +21,13 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); const BULK_BATCH_SIZE = 150; // eslint-disable-next-line complexity async function onMove(mailboxId, update, session, fn) { - logger.debug('MOVE', { mailboxId, update, session }); + this.logger.debug('MOVE', { mailboxId, update, session }); try { const { alias } = await this.refreshSession(session, 'MOVE'); @@ -115,7 +114,7 @@ async function onMove(mailboxId, update, session, fn) { const newModseq = updatedMailbox.modifyIndex || 1; for await (let message of cursor.cursor()) { - logger.debug('fetched message', { + this.logger.debug('fetched message', { message, mailboxId, update, @@ -125,7 +124,7 @@ async function onMove(mailboxId, update, session, fn) { // return early if no message // TODO: does this actually occur as an edge case (?) if (!message) { - logger.fatal('message not fetched', { + this.logger.fatal('message not fetched', { mailboxId, update, session @@ -240,7 +239,7 @@ async function onMove(mailboxId, update, session, fn) { thread: message.thread }); } else { - logger.fatal(new Error('failed to delete old message'), { + this.logger.fatal(new Error('failed to delete old message'), { mailboxId, update, session @@ -257,7 +256,7 @@ async function onMove(mailboxId, update, session, fn) { expungeEntries = []; this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -271,7 +270,7 @@ async function onMove(mailboxId, update, session, fn) { existEntries = []; this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } } @@ -283,7 +282,7 @@ async function onMove(mailboxId, update, session, fn) { try { await this.server.lock.releaseLock(lock); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } // write any if needed @@ -308,7 +307,7 @@ async function onMove(mailboxId, update, session, fn) { await this.server.notifier.addEntries(mailbox, expungeEntries); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -318,7 +317,7 @@ async function onMove(mailboxId, update, session, fn) { await this.server.notifier.addEntries(targetMailbox, existEntries); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -338,7 +337,7 @@ async function onMove(mailboxId, update, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { mailboxId, update, session }); + this.logger.error(err, { mailboxId, update, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-open.js b/helpers/imap/on-open.js index a2ff6e7b6c..8544688252 100644 --- a/helpers/imap/on-open.js +++ b/helpers/imap/on-open.js @@ -19,11 +19,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onOpen(path, session, fn) { - logger.debug('OPEN', { path, session }); + this.logger.debug('OPEN', { path, session }); try { const { alias } = await this.refreshSession(session, 'OPEN'); @@ -61,7 +60,7 @@ async function onOpen(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-rename.js b/helpers/imap/on-rename.js index ddb50b9097..a1d72db41a 100644 --- a/helpers/imap/on-rename.js +++ b/helpers/imap/on-rename.js @@ -17,12 +17,11 @@ const ms = require('ms'); const Mailboxes = require('#models/mailboxes'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); const IMAPError = require('#helpers/imap-error'); async function onRename(path, newPath, session, fn) { - logger.debug('RENAME', { path, newPath, session }); + this.logger.debug('RENAME', { path, newPath, session }); try { const { alias } = await this.refreshSession(session, 'RENAME'); @@ -85,7 +84,7 @@ async function onRename(path, newPath, session, fn) { }); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { path, session }); + this.logger.fatal(err, { path, session }); } // send response @@ -93,7 +92,7 @@ async function onRename(path, newPath, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, newPath, session }); + this.logger.error(err, { path, newPath, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-search.js b/helpers/imap/on-search.js index 9e46ac7bb6..7235acdf3d 100644 --- a/helpers/imap/on-search.js +++ b/helpers/imap/on-search.js @@ -23,11 +23,10 @@ const IMAPError = require('#helpers/imap-error'); const Messages = require('#models/messages'); const Mailboxes = require('#models/mailboxes'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onSearch(mailboxId, options, session, fn) { - logger.debug('SEARCH', { mailboxId, options, session, fn }); + this.logger.debug('SEARCH', { mailboxId, options, session, fn }); try { const { alias } = await this.refreshSession(session, 'SEARCH'); @@ -454,7 +453,7 @@ async function onSearch(mailboxId, options, session, fn) { try { for await (const message of cursor) { - logger.debug('fetched message', { + this.logger.debug('fetched message', { message, mailboxId, options, @@ -468,7 +467,7 @@ async function onSearch(mailboxId, options, session, fn) { uidList.push(message.uid); } } catch (err) { - logger.fatal(err, { mailboxId, options, session }); + this.logger.fatal(err, { mailboxId, options, session }); throw new IMAPError(i18n.translateError('IMAP_INVALID_SEARCH')); } @@ -476,7 +475,7 @@ async function onSearch(mailboxId, options, session, fn) { try { await cursor.close(); } catch (err) { - logger.fatal(err, { mailboxId, options, session }); + this.logger.fatal(err, { mailboxId, options, session }); } // send response @@ -487,7 +486,7 @@ async function onSearch(mailboxId, options, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { mailboxId, options, session }); + this.logger.error(err, { mailboxId, options, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-status.js b/helpers/imap/on-status.js index e36b6f86fc..9fe3704389 100644 --- a/helpers/imap/on-status.js +++ b/helpers/imap/on-status.js @@ -19,11 +19,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onStatus(path, session, fn) { - logger.debug('STATUS', { path, session }); + this.logger.debug('STATUS', { path, session }); try { const { alias } = await this.refreshSession(session, 'STATUS'); @@ -66,7 +65,7 @@ async function onStatus(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-store.js b/helpers/imap/on-store.js index 48d6bfa0e8..87dc295dd3 100644 --- a/helpers/imap/on-store.js +++ b/helpers/imap/on-store.js @@ -21,7 +21,6 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); const MAX_BULK_WRITE_SIZE = 150; @@ -51,7 +50,7 @@ async function getModseq(mailbox, alias) { // eslint-disable-next-line complexity async function onStore(mailboxId, update, session, fn) { - logger.debug('STORE', { mailboxId, update, session }); + this.logger.debug('STORE', { mailboxId, update, session }); try { const { alias } = await this.refreshSession(session, 'STORE'); @@ -104,7 +103,7 @@ async function onStore(mailboxId, update, session, fn) { try { for await (const message of cursor) { - logger.debug('fetched message', { + this.logger.debug('fetched message', { message, mailboxId, update, @@ -114,7 +113,7 @@ async function onStore(mailboxId, update, session, fn) { // return early if no message // TODO: does this actually occur as an edge case (?) if (!message) { - logger.fatal('message not fetched', { + this.logger.fatal('message not fetched', { mailboxId, update, session @@ -361,7 +360,7 @@ async function onStore(mailboxId, update, session, fn) { bulkWrite = []; } catch (err) { bulkWrite = []; - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); throw err; } @@ -371,7 +370,7 @@ async function onStore(mailboxId, update, session, fn) { this.server.notifier.fire(alias.id); entries = []; } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } } @@ -384,7 +383,7 @@ async function onStore(mailboxId, update, session, fn) { try { await cursor.close(); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } // update messages @@ -399,7 +398,7 @@ async function onStore(mailboxId, update, session, fn) { await this.server.notifier.addEntries(mailbox, entries); this.server.notifier.fire(alias.id); } catch (err) { - logger.fatal(err, { mailboxId, update, session }); + this.logger.fatal(err, { mailboxId, update, session }); } } @@ -449,7 +448,7 @@ async function onStore(mailboxId, update, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { mailboxId, update, session }); + this.logger.error(err, { mailboxId, update, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-subscribe.js b/helpers/imap/on-subscribe.js index 98a632617c..7268b07143 100644 --- a/helpers/imap/on-subscribe.js +++ b/helpers/imap/on-subscribe.js @@ -16,11 +16,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onSubscribe(path, session, fn) { - logger.debug('SUBSCRIBE', { path, session }); + this.logger.debug('SUBSCRIBE', { path, session }); try { const { alias } = await this.refreshSession(session, 'SUBSCRIBE'); @@ -48,7 +47,7 @@ async function onSubscribe(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/imap/on-unsubscribe.js b/helpers/imap/on-unsubscribe.js index a5a562f202..3fd7f343f2 100644 --- a/helpers/imap/on-unsubscribe.js +++ b/helpers/imap/on-unsubscribe.js @@ -16,11 +16,10 @@ const IMAPError = require('#helpers/imap-error'); const Mailboxes = require('#models/mailboxes'); const i18n = require('#helpers/i18n'); -const logger = require('#helpers/logger'); const refineAndLogError = require('#helpers/refine-and-log-error'); async function onUnsubscribe(path, session, fn) { - logger.debug('UNSUBSCRIBE', { path, session }); + this.logger.debug('UNSUBSCRIBE', { path, session }); try { const { alias } = await this.refreshSession(session, 'UNSUBSCRIBE'); @@ -48,7 +47,7 @@ async function onUnsubscribe(path, session, fn) { } catch (err) { // NOTE: wildduck uses `imapResponse` so we are keeping it consistent if (err.imapResponse) { - logger.error(err, { path, session }); + this.logger.error(err, { path, session }); return fn(null, err.imapResponse); } diff --git a/helpers/on-auth.js b/helpers/on-auth.js index 158654eaf6..652274a46b 100644 --- a/helpers/on-auth.js +++ b/helpers/on-auth.js @@ -12,7 +12,6 @@ const { isEmail } = require('validator'); const SMTPError = require('./smtp-error'); const ServerShutdownError = require('./server-shutdown-error'); const SocketError = require('./socket-error'); -const logger = require('./logger'); const parseRootDomain = require('./parse-root-domain'); const refineAndLogError = require('./refine-and-log-error'); const validateAlias = require('./validate-alias'); @@ -41,7 +40,7 @@ const REQUIRED_PATHS = [ // eslint-disable-next-line complexity async function onAuth(auth, session, fn) { - logger.debug('AUTH', { auth, session }); + this.logger.debug('AUTH', { auth, session }); // TODO: credit system + domain billing rules (assigned billing manager -> person who gets credits deducted) // TODO: salt/hash/deprecate legacy API token + remove from API docs page @@ -114,7 +113,7 @@ async function onAuth(auth, session, fn) { verifications.push(record.replace(config.paidPrefix, '').trim()); } } catch (err) { - logger.error(err, { session }); + this.logger.error(err, { session }); } if (verifications.length === 0) @@ -217,7 +216,7 @@ async function onAuth(auth, session, fn) { this.client .del(`${this.rateLimiter.namespace}:${session.remoteAddress}`) .then() - .catch((err) => this.config.logger.fatal(err)); + .catch((err) => this.logger.fatal(err)); // // If this was IMAP server then ensure the user has all essential folders @@ -233,7 +232,7 @@ async function onAuth(auth, session, fn) { } if (required.length > 0) { - logger.debug('creating required', { required }); + this.logger.debug('creating required', { required }); await Mailboxes.create( required.map((path) => ({ alias: alias._id, @@ -242,7 +241,7 @@ async function onAuth(auth, session, fn) { ); } } catch (err) { - logger.fatal(err, { session }); + this.logger.fatal(err, { session }); } } diff --git a/imap-server.js b/imap-server.js index 0d277c72d0..b7b91e6af0 100644 --- a/imap-server.js +++ b/imap-server.js @@ -17,6 +17,7 @@ const fs = require('node:fs'); const os = require('node:os'); const AttachmentStorage = require('wildduck/lib/attachment-storage'); +const Axe = require('axe'); const Indexer = require('wildduck/imap-core/lib/indexer/indexer'); const Lock = require('ioredfour'); const MessageHandler = require('wildduck/lib/message-handler'); @@ -59,6 +60,7 @@ const validateDomain = require('#helpers/validate-domain'); // - [ ] increase limit to 30gb with paid-addon // TODO: urgent items +// - [ ] attachment model and indexes // - [ ] enforce billing for IMAP support // - [ ] when users delete their account then delete all Emails, Messages, and Mailboxes in the system // - [ ] auto expunge in bree job when message gets a Deleted flag @@ -108,6 +110,9 @@ class IMAP { namespace: config.smtpLimitNamespace }); + this.logger = + config.env === 'development' ? logger : new Axe({ silent: true }); + const server = new IMAPServer({ secure, secured: false, @@ -120,7 +125,7 @@ class IMAP { version: config.pkg.version, vendor: config.pkg.author }, - logger: config.env === 'development' ? logger : false, + logger: this.logger, maxMessage: bytes('50MB'), // NOTE: we don't need this since we have custom logic @@ -144,8 +149,10 @@ class IMAP { : {}) }); - // server.loggelf = - // config.env === 'development' ? (...args) => logger.info(...args) : false; + // override logger + server.logger = this.logger; + + server.loggelf = (...args) => this.logger.debug(...args); server.lock = new Lock({ redis: this.client, @@ -177,7 +184,7 @@ class IMAP { server.address = server.server.address.bind(server.server); server.on('error', (err) => { - logger.warn(err); + logger.error(err); }); // diff --git a/smtp-server.js b/smtp-server.js index 9d950e6508..f945395632 100644 --- a/smtp-server.js +++ b/smtp-server.js @@ -5,6 +5,7 @@ const fs = require('node:fs'); +const Axe = require('axe'); const RateLimiter = require('async-ratelimiter'); const bytes = require('bytes'); const ms = require('ms'); @@ -43,6 +44,9 @@ class SMTP { namespace: config.smtpLimitNamespace }); + this.logger = + config.env === 'development' ? logger : new Axe({ silent: true }); + // setup our smtp server which listens for incoming email // TODO: this.server = new SMTPServer({ @@ -67,7 +71,7 @@ class SMTP { closeTimeout: ms('30s'), // disableReverseLookup: true, - logger: config.env === 'production' ? false : logger, + logger: this.logger, disabledCommands: secure ? ['STARTTLS'] : [], secure, @@ -89,12 +93,15 @@ class SMTP { : {}) }); + // override logger + this.server.logger = this.logger; + // kind of hacky but I filed a GH issue // this.server.address = this.server.server.address.bind(this.server.server); this.server.on('error', (err) => { - logger.warn(err); + logger.error(err); }); this.listen = this.listen.bind(this); diff --git a/test/imap/index.js b/test/imap/index.js index 93686611ae..209fd9820b 100644 --- a/test/imap/index.js +++ b/test/imap/index.js @@ -16,6 +16,7 @@ const { createHash } = require('node:crypto'); // NOTE: wait command not supported by `ioredis-mock` // const Redis = require('ioredis-mock'); // +const Axe = require('axe'); const Redis = require('@ladjs/redis'); const dayjs = require('dayjs-with-plugins'); const getPort = require('get-port'); @@ -34,8 +35,8 @@ const Aliases = require('#models/aliases'); const Mailboxes = require('#models/mailboxes'); const Messages = require('#models/messages'); const config = require('#config'); -const logger = require('#helpers/logger'); +const logger = new Axe({ silent: true }); const IP_ADDRESS = ip.address(); const client = new Redis(); const subscriber = new Redis();