From 94e85dc09e1b0c78e7dcc354f97487811e306bb8 Mon Sep 17 00:00:00 2001 From: Simon Backx Date: Wed, 14 Dec 2022 17:50:42 +0100 Subject: [PATCH] Reduced webhook calls when updating last_seen_at for email opens (#16008) refs https://ghost.slack.com/archives/C02G9E68C/p1670960248186789 This reverts a change that was made here: https://github.com/TryGhost/Ghost/commit/f4fdb4fa6cfc47747856eff84cae4e3fb51d1730#r93071549, but it still moved the original code to a new location in the LastSeenAtUpdater It includes a new E2E test to make sure timezones are supported correctly. - By not using Bookshelf, we no longer fire webhook calls - By not using the member repository, we don't fetch and update the member model and the labels relation in a forUpdate transaction, which caused deadlock issues on the labels/members_labels tables which were hard to resolve. Until now I was unable to find the other conflicting transaction that caused this deadlock. Moving to raw knex (instead of Bookshelf) and only updating the last_updated_at column should remove the deadlock issue. This removed the test for the email service wrapper, since it started failing for an unknown reason and the test didn't make much sense (was added earlier only to bump test threshold). --- .../server/services/members-events/index.js | 5 +- .../services/last-seen-at-updater.test.js | 46 +++++++++++++++++++ .../email-service/EmailServiceWrapper.test.js | 19 -------- .../lib/last-seen-at-updater.js | 26 +++++++---- .../test/last-seen-at-updater.test.js | 35 +++++++------- 5 files changed, 85 insertions(+), 46 deletions(-) create mode 100644 ghost/core/test/integration/services/last-seen-at-updater.test.js delete mode 100644 ghost/core/test/unit/server/services/email-service/EmailServiceWrapper.test.js diff --git a/ghost/core/core/server/services/members-events/index.js b/ghost/core/core/server/services/members-events/index.js index 58ac5062d3..a99592d093 100644 --- a/ghost/core/core/server/services/members-events/index.js +++ b/ghost/core/core/server/services/members-events/index.js @@ -23,13 +23,16 @@ class MembersEventsServiceWrapper { labsService }); + const db = require('../../data/db'); + this.lastSeenAtUpdater = new LastSeenAtUpdater({ services: { settingsCache }, getMembersApi() { return members.api; - } + }, + db }); this.eventStorage.subscribe(DomainEvents); diff --git a/ghost/core/test/integration/services/last-seen-at-updater.test.js b/ghost/core/test/integration/services/last-seen-at-updater.test.js new file mode 100644 index 0000000000..fc7f3bcc08 --- /dev/null +++ b/ghost/core/test/integration/services/last-seen-at-updater.test.js @@ -0,0 +1,46 @@ +require('should'); +const {agentProvider, fixtureManager, mockManager} = require('../../utils/e2e-framework'); +const models = require('../../../core/server/models'); +const assert = require('assert'); +let agent; + +describe('Last Seen At Updater', function () { + before(async function () { + agent = await agentProvider.getAdminAPIAgent(); + await fixtureManager.init('newsletters', 'members:newsletters'); + await agent.loginAsOwner(); + }); + + it('updateLastSeenAtWithoutKnownLastSeen', async function () { + const membersEvents = require('../../../core/server/services/members-events'); + + // Fire lots of EmailOpenedEvent for the same + const memberId = fixtureManager.get('members', 0).id; + + const firstDate = new Date(Date.UTC(2099, 11, 31, 21, 0, 0, 0)); + // In UTC this is 2099-12-31 21:00:00 + // In CET this is 2099-12-31 22:00:00 + + const secondDate = new Date(Date.UTC(2099, 11, 31, 22, 0, 0, 0)); + // In UTC this is 2099-12-31 22:00:00 + // In CET this is 2099-12-31 23:00:00 + + const newDay = new Date(Date.UTC(2099, 11, 31, 23, 0, 0, 0)); + // In UTC this is 2099-12-31 23:00:00 + // In CET this is 2100-01-01 00:00:00 + + async function assertLastSeen(date) { + const member = await models.Member.findOne({id: memberId}, {require: true}); + assert.equal(member.get('last_seen_at').getTime(), date.getTime()); + } + + mockManager.mockSetting('timezone', 'CET'); + + await membersEvents.lastSeenAtUpdater.updateLastSeenAtWithoutKnownLastSeen(memberId, firstDate); + await assertLastSeen(firstDate); + await membersEvents.lastSeenAtUpdater.updateLastSeenAtWithoutKnownLastSeen(memberId, secondDate); + await assertLastSeen(firstDate); // not changed + await membersEvents.lastSeenAtUpdater.updateLastSeenAtWithoutKnownLastSeen(memberId, newDay); + await assertLastSeen(newDay); // changed + }); +}); diff --git a/ghost/core/test/unit/server/services/email-service/EmailServiceWrapper.test.js b/ghost/core/test/unit/server/services/email-service/EmailServiceWrapper.test.js deleted file mode 100644 index 5279370e0e..0000000000 --- a/ghost/core/test/unit/server/services/email-service/EmailServiceWrapper.test.js +++ /dev/null @@ -1,19 +0,0 @@ -describe('EmailServiceWrapper', function () { - it('Does not throw', async function () { - const offersService = require('../../../../../core/server/services/offers'); - await offersService.init(); - - const memberService = require('../../../../../core/server/services/members'); - await memberService.init(); - - const service = require('../../../../../core/server/services/email-service'); - service.init(); - - // Increase test coverage for the wrapper - service.getPostUrl({ - toJSON: () => [{ - id: '1' - }] - }); - }); -}); diff --git a/ghost/members-events-service/lib/last-seen-at-updater.js b/ghost/members-events-service/lib/last-seen-at-updater.js index 34f95b0a3b..269dbd28d2 100644 --- a/ghost/members-events-service/lib/last-seen-at-updater.js +++ b/ghost/members-events-service/lib/last-seen-at-updater.js @@ -14,12 +14,14 @@ class LastSeenAtUpdater { * @param {Object} deps.services The list of service dependencies * @param {any} deps.services.settingsCache The settings service * @param {() => object} deps.getMembersApi - A function which returns an instance of members-api + * @param {any} deps.db Database connection */ constructor({ services: { settingsCache }, - getMembersApi + getMembersApi, + db }) { if (!getMembersApi) { throw new IncorrectUsageError({message: 'Missing option getMembersApi'}); @@ -27,6 +29,7 @@ class LastSeenAtUpdater { this._getMembersApi = getMembersApi; this._settingsCacheService = settingsCache; + this._db = db; } /** * Subscribe to events of this domainEvents service @@ -79,13 +82,20 @@ class LastSeenAtUpdater { * @param {Date} timestamp The event timestamp */ async updateLastSeenAtWithoutKnownLastSeen(memberId, timestamp) { - // Fetch manually - const membersApi = this._getMembersApi(); - const member = await membersApi.members.get({id: memberId}, {require: true}); - if (member) { - const memberLastSeenAt = member.get('last_seen_at'); - await this.updateLastSeenAt(memberId, memberLastSeenAt, timestamp); - } + // Note: we are not using Bookshelf / member repository to prevent firing webhooks + to prevent deadlock issues + // If we would use the member repostiory, we would create a forUpdate lock when editing the member, including when fetching the member labels. Creating a possible deadlock if somewhere else we do the reverse in a transaction. + const timezone = this._settingsCacheService.get('timezone') || 'Etc/UTC'; + const startOfDayInSiteTimezone = moment.utc(timestamp).tz(timezone).startOf('day').utc().format('YYYY-MM-DD HH:mm:ss'); + const formattedTimestamp = moment.utc(timestamp).format('YYYY-MM-DD HH:mm:ss'); + await this._db.knex('members') + .where('id', '=', memberId) + .andWhere(builder => builder + .where('last_seen_at', '<', startOfDayInSiteTimezone) + .orWhereNull('last_seen_at') + ) + .update({ + last_seen_at: formattedTimestamp + }); } /** diff --git a/ghost/members-events-service/test/last-seen-at-updater.test.js b/ghost/members-events-service/test/last-seen-at-updater.test.js index e80185da19..76522904af 100644 --- a/ghost/members-events-service/test/last-seen-at-updater.test.js +++ b/ghost/members-events-service/test/last-seen-at-updater.test.js @@ -44,14 +44,19 @@ describe('LastSeenAtUpdater', function () { it('Calls updateLastSeenAt on email opened events', async function () { const now = moment('2022-02-28T18:00:00Z').utc(); - const previousLastSeen = moment('2022-02-27T23:00:00Z').toISOString(); - const stub = sinon.stub().resolves(); - const getStub = sinon.stub().resolves({ - get() { - return previousLastSeen; - } - }); const settingsCache = sinon.stub().returns('Etc/UTC'); + const db = { + knex() { + return this; + }, + where() { + return this; + }, + andWhere() { + return this; + }, + update: sinon.stub() + }; const updater = new LastSeenAtUpdater({ services: { settingsCache: { @@ -59,13 +64,9 @@ describe('LastSeenAtUpdater', function () { } }, getMembersApi() { - return { - members: { - update: stub, - get: getStub - } - }; - } + return {}; + }, + db }); updater.subscribe(DomainEvents); sinon.spy(updater, 'updateLastSeenAt'); @@ -73,10 +74,8 @@ describe('LastSeenAtUpdater', function () { DomainEvents.dispatch(EmailOpenedEvent.create({memberId: '1', emailRecipientId: '1', emailId: '1', timestamp: now.toDate()})); // Wait for next tick await sleep(50); - assert(updater.updateLastSeenAt.calledOnceWithExactly('1', previousLastSeen, now.toDate())); assert(updater.updateLastSeenAtWithoutKnownLastSeen.calledOnceWithExactly('1', now.toDate())); - assert(getStub.calledOnce); - assert(stub.calledOnce); + assert(db.update.calledOnce); }); it('Calls updateLastCommentedAt on MemberCommentEvents', async function () { @@ -369,7 +368,7 @@ describe('LastSeenAtUpdater', function () { it('throws if getMembersApi is not passed to LastSeenAtUpdater', async function () { const settingsCache = sinon.stub().returns('Asia/Bangkok'); - + should.throws(() => { new LastSeenAtUpdater({ services: {