diff --git a/ghost/core/core/server/services/members-events/index.js b/ghost/core/core/server/services/members-events/index.js index a99592d093..411e28d840 100644 --- a/ghost/core/core/server/services/members-events/index.js +++ b/ghost/core/core/server/services/members-events/index.js @@ -1,5 +1,6 @@ const labsService = require('../../../shared/labs'); const DomainEvents = require('@tryghost/domain-events'); +const events = require('../../lib/common/events'); const settingsCache = require('../../../shared/settings-cache'); const members = require('../members'); @@ -32,7 +33,8 @@ class MembersEventsServiceWrapper { getMembersApi() { return members.api; }, - db + db, + events }); this.eventStorage.subscribe(DomainEvents); diff --git a/ghost/core/test/e2e-server/__snapshots__/click-tracking.test.js.snap b/ghost/core/test/e2e-server/__snapshots__/click-tracking.test.js.snap new file mode 100644 index 0000000000..5d53952d5c --- /dev/null +++ b/ghost/core/test/e2e-server/__snapshots__/click-tracking.test.js.snap @@ -0,0 +1,43 @@ +// Jest Snapshot v1, https://goo.gl/fbAQLP + +exports[`Click Tracking Full test 1: [headers] 1`] = ` +Object { + "accept-encoding": "gzip, deflate, br", + "content-length": Any, + "content-type": "application/json", + "content-version": StringMatching /v\\\\d\\+\\\\\\.\\\\d\\+/, + "user-agent": StringMatching /Ghost\\\\/\\\\d\\+\\\\\\.\\\\d\\+\\\\\\.\\\\d\\+\\\\s\\\\\\(https:\\\\/\\\\/github\\.com\\\\/TryGhost\\\\/Ghost\\\\\\)/, +} +`; + +exports[`Click Tracking Full test 2: [body] 1`] = ` +Object { + "member": Object { + "current": Object { + "avatar_image": null, + "comped": false, + "created_at": StringMatching /\\\\d\\{4\\}-\\\\d\\{2\\}-\\\\d\\{2\\}T\\\\d\\{2\\}:\\\\d\\{2\\}:\\\\d\\{2\\}\\\\\\.000Z/, + "email": "with-product@test.com", + "email_count": 0, + "email_open_rate": null, + "email_opened_count": 0, + "geolocation": null, + "id": StringMatching /\\[a-f0-9\\]\\{24\\}/, + "labels": Array [], + "last_seen_at": StringMatching /\\\\d\\{4\\}-\\\\d\\{2\\}-\\\\d\\{2\\}T\\\\d\\{2\\}:\\\\d\\{2\\}:\\\\d\\{2\\}\\\\\\.000Z/, + "name": "Dana Barrett", + "newsletters": Array [], + "note": null, + "status": "paid", + "subscribed": false, + "subscriptions": Array [], + "updated_at": StringMatching /\\\\d\\{4\\}-\\\\d\\{2\\}-\\\\d\\{2\\}T\\\\d\\{2\\}:\\\\d\\{2\\}:\\\\d\\{2\\}\\\\\\.000Z/, + "uuid": "f6f91461-d7d8-4a3f-aa5d-8e582c40b347", + }, + "previous": Object { + "last_seen_at": null, + "updated_at": StringMatching /\\\\d\\{4\\}-\\\\d\\{2\\}-\\\\d\\{2\\}T\\\\d\\{2\\}:\\\\d\\{2\\}:\\\\d\\{2\\}\\\\\\.000Z/, + }, + }, +} +`; diff --git a/ghost/core/test/e2e-server/click-tracking.test.js b/ghost/core/test/e2e-server/click-tracking.test.js index 030829ae32..01f1e1bcb8 100644 --- a/ghost/core/test/e2e-server/click-tracking.test.js +++ b/ghost/core/test/e2e-server/click-tracking.test.js @@ -1,22 +1,25 @@ const assert = require('assert/strict'); const fetch = require('node-fetch').default; -const {agentProvider, mockManager, fixtureManager} = require('../utils/e2e-framework'); +const {agentProvider, mockManager, fixtureManager, matchers} = require('../utils/e2e-framework'); const urlUtils = require('../../core/shared/url-utils'); const jobService = require('../../core/server/services/jobs/job-service'); +const {anyGhostAgent, anyContentVersion, anyNumber, anyISODateTime, anyObjectId} = matchers; describe('Click Tracking', function () { let agent; + let webhookMockReceiver; before(async function () { const {adminAgent} = await agentProvider.getAgentsWithFrontend(); agent = adminAgent; - await fixtureManager.init('newsletters', 'members:newsletters'); + await fixtureManager.init('newsletters', 'members:newsletters', 'integrations'); await agent.loginAsOwner(); }); beforeEach(function () { mockManager.mockMail(); mockManager.mockMailgun(); + webhookMockReceiver = mockManager.mockWebhookRequests(); }); afterEach(function () { @@ -51,6 +54,14 @@ describe('Click Tracking', function () { // Wait for the newsletter to be sent await jobService.allSettled(); + // Setup a webhook listener for member.edited events + const webhookURL = 'https://test-webhook-receiver.com/member-edited/'; + await webhookMockReceiver.mock(webhookURL); + await fixtureManager.insertWebhook({ + event: 'member.edited', + url: webhookURL + }); + const {body: {links}} = await agent.get( `/links/?filter=${encodeURIComponent(`post_id:'${post.id}'`)}` ); @@ -99,7 +110,7 @@ describe('Click Tracking', function () { const linkToClick = links[0]; const memberToClickLink = members[0]; - + assert(memberToClickLink.last_seen_at === null); const urlOfLinkToClick = new URL(linkToClick.link.from); urlOfLinkToClick.searchParams.set('m', memberToClickLink.uuid); @@ -124,5 +135,34 @@ describe('Click Tracking', function () { assert(clickEvent); assert(previousClickCount + 1 === clickCount); + + // Ensure we updated the member's last_seen_at + const {body: {members: [memberWhoClicked]}} = await agent.get( + `/members/${memberToClickLink.id}` + ); + assert(memberWhoClicked.last_seen_at !== null, 'last_seen_at should be set after a click'); + assert(new Date(memberWhoClicked.last_seen_at).getTime() > 0, 'last_seen_at should be a valid date'); + // Ensure we sent the webhook with the correct payload, including newsletters and labels + await webhookMockReceiver.receivedRequest(); + webhookMockReceiver + .matchHeaderSnapshot({ + 'content-version': anyContentVersion, + 'content-length': anyNumber, + 'user-agent': anyGhostAgent + }) + .matchBodySnapshot({ + member: { + current: { + created_at: anyISODateTime, + id: anyObjectId, + last_seen_at: anyISODateTime, + updated_at: anyISODateTime + }, + previous: { + last_seen_at: null, + updated_at: anyISODateTime + } + } + }); }); }); diff --git a/ghost/members-events-service/lib/LastSeenAtUpdater.js b/ghost/members-events-service/lib/LastSeenAtUpdater.js index 269dbd28d2..0b9a854c76 100644 --- a/ghost/members-events-service/lib/LastSeenAtUpdater.js +++ b/ghost/members-events-service/lib/LastSeenAtUpdater.js @@ -15,13 +15,15 @@ class LastSeenAtUpdater { * @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 + * @param {any} deps.events The event emitter */ constructor({ services: { settingsCache }, getMembersApi, - db + db, + events }) { if (!getMembersApi) { throw new IncorrectUsageError({message: 'Missing option getMembersApi'}); @@ -30,6 +32,7 @@ class LastSeenAtUpdater { this._getMembersApi = getMembersApi; this._settingsCacheService = settingsCache; this._db = db; + this._events = events; } /** * Subscribe to events of this domainEvents service @@ -104,17 +107,27 @@ class LastSeenAtUpdater { * - memberLastSeenAt is 2022-02-27 23:00:00, timestamp is current time, then `last_seen_at` is set to the current time * - memberLastSeenAt is 2022-02-28 01:00:00, timestamp is current time, then `last_seen_at` isn't changed * @param {string} memberId The id of the member to be udpated - * @param {string|null} memberLastSeenAt The previous last_seen_at property value for the current member * @param {Date} timestamp The event timestamp */ async updateLastSeenAt(memberId, memberLastSeenAt, timestamp) { const timezone = this._settingsCacheService.get('timezone'); + // First, check if memberLastSeenAt is null or before the beginning of the current day in the publication timezone + // This isn't strictly necessary since we will fetch the member row for update and double check this + // This is an optimization to avoid unnecessary database queries if last_seen_at is already after the beginning of the current day if (memberLastSeenAt === null || moment(moment.utc(timestamp).tz(timezone).startOf('day')).isAfter(memberLastSeenAt)) { const membersApi = this._getMembersApi(); - await membersApi.members.update({ - last_seen_at: moment.utc(timestamp).format('YYYY-MM-DD HH:mm:ss') - }, { - id: memberId + await this._db.knex.transaction(async (trx) => { + // To avoid a race condition, we lock the member row for update, then the last_seen_at field again to prevent simultaneous updates + const currentMember = await membersApi.members.get({id: memberId}, {require: true, transacting: trx, forUpdate: true}); + const currentMemberLastSeenAt = currentMember.get('last_seen_at'); + if (currentMemberLastSeenAt === null || moment(moment.utc(timestamp).tz(timezone).startOf('day')).isAfter(currentMemberLastSeenAt)) { + const memberToUpdate = await currentMember.refresh({transacting: trx, forUpdate: false, withRelated: ['labels', 'newsletters']}); + const updatedMember = await memberToUpdate.save({last_seen_at: moment.utc(timestamp).format('YYYY-MM-DD HH:mm:ss')}, {transacting: trx, patch: true, method: 'update'}); + // The standard event doesn't get emitted inside the transaction, so we do it manually + this._events.emit('member.edited', updatedMember); + return Promise.resolve(updatedMember); + } + return Promise.resolve(undefined); }); } } 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 49320ca667..f3628e3403 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 @@ -6,11 +6,19 @@ const assert = require('assert/strict'); const sinon = require('sinon'); const {LastSeenAtUpdater} = require('../'); const DomainEvents = require('@tryghost/domain-events'); -const {MemberPageViewEvent, MemberCommentEvent} = require('@tryghost/member-events'); +const {MemberPageViewEvent, MemberCommentEvent, MemberSubscribeEvent, MemberLinkClickEvent} = require('@tryghost/member-events'); const moment = require('moment'); const {EmailOpenedEvent} = require('@tryghost/email-events'); +const EventEmitter = require('events'); describe('LastSeenAtUpdater', function () { + let events; + + beforeEach(function () { + events = new EventEmitter(); + DomainEvents.ee.removeAllListeners(); + }); + it('Calls updateLastSeenAt on MemberPageViewEvents', async function () { const now = moment('2022-02-28T18:00:00Z').utc(); const previousLastSeen = moment('2022-02-27T23:00:00Z').toISOString(); @@ -28,7 +36,8 @@ describe('LastSeenAtUpdater', function () { update: stub } }; - } + }, + events }); updater.subscribe(DomainEvents); sinon.stub(updater, 'updateLastSeenAt'); @@ -36,6 +45,32 @@ describe('LastSeenAtUpdater', function () { assert(updater.updateLastSeenAt.calledOnceWithExactly('1', previousLastSeen, now.toDate())); }); + it('Calls updateLastSeenAt on MemberLinkClickEvents', 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 settingsCache = sinon.stub().returns('Etc/UTC'); + const updater = new LastSeenAtUpdater({ + services: { + settingsCache: { + get: settingsCache + } + }, + getMembersApi() { + return { + members: { + update: stub + } + }; + }, + events + }); + updater.subscribe(DomainEvents); + sinon.stub(updater, 'updateLastSeenAt'); + DomainEvents.dispatch(MemberLinkClickEvent.create({memberId: '1', memberLastSeenAt: previousLastSeen, url: '/'}, now.toDate())); + assert(updater.updateLastSeenAt.calledOnceWithExactly('1', previousLastSeen, now.toDate())); + }); + it('Calls updateLastSeenAt on email opened events', async function () { const now = moment('2022-02-28T18:00:00Z').utc(); const settingsCache = sinon.stub().returns('Etc/UTC'); @@ -60,7 +95,8 @@ describe('LastSeenAtUpdater', function () { getMembersApi() { return {}; }, - db + db, + events }); updater.subscribe(DomainEvents); sinon.spy(updater, 'updateLastSeenAt'); @@ -87,7 +123,8 @@ describe('LastSeenAtUpdater', function () { update: stub } }; - } + }, + events }); updater.subscribe(DomainEvents); sinon.stub(updater, 'updateLastCommentedAt'); @@ -98,7 +135,11 @@ describe('LastSeenAtUpdater', function () { it('works correctly on another timezone (not updating last_seen_at)', async function () { const now = moment('2022-02-28T04:00:00Z').utc(); const previousLastSeen = moment('2022-02-27T20:00:00Z').toISOString(); - const stub = sinon.stub().resolves(); + const transactionStub = sinon.stub().callsFake((callback) => { + return callback(); + }); + const saveStub = sinon.stub().resolves(); + const getStub = sinon.stub().resolves({get: () => previousLastSeen, save: saveStub}); const settingsCache = sinon.stub().returns('Asia/Bangkok'); const updater = new LastSeenAtUpdater({ services: { @@ -109,13 +150,19 @@ describe('LastSeenAtUpdater', function () { getMembersApi() { return { members: { - update: stub + get: getStub } }; - } + }, + db: { + knex: { + transaction: transactionStub + } + }, + events }); await updater.updateLastSeenAt('1', previousLastSeen, now.toDate()); - assert(stub.notCalled, 'The LastSeenAtUpdater should attempt a member update when the new timestamp is within the same day in the publication timezone.'); + assert(saveStub.notCalled, 'The LastSeenAtUpdater should attempt a member update when the new timestamp is within the same day in the publication timezone.'); }); it('works correctly on another timezone (not updating last_commented_at)', async function () { @@ -143,7 +190,8 @@ describe('LastSeenAtUpdater', function () { } } }; - } + }, + events }); await updater.updateLastCommentedAt('1', now.toDate()); assert(stub.notCalled, 'The LastSeenAtUpdater should attempt a member update when the new timestamp is within the same day in the publication timezone.'); @@ -152,7 +200,12 @@ describe('LastSeenAtUpdater', function () { it('works correctly on another timezone (updating last_seen_at)', async function () { const now = moment('2022-02-28T04:00:00Z').utc(); const previousLastSeen = moment('2022-02-27T20:00:00Z').toISOString(); - const stub = sinon.stub().resolves(); + const transactionStub = sinon.stub().callsFake((callback) => { + return callback(); + }); + const saveStub = sinon.stub().resolves(); + const refreshStub = sinon.stub().resolves({save: saveStub}); + const getStub = sinon.stub().resolves({get: () => previousLastSeen, refresh: refreshStub}); const settingsCache = sinon.stub().returns('Europe/Paris'); const updater = new LastSeenAtUpdater({ services: { @@ -163,23 +216,32 @@ describe('LastSeenAtUpdater', function () { getMembersApi() { return { members: { - update: stub + get: getStub } }; - } + }, + db: { + knex: { + transaction: transactionStub + } + }, + events }); await updater.updateLastSeenAt('1', previousLastSeen, now.toDate()); - assert(stub.calledOnceWithExactly({ - last_seen_at: now.format('YYYY-MM-DD HH:mm:ss') - }, { - id: '1' - }), 'The LastSeenAtUpdater should attempt a member update with the current date.'); + assert(saveStub.calledOnceWithExactly( + sinon.match({last_seen_at: now.tz('utc').format('YYYY-MM-DD HH:mm:ss')}), + sinon.match({transacting: sinon.match.any, patch: true, method: 'update'}) + ), 'The LastSeenAtUpdater should attempt a member update with the current date.'); }); it('Doesn\'t update when last_seen_at is too recent', async function () { const now = moment('2022-02-28T18:00:00Z'); const previousLastSeen = moment('2022-02-28T00:00:00Z').toISOString(); - const stub = sinon.stub().resolves(); + const saveStub = sinon.stub().resolves(); + const getStub = sinon.stub().resolves({get: () => previousLastSeen, save: saveStub}); + const transactionStub = sinon.stub().callsFake((callback) => { + return callback(); + }); const settingsCache = sinon.stub().returns('Etc/UTC'); const updater = new LastSeenAtUpdater({ services: { @@ -190,13 +252,19 @@ describe('LastSeenAtUpdater', function () { getMembersApi() { return { members: { - update: stub + get: getStub } }; - } + }, + db: { + knex: { + transaction: transactionStub + } + }, + events }); await updater.updateLastSeenAt('1', previousLastSeen, now.toDate()); - assert(stub.notCalled, 'The LastSeenAtUpdater should\'t update a member when the previous last_seen_at is close to the event timestamp.'); + assert(saveStub.notCalled, 'The LastSeenAtUpdater should\'t update a member when the previous last_seen_at is close to the event timestamp.'); }); it('Doesn\'t update when last_commented_at is too recent', async function () { @@ -224,7 +292,8 @@ describe('LastSeenAtUpdater', function () { } } }; - } + }, + events }); await updater.updateLastCommentedAt('1', now.toDate()); assert(stub.notCalled, 'The LastSeenAtUpdater should\'t update a member'); @@ -255,7 +324,8 @@ describe('LastSeenAtUpdater', function () { } } }; - } + }, + events }); await updater.updateLastCommentedAt('1', now.toDate()); assert(stub.notCalled, 'The LastSeenAtUpdater should\'t update a member.'); @@ -286,7 +356,8 @@ describe('LastSeenAtUpdater', function () { } } }; - } + }, + events }); await updater.updateLastCommentedAt('1', now.toDate()); assert(stub.calledOnce, 'The LastSeenAtUpdater should attempt a member update'); @@ -324,7 +395,8 @@ describe('LastSeenAtUpdater', function () { } } }; - } + }, + events }); await updater.updateLastCommentedAt('1', now.toDate()); assert(stub.calledOnce, 'The LastSeenAtUpdater should attempt a member update'); @@ -338,25 +410,26 @@ describe('LastSeenAtUpdater', function () { }); it('Doesn\'t fire on other events', async function () { - const now = moment('2022-02-28T18:00:00Z'); - const stub = sinon.stub().resolves(); - const settingsCache = sinon.stub().returns('Etc/UTC'); + const spy = sinon.spy(); const updater = new LastSeenAtUpdater({ services: { settingsCache: { - get: settingsCache + get: () => 'Etc/UTC' } }, getMembersApi() { return { members: { - update: stub + update: spy } }; - } + }, + events }); - await updater.updateLastSeenAt('1', undefined, now.toDate()); - assert(stub.notCalled, 'The LastSeenAtUpdater should never fire on MemberPageViewEvent events.'); + updater.subscribe(DomainEvents); + DomainEvents.dispatch(MemberSubscribeEvent.create({memberId: '1', source: 'api'}, new Date())); + await DomainEvents.allSettled(); + assert(spy.notCalled, 'The LastSeenAtUpdater should never fire on MemberSubscribeEvent events.'); }); it('throws if getMembersApi is not passed to LastSeenAtUpdater', async function () { @@ -372,4 +445,55 @@ describe('LastSeenAtUpdater', function () { }); }, 'Missing option getMembersApi'); }); + + it('avoids a race condition when updating last_seen_at', async function () { + const now = moment.utc('2022-02-28T18:00:00Z'); + const saveStub = sinon.stub().resolves(); + const refreshStub = sinon.stub().resolves({save: saveStub}); + const settingsCache = sinon.stub().returns('Europe/Brussels'); + const transactionStub = sinon.stub().callsFake((callback) => { + return callback(); + }); + const getStub = sinon.stub(); + getStub.onFirstCall().resolves({get: () => null, save: saveStub, refresh: refreshStub}); + getStub.onSecondCall().resolves({get: () => now.toDate(), save: saveStub, refresh: refreshStub}); + getStub.resolves({get: () => now.toDate(), save: saveStub, refresh: refreshStub}); + const updater = new LastSeenAtUpdater({ + services: { + settingsCache: { + get: settingsCache + } + }, + getMembersApi() { + return { + members: { + get: getStub + } + }; + }, + db: { + knex: { + transaction: transactionStub + } + }, + events + }); + sinon.stub(events, 'emit'); + await Promise.all([ + updater.updateLastSeenAt('1', null, now.toDate()), + updater.updateLastSeenAt('1', null, now.toDate()), + updater.updateLastSeenAt('1', null, now.toDate()), + updater.updateLastSeenAt('1', null, now.toDate()) + ]); + assert(saveStub.calledOnce, `The LastSeenAtUpdater should attempt a member update only once, but was called ${saveStub.callCount} times`); + assert(saveStub.calledOnceWithExactly( + sinon.match({last_seen_at: now.tz('utc').format('YYYY-MM-DD HH:mm:ss')}), + sinon.match({transacting: undefined, patch: true, method: 'update'}) + ), 'The LastSeenAtUpdater should attempt a member update with the current date.'); + + assert(events.emit.calledOnceWithExactly( + 'member.edited', + sinon.match.any + ), 'The LastSeenAtUpdater should emit a member.edited event if it updated last_seen_at'); + }); });