Added structured logs for Ghost welcome emails enabled/disabled (#26339)

ref
https://linear.app/ghost/issue/NY-1019/add-structured-logs-for-when-a-welcome-email-is-enableddisabled

This adds two logging events when publishers enable or disable welcome
emails:
- welcome_email.enabled - a useful signal for feature adoption
- welcome_email.disabled - a useful signal for feature
(dis)-satisfaction

This is also an initial experiment in structured logging in Ghost, which
we can hopefully build on and convert most/all of Ghost's logs to a
similar format over time to make them easier to search through.

The reason for the "system" top level key is that this top level object
is already ingested in Elastic search. We may want to adjust this at
some point to something that makes more sense in the context of Ghost,
but for now this should do the trick.

Author: cmraible

ghost/core/core/server/models/automated-email.js

@@ -1,6 +1,10 @@
 const ghostBookshelf = require('./base');
+const logging = require('@tryghost/logging');
 const urlUtils = require('../../shared/url-utils');
 const lexicalLib = require('../lib/lexical');
+const {MEMBER_WELCOME_EMAIL_SLUGS} = require('../services/member-welcome-emails/constants');
+
+const MEMBER_WELCOME_EMAIL_SLUG_SET = new Set(Object.values(MEMBER_WELCOME_EMAIL_SLUGS));
 
 const AutomatedEmail = ghostBookshelf.Model.extend({
     tableName: 'automated_emails',
@@ -33,6 +37,36 @@ const AutomatedEmail = ghostBookshelf.Model.extend({
         }
 
         return attrs;
+    },
+
+    onSaved(model) {
+        if (!model?.id) {
+            return;
+        }
+
+        const slug = model.get('slug');
+
+        if (!MEMBER_WELCOME_EMAIL_SLUG_SET.has(slug)) {
+            return;
+        }
+
+        const previousStatus = model.previous('status');
+        const currentStatus = model.get('status');
+        const isNewModel = previousStatus === undefined;
+        const isEnableTransition = currentStatus === 'active' && (isNewModel || previousStatus === 'inactive');
+        const isDisableTransition = previousStatus === 'active' && currentStatus === 'inactive';
+
+        if (!isEnableTransition && !isDisableTransition) {
+            return;
+        }
+
+        logging.info({
+            system: {
+                event: isEnableTransition ? 'welcome_email.enabled' : 'welcome_email.disabled',
+                automated_email_id: model.id,
+                slug
+            }
+        }, isEnableTransition ? 'Welcome email enabled' : 'Welcome email disabled');
     }
 });
 

ghost/core/test/e2e-api/admin/automated-emails.test.js

@@ -1,6 +1,7 @@
 const {agentProvider, fixtureManager, matchers, dbUtils} = require('../../utils/e2e-framework');
 const {anyContentVersion, anyObjectId, anyISODateTime, anyErrorId, anyEtag, anyLocationFor} = matchers;
 const sinon = require('sinon');
+const logging = require('@tryghost/logging');
 const mailService = require('../../../core/server/services/mail');
 
 const matchAutomatedEmail = {
@@ -169,6 +170,61 @@ describe('Automated Emails API', function () {
                     etag: anyEtag
                 });
         });
+
+        describe('Structured logging', function () {
+            let infoStub;
+
+            beforeEach(function () {
+                infoStub = sinon.stub(logging, 'info');
+            });
+
+            afterEach(function () {
+                sinon.restore();
+            });
+
+            it('Logs when a welcome email is created as active', async function () {
+                const {body} = await agent
+                    .post('automated_emails')
+                    .body({automated_emails: [{
+                        name: 'Welcome Email (Free)',
+                        slug: 'member-welcome-email-free',
+                        status: 'active',
+                        subject: 'Welcome to the site!',
+                        lexical: JSON.stringify({root: {children: []}})
+                    }]})
+                    .expectStatus(201);
+
+                const automatedEmail = body.automated_emails[0];
+
+                sinon.assert.calledWithMatch(infoStub, {
+                    system: {
+                        event: 'welcome_email.enabled',
+                        automated_email_id: automatedEmail.id,
+                        slug: 'member-welcome-email-free'
+                    }
+                }, 'Welcome email enabled');
+            });
+
+            it('Does not log when a welcome email is created as inactive', async function () {
+                await agent
+                    .post('automated_emails')
+                    .body({automated_emails: [{
+                        name: 'Welcome Email (Free)',
+                        slug: 'member-welcome-email-free',
+                        status: 'inactive',
+                        subject: 'Welcome to the site!',
+                        lexical: JSON.stringify({root: {children: []}})
+                    }]})
+                    .expectStatus(201);
+
+                sinon.assert.neverCalledWithMatch(infoStub, {
+                    system: {
+                        event: 'welcome_email.enabled',
+                        slug: 'member-welcome-email-free'
+                    }
+                }, sinon.match.any);
+            });
+        });
     });
 
     describe('Edit', function () {
@@ -283,6 +339,76 @@ describe('Automated Emails API', function () {
                     etag: anyEtag
                 });
         });
+
+        describe('Structured logging', function () {
+            let infoStub;
+
+            beforeEach(function () {
+                infoStub = sinon.stub(logging, 'info');
+            });
+
+            afterEach(function () {
+                sinon.restore();
+            });
+
+            it('Logs when a welcome email is enabled', async function () {
+                const automatedEmail = await createAutomatedEmail({status: 'inactive'});
+
+                await agent
+                    .put(`automated_emails/${automatedEmail.id}`)
+                    .body({automated_emails: [{
+                        name: 'Welcome Email (Free)',
+                        status: 'active'
+                    }]})
+                    .expectStatus(200);
+
+                sinon.assert.calledWithMatch(infoStub, {
+                    system: {
+                        event: 'welcome_email.enabled',
+                        automated_email_id: automatedEmail.id,
+                        slug: 'member-welcome-email-free'
+                    }
+                }, 'Welcome email enabled');
+            });
+
+            it('Logs when a welcome email is disabled', async function () {
+                const automatedEmail = await createAutomatedEmail({status: 'active'});
+
+                await agent
+                    .put(`automated_emails/${automatedEmail.id}`)
+                    .body({automated_emails: [{
+                        name: 'Welcome Email (Free)',
+                        status: 'inactive'
+                    }]})
+                    .expectStatus(200);
+
+                sinon.assert.calledWithMatch(infoStub, {
+                    system: {
+                        event: 'welcome_email.disabled',
+                        automated_email_id: automatedEmail.id,
+                        slug: 'member-welcome-email-free'
+                    }
+                }, 'Welcome email disabled');
+            });
+
+            it('Does not log when status does not change', async function () {
+                const automatedEmail = await createAutomatedEmail({status: 'inactive'});
+
+                await agent
+                    .put(`automated_emails/${automatedEmail.id}`)
+                    .body({automated_emails: [{
+                        name: 'Welcome Email (Free)',
+                        subject: 'Updated subject only'
+                    }]})
+                    .expectStatus(200);
+
+                sinon.assert.neverCalledWithMatch(infoStub, {
+                    system: {
+                        event: sinon.match(/^welcome_email\.(enabled|disabled)$/)
+                    }
+                }, sinon.match.any);
+            });
+        });
     });
 
     describe('Destroy', function () {