From 1605198a1ac5927c8b355efd3250700f7dcdf81b Mon Sep 17 00:00:00 2001 From: Naz Date: Tue, 30 May 2023 16:24:14 +0700 Subject: [PATCH] Added debug data dump to email service closes https://github.com/TryGhost/Team/issues/3324 - When the recipients batch size is larger than the limit in addition to logging the error we need extra data to figure out what exactly is inside those `2000` or `3000` records causing faulty behavior. - This change grabs all available models and dumps them into a file inside of the `content/data` folder. The code is temporary and should be removed once the problem is narrowed down --- .../email-service/EmailServiceWrapper.js | 3 +- .../email-service/lib/BatchSendingService.js | 24 ++- .../test/batch-sending-service.test.js | 194 ++++++++++++++++++ 3 files changed, 219 insertions(+), 2 deletions(-) diff --git a/ghost/core/core/server/services/email-service/EmailServiceWrapper.js b/ghost/core/core/server/services/email-service/EmailServiceWrapper.js index 0038506392..fed21f955e 100644 --- a/ghost/core/core/server/services/email-service/EmailServiceWrapper.js +++ b/ghost/core/core/server/services/email-service/EmailServiceWrapper.js @@ -94,7 +94,8 @@ class EmailServiceWrapper { emailSegmenter, emailRenderer, db, - sentry + sentry, + debugStorageFilePath: configService.getContentPath('data') }); this.renderer = emailRenderer; diff --git a/ghost/email-service/lib/BatchSendingService.js b/ghost/email-service/lib/BatchSendingService.js index 97ad577e88..6705b69edb 100644 --- a/ghost/email-service/lib/BatchSendingService.js +++ b/ghost/email-service/lib/BatchSendingService.js @@ -32,6 +32,7 @@ class BatchSendingService { #models; #db; #sentry; + #debugStorageFilePath; // Retry database queries happening before sending the email #BEFORE_RETRY_CONFIG = {maxRetries: 10, maxTime: 10 * 60 * 1000, sleep: 2000}; @@ -54,6 +55,7 @@ class BatchSendingService { * @param {object} [dependencies.BEFORE_RETRY_CONFIG] * @param {object} [dependencies.AFTER_RETRY_CONFIG] * @param {object} [dependencies.MAILGUN_API_RETRY_CONFIG] + * @param {string} [dependencies.debugStorageFilePath] */ constructor({ emailRenderer, @@ -65,7 +67,8 @@ class BatchSendingService { sentry, BEFORE_RETRY_CONFIG, AFTER_RETRY_CONFIG, - MAILGUN_API_RETRY_CONFIG + MAILGUN_API_RETRY_CONFIG, + debugStorageFilePath }) { this.#emailRenderer = emailRenderer; this.#sendingService = sendingService; @@ -74,6 +77,7 @@ class BatchSendingService { this.#models = models; this.#db = db; this.#sentry = sentry; + this.#debugStorageFilePath = debugStorageFilePath; if (BEFORE_RETRY_CONFIG) { this.#BEFORE_RETRY_CONFIG = BEFORE_RETRY_CONFIG; @@ -533,6 +537,24 @@ class BatchSendingService { const BATCH_SIZE = this.#sendingService.getMaximumRecipients(); if (mappedMemberLikes.length > BATCH_SIZE) { logging.error(`Batch ${batchId} has ${mappedMemberLikes.length} members, but the sending service only supports ${BATCH_SIZE} members per batch.`); + + // @NOTE below is a throwaway code, that's why it is dirty and lives here instead of a nice module + if (this.#debugStorageFilePath) { + try { + const fs = require('fs-extra'); + const path = require('path'); + const currentTimeFilename = new Date().toISOString().replace(/:/g, '-').replace(/\./gi, '-'); + const outputFileName = `email-batch-sending-members-${currentTimeFilename}.json`; + const outputFilePath = path.join(this.#debugStorageFilePath, '/', outputFileName); + const jsonData = JSON.stringify(models, null, 4); + + logging.info(`Writing members object dump to ${outputFilePath}`); + await fs.writeFile(outputFilePath, jsonData); + } catch (e) { + logging.error(`Failed to write members object dump to ${this.#debugStorageFilePath}`); + logging.error(e); + } + } } return mappedMemberLikes; diff --git a/ghost/email-service/test/batch-sending-service.test.js b/ghost/email-service/test/batch-sending-service.test.js index de7d3409bd..16f2cf682a 100644 --- a/ghost/email-service/test/batch-sending-service.test.js +++ b/ghost/email-service/test/batch-sending-service.test.js @@ -11,6 +11,7 @@ describe('Batch Sending Service', function () { beforeEach(function () { errorLog = sinon.stub(logging, 'error'); + sinon.stub(logging, 'info'); }); afterEach(function () { @@ -1041,6 +1042,199 @@ describe('Batch Sending Service', function () { sinon.assert.notCalled(sendingService.send); }); + + it('Dumps members information into a file when recipients count is over the sender limit', async function () { + const fs = require('fs-extra'); + + const EmailBatch = createModelClass({ + findOne: { + status: 'pending', + member_segment: null + } + }); + const findOne = sinon.spy(EmailBatch, 'findOne'); + const fsStub = sinon.stub(fs, 'writeFile').resolves(); + const dbMembers = [ + { + member_id: '123', + member_uuid: '123', + member_email: 'example@example.com', + member_name: 'Test User', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + loaded: ['stripeSubscriptions', 'products'], + status: 'free', + stripeSubscriptions: [], + products: [] + }) + }, + { + member_id: '124', + member_uuid: '124', + member_email: 'example2@example.com', + member_name: 'Test User 2', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + status: 'free', + loaded: ['stripeSubscriptions', 'products'], + stripeSubscriptions: [], + products: [] + }) + }, + { + member_id: '125', + member_uuid: '125', + member_email: 'example3@example.com', + member_name: 'Test User 3', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + status: 'free', + loaded: ['stripeSubscriptions', 'products'], + stripeSubscriptions: [], + products: [] + }) + }, + { + member_id: '125', + member_uuid: '125', + member_email: 'example3@example.com', + member_name: 'Test User 3', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + status: 'free', + loaded: ['stripeSubscriptions', 'products'], + stripeSubscriptions: [], + products: [] + }) + } + ]; + + const DoubleTheEmailRecipients = createModelClass({ + findAll: dbMembers + }); + + const sendingService = { + send: sinon.stub().resolves({id: 'providerid@example.com'}), + getMaximumRecipients: () => 2 + }; + + const service = new BatchSendingService({ + models: { + EmailBatch, + EmailRecipient: DoubleTheEmailRecipients + }, + sendingService, + BEFORE_RETRY_CONFIG: {maxRetries: 10, maxTime: 2000, sleep: 1}, + debugStorageFilePath: '/tmp/' + }); + + const result = await service.sendBatch({ + email: createModel({}), + batch: createModel({}), + post: createModel({}), + newsletter: createModel({}) + }); + + // dumps the members into a file + assert.ok(fsStub.calledOnce); + assert.match(fsStub.firstCall.args[0], /\/tmp\/email-batch-sending-members-(.+)Z\.json/); + assert.match(fsStub.firstCall.args[1], /example@example.com/gi); + + // still sends the batch + assert.equal(result, true); + sinon.assert.calledOnce(sendingService.send); + + const {members} = sendingService.send.firstCall.args[0]; + assert.equal(members.length, 2); + + sinon.assert.calledOnce(findOne); + const batch = await findOne.firstCall.returnValue; + assert.equal(batch.get('status'), 'submitted'); + assert.equal(batch.get('provider_id'), 'providerid@example.com'); + }); + + it('Catches an error when dumping members into a file', async function () { + const fs = require('fs-extra'); + + const EmailBatch = createModelClass({ + findOne: { + status: 'pending', + member_segment: null + } + }); + const dbMembers = [ + { + member_id: '123', + member_uuid: '123', + member_email: 'example@example.com', + member_name: 'Test User', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + loaded: ['stripeSubscriptions', 'products'], + status: 'free', + stripeSubscriptions: [], + products: [] + }) + }, + { + member_id: '124', + member_uuid: '124', + member_email: 'example2@example.com', + member_name: 'Test User 2', + loaded: ['member'], + member: createModel({ + created_at: new Date(), + status: 'free', + loaded: ['stripeSubscriptions', 'products'], + stripeSubscriptions: [], + products: [] + }) + } + ]; + + const fsStub = sinon.stub(fs, 'writeFile').rejects('oops'); + + const DoubleTheEmailRecipients = createModelClass({ + findAll: dbMembers + }); + + const sendingService = { + send: sinon.stub().resolves({id: 'providerid@example.com'}), + getMaximumRecipients: () => 1 + }; + + const service = new BatchSendingService({ + models: { + EmailBatch, + EmailRecipient: DoubleTheEmailRecipients + }, + sendingService, + BEFORE_RETRY_CONFIG: {maxRetries: 10, maxTime: 2000, sleep: 1}, + debugStorageFilePath: '/tmp/' + }); + + await service.sendBatch({ + email: createModel({}), + batch: createModel({}), + post: createModel({}), + newsletter: createModel({}) + }); + + assert.ok(fsStub.calledOnce); + assert.equal(errorLog.callCount, 5, 'should have logged 5 errors'); + const firstLoggedError = errorLog.firstCall.args[0]; + const secondLoggedError = errorLog.secondCall.args[0]; + const thirdLoggedError = errorLog.thirdCall.args[0]; + + assert.match(firstLoggedError, /Batch [a-f0-9]{24} has 2 members, but the sending service only supports 1 members per batch/); + assert.match(secondLoggedError, /Failed to write members object dump to/); + assert.equal(thirdLoggedError.name, 'oops'); + }); }); describe('getBatchMembers', function () {