From 5800418902236e15bbe7652b7751fbef2a5ff2b9 Mon Sep 17 00:00:00 2001 From: Phil Booth Date: Mon, 28 Aug 2017 10:53:25 +0100 Subject: [PATCH] feat(logging): send amplitude events to the logs https://github.com/mozilla/fxa-auth-server/pull/2069 r=rfk,vbudhram --- docs/api.md | 1 + lib/email/utils/helpers.js | 28 + lib/log.js | 9 + lib/metrics/amplitude.js | 209 +++++++ lib/metrics/context.js | 21 +- lib/metrics/events.js | 20 +- lib/routes/account.js | 20 +- lib/routes/emails.js | 33 +- lib/routes/password.js | 12 +- lib/senders/email.js | 66 +- scripts/write-api-docs.js | 8 +- test/local/email/utils.js | 78 ++- test/local/log.js | 61 ++ test/local/metrics/amplitude.js | 1007 +++++++++++++++++++++++++++++++ test/local/metrics/context.js | 44 +- test/local/metrics/events.js | 121 ++-- test/local/routes/account.js | 40 +- test/local/routes/emails.js | 32 +- test/local/routes/password.js | 6 + test/local/senders/email.js | 30 +- test/mocks.js | 7 +- 21 files changed, 1707 insertions(+), 146 deletions(-) create mode 100644 lib/metrics/amplitude.js create mode 100644 test/local/metrics/amplitude.js diff --git a/docs/api.md b/docs/api.md index 688c093c..bdf9173e 100644 --- a/docs/api.md +++ b/docs/api.md @@ -320,6 +320,7 @@ those common validations are defined here. #### lib/metrics/context * `SCHEMA`: object({ + * `deviceId`: string, length(32), regex(HEX_STRING), optional * `flowId`: string, length(64), regex(HEX_STRING), optional * `flowBeginTime`: number, integer, positive, optional diff --git a/lib/email/utils/helpers.js b/lib/email/utils/helpers.js index 8939f36c..82dac0bc 100644 --- a/lib/email/utils/helpers.js +++ b/lib/email/utils/helpers.js @@ -3,6 +3,7 @@ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ const emailDomains = require('../../../config/popular-email-domains') +let amplitude function getInsensitiveHeaderValueFromArray(headerName, headers) { var value = '' @@ -61,6 +62,31 @@ function logEmailEventSent(log, message) { msg.domain = getAnonymizedEmailDomain(addr) log.info(msg) }) + + logAmplitudeEvent(log, message, emailEventInfo) +} + +function logAmplitudeEvent (log, message, eventInfo) { + if (! amplitude) { + amplitude = require('../../metrics/amplitude')(log) + } + + amplitude(`email.${eventInfo.template}.${eventInfo.type}`, { + app: { + locale: eventInfo.locale, + ua: {} + }, + auth: {}, + query: {}, + payload: {} + }, { + device_id: getHeaderValue('X-Device-Id', message), + service: getHeaderValue('X-Service-Id', message), + uid: getHeaderValue('X-Uid', message) + }, { + flow_id: eventInfo.flow_id, + time: Date.now() + }) } function logEmailEventFromMessage(log, message, type, emailDomain) { @@ -89,6 +115,8 @@ function logEmailEventFromMessage(log, message, type, emailDomain) { } log.info(emailEventInfo) + + logAmplitudeEvent(log, message, emailEventInfo) } function logFlowEventFromMessage(log, message, type) { diff --git a/lib/log.js b/lib/log.js index ed6bffd4..8f371efd 100644 --- a/lib/log.js +++ b/lib/log.js @@ -158,6 +158,15 @@ Lug.prototype.flowEvent = function (data) { this.logger.info('flowEvent', data) } +Lug.prototype.amplitudeEvent = function (data) { + if (! data || ! data.event_type) { + this.error({ op: 'log.amplitudeEvent', data }) + return + } + + this.logger.info('amplitudeEvent', data) +} + module.exports = function (level, name, options) { if (arguments.length === 1 && typeof level === 'object') { options = level diff --git a/lib/metrics/amplitude.js b/lib/metrics/amplitude.js new file mode 100644 index 00000000..796ce224 --- /dev/null +++ b/lib/metrics/amplitude.js @@ -0,0 +1,209 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +// This module contains mappings from activity/flow event names to +// amplitude event definitions. The intention is for the returned +// `receiveEvent` function to be invoked for every event and the +// mappings determine which of those will be transformed into an +// amplitude event. You can read more about the amplitude event +// structure here: +// +// https://amplitude.zendesk.com/hc/en-us/articles/204771828-HTTP-API + +'use strict' + +const APP_VERSION = /^[0-9]+\.([0-9]+)\./.exec(require('../../package.json').version)[1] + +const GROUPS = { + activity: 'fxa_activity', + email: 'fxa_email', + login: 'fxa_login', + registration: 'fxa_reg', + sms: 'fxa_sms' +} + +const EVENTS = { + 'account.confirmed': { + group: GROUPS.login, + event: 'email_confirmed' + }, + 'account.created': { + group: GROUPS.registration, + event: 'created' + }, + 'account.login': { + group: GROUPS.login, + event: 'success' + }, + 'account.login.blocked': { + group: GROUPS.login, + event: 'blocked' + }, + 'account.login.confirmedUnblockCode': { + group: GROUPS.login, + event: 'unblock_success' + }, + 'account.reset': { + group: GROUPS.login, + event: 'forgot_complete' + }, + 'account.signed': { + group: GROUPS.activity, + event: 'cert_signed' + }, + 'account.verified': { + group: GROUPS.registration, + event: 'email_confirmed' + }, + 'flow.complete': { + isDynamicGroup: true, + group: (request, data, metricsContext) => GROUPS[metricsContext.flowType], + event: 'complete' + }, + 'password.forgot.resend_code.completed': { + group: GROUPS.login, + event: 'forgot_sent' + }, + 'password.forgot.send_code.completed': { + group: GROUPS.login, + event: 'forgot_sent' + }, + 'sms.installFirefox.sent': { + group: GROUPS.sms, + event: 'sent' + } +} + +const EMAIL_EVENTS = /^email\.(\w+)\.(bounced|sent)$/ + +const EMAIL_TYPES = { + newDeviceLoginEmail: 'login', + passwordChangedEmail: 'change_password', + passwordResetEmail: 'reset_password', + passwordResetRequiredEmail: 'reset_password', + postRemoveSecondaryEmail: 'secondary_email', + postVerifyEmail: 'registration', + postVerifySecondaryEmail: 'secondary_email', + recoveryEmail: 'reset_password', + unblockCode: 'unblock', + verificationReminderFirstEmail: 'registration', + verificationReminderSecondEmail: 'registration', + verificationReminderEmail: 'registration', + verifyEmail: 'registration', + verifyLoginEmail: 'login', + verifySyncEmail: 'registration', + verifySecondaryEmail: 'secondary_email' +} + +const NOP = () => {} + +const EVENT_PROPERTIES = { + [GROUPS.activity]: NOP, + [GROUPS.email]: mapEmailType, + [GROUPS.login]: NOP, + [GROUPS.registration]: NOP, + [GROUPS.sms]: NOP +} + +const USER_PROPERTIES = { + [GROUPS.activity]: mapUid, + [GROUPS.email]: mapUid, + [GROUPS.login]: mapUid, + [GROUPS.registration]: mapUid, + [GROUPS.sms]: NOP +} + +module.exports = log => { + if (log) { + return receiveEvent + } + + function receiveEvent (event, request, data = {}, metricsContext = {}) { + if (! event || ! request) { + log.error({ op: 'amplitudeMetrics', err: 'Bad argument', event, hasRequest: !! request }) + return + } + + let mapping = EVENTS[event] + + if (! mapping) { + const matches = EMAIL_EVENTS.exec(event) + if (matches) { + const eventCategory = matches[1] + if (EMAIL_TYPES[eventCategory]) { + mapping = { + group: GROUPS.email, + event: matches[2], + eventCategory: matches[1] + } + } + } + } + + if (mapping) { + let group = mapping.group + if (mapping.isDynamicGroup) { + group = group(request, data, metricsContext) + if (! group) { + return + } + } + if (mapping.eventCategory) { + data.eventCategory = mapping.eventCategory + } + log.amplitudeEvent({ + time: metricsContext.time || Date.now(), + event_type: `${group} - ${mapping.event}`, + session_id: getFromMetricsContext(metricsContext, 'flowBeginTime', request, 'flowBeginTime'), + event_properties: mapEventProperties(group, request, data, metricsContext), + user_properties: mapUserProperties(group, request, data, metricsContext), + app_version: APP_VERSION, + language: request.app.locale || undefined + }) + } + } +} + +function getFromMetricsContext (metricsContext, key, request, payloadKey) { + return metricsContext[key] || + (request.payload.metricsContext && request.payload.metricsContext[payloadKey]) +} + +function mapEventProperties (group, request, data, metricsContext) { + return Object.assign({ + device_id: getFromMetricsContext(metricsContext, 'device_id', request, 'deviceId'), + service: data.service || request.query.service || request.payload.service + }, EVENT_PROPERTIES[group](request, data, metricsContext)) +} + +function mapEmailType (request, data) { + const emailType = EMAIL_TYPES[data.eventCategory] + if (emailType) { + return { + email_type: emailType + } + } +} + +function mapUserProperties (group, request, data, metricsContext) { + const { browser, browserVersion, os } = request.app.ua + return Object.assign({ + flow_id: getFromMetricsContext(metricsContext, 'flow_id', request, 'flowId'), + ua_browser: browser, + ua_version: browserVersion, + ua_os: os + }, USER_PROPERTIES[group](request, data, metricsContext)) +} + +function mapUid (request, data) { + return { + fxa_uid: data.uid || getFromToken(request, 'uid') + } +} + +function getFromToken (request, key) { + if (request.auth.credentials) { + return request.auth.credentials[key] + } +} diff --git a/lib/metrics/context.js b/lib/metrics/context.js index d81a0c20..d9df5b0c 100644 --- a/lib/metrics/context.js +++ b/lib/metrics/context.js @@ -13,6 +13,11 @@ const P = require('../promise') const FLOW_ID_LENGTH = 64 const SCHEMA = isA.object({ + // The metrics context device id is a client-generated property + // that is entirely separate to the devices table in our db. + // All clients can generate a metrics context device id, whereas + // only Sync creates records in the devices table. + deviceId: isA.string().length(32).regex(HEX_STRING).optional(), flowId: isA.string().length(64).regex(HEX_STRING).optional(), flowBeginTime: isA.number().integer().positive().optional() }) @@ -23,11 +28,11 @@ module.exports = function (log, config) { const cache = require('../cache')(log, config, 'fxa-metrics~') return { - stash: stash, - gather: gather, - clear: clear, - validate: validate, - setFlowCompleteSignal: setFlowCompleteSignal + stash, + gather, + clear, + validate, + setFlowCompleteSignal } /** @@ -85,9 +90,12 @@ module.exports = function (log, config) { .then(metadata => { if (metadata) { data.time = Date.now() + data.device_id = metadata.deviceId data.flow_id = metadata.flowId data.flow_time = calculateFlowTime(data.time, metadata.flowBeginTime) + data.flowBeginTime = metadata.flowBeginTime data.flowCompleteSignal = metadata.flowCompleteSignal + data.flowType = metadata.flowType } }) .catch(err => log.error({ @@ -218,9 +226,10 @@ module.exports = function (log, config) { * @this request * @param {String} flowCompleteSignal */ - function setFlowCompleteSignal (flowCompleteSignal) { + function setFlowCompleteSignal (flowCompleteSignal, flowType) { if (this.payload && this.payload.metricsContext) { this.payload.metricsContext.flowCompleteSignal = flowCompleteSignal + this.payload.metricsContext.flowType = flowType } } } diff --git a/lib/metrics/events.js b/lib/metrics/events.js index d5b25d4f..f26a28c7 100644 --- a/lib/metrics/events.js +++ b/lib/metrics/events.js @@ -64,6 +64,8 @@ const FLOW_EVENT_ROUTES = new Set([ const PATH_PREFIX = /^\/v1/ module.exports = log => { + const amplitude = require('./amplitude')(log) + return { /** * Asynchronously emit a flow event and/or an activity event. @@ -98,7 +100,15 @@ module.exports = log => { } return emitFlowEvent(event, request, data) - .then(() => {}) + }) + .then(metricsContext => { + amplitude(event, request, data, metricsContext) + + if (metricsContext && event === metricsContext.flowCompleteSignal) { + log.flowEvent(Object.assign({}, metricsContext, { event: 'flow.complete' })) + amplitude('flow.complete', request, data, metricsContext) + request.clearMetricsContext() + } }) }, @@ -170,14 +180,6 @@ module.exports = log => { } log.flowEvent(data) - - if (event === data.flowCompleteSignal) { - log.flowEvent(Object.assign({}, data, { - event: 'flow.complete' - })) - - request.clearMetricsContext() - } } else if (! OPTIONAL_FLOW_EVENTS[event]) { log.error({ op: 'metricsEvents.emitFlowEvent', event, missingFlowId: true }) } diff --git a/lib/routes/account.js b/lib/routes/account.js index d6ee2b47..93c108c2 100644 --- a/lib/routes/account.js +++ b/lib/routes/account.js @@ -130,7 +130,7 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus } else { flowCompleteSignal = 'account.verified' } - request.setMetricsFlowCompleteSignal(flowCompleteSignal) + request.setMetricsFlowCompleteSignal(flowCompleteSignal, 'registration') return P.resolve() } @@ -283,7 +283,8 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, - uaDeviceType: sessionToken.uaDeviceType + uaDeviceType: sessionToken.uaDeviceType, + uid: sessionToken.uid }) .then(function () { // only create reminder if sendVerifyCode succeeds @@ -673,7 +674,7 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus } else { flowCompleteSignal = 'account.login' } - request.setMetricsFlowCompleteSignal(flowCompleteSignal) + request.setMetricsFlowCompleteSignal(flowCompleteSignal, 'login') return checkPassword(accountRecord, authPW, request.app.clientAddress) .then( @@ -886,7 +887,8 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, - uaDeviceType: sessionToken.uaDeviceType + uaDeviceType: sessionToken.uaDeviceType, + uid: sessionToken.uid }) } ) @@ -918,12 +920,14 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus flowBeginTime: flowBeginTime, ip: ip, location: geoData.location, + service, timeZone: geoData.timeZone, uaBrowser: sessionToken.uaBrowser, uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, - uaDeviceType: sessionToken.uaDeviceType + uaDeviceType: sessionToken.uaDeviceType, + uid: sessionToken.uid } ) .catch(e => { @@ -966,7 +970,8 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, - uaDeviceType: sessionToken.uaDeviceType + uaDeviceType: sessionToken.uaDeviceType, + uid: sessionToken.uid } ) }) @@ -1282,7 +1287,8 @@ module.exports = (log, db, mailer, Password, config, customs, checkPassword, pus uaBrowserVersion, uaOS, uaOSVersion, - uaDeviceType + uaDeviceType, + uid: emailRecord.uid }) }) } diff --git a/lib/routes/emails.js b/lib/routes/emails.js index b0cef64d..646bc3c2 100644 --- a/lib/routes/emails.js +++ b/lib/routes/emails.js @@ -175,6 +175,8 @@ module.exports = (log, db, mailer, config, customs, push) => { let verifyFunction let event let emails = [] + let flowId + let flowBeginTime // Return immediately if this session or token is already verified. Only exception // is if the email param has been specified, which means that this is @@ -183,13 +185,21 @@ module.exports = (log, db, mailer, config, customs, push) => { return reply({}) } + if (request.payload.metricsContext) { + flowId = request.payload.metricsContext.flowId + flowBeginTime = request.payload.metricsContext.flowBeginTime + } + customs.check(request, sessionToken.email, 'recoveryEmailResendCode') .then(setVerifyCode) .then(setVerifyFunction) .then(() => { const mailerOpts = { - code: code, - service: service, + code, + deviceId: sessionToken.deviceId, + flowId, + flowBeginTime, + service, timestamp: Date.now(), redirectTo: request.payload.redirectTo, resume: request.payload.resume, @@ -198,7 +208,8 @@ module.exports = (log, db, mailer, config, customs, push) => { uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, - uaDeviceType: sessionToken.uaDeviceType + uaDeviceType: sessionToken.uaDeviceType, + uid: sessionToken.uid } return verifyFunction(emails, sessionToken, mailerOpts) @@ -351,7 +362,9 @@ module.exports = (log, db, mailer, config, customs, push) => { return mailer.sendPostVerifySecondaryEmail([], account, { acceptLanguage: request.app.acceptLanguage, - secondaryEmail: matchedEmail.email + secondaryEmail: matchedEmail.email, + service, + uid }) }) }) @@ -473,7 +486,9 @@ module.exports = (log, db, mailer, config, customs, push) => { // so only send it if we're sure this is for sync. if (service === 'sync') { return mailer.sendPostVerifyEmail([], account, { - acceptLanguage: request.app.acceptLanguage + acceptLanguage: request.app.acceptLanguage, + service, + uid }) } }) @@ -633,6 +648,7 @@ module.exports = (log, db, mailer, config, customs, push) => { .then((geoData) => { return mailer.sendVerifySecondaryEmail([emailData], sessionToken, { code: emailData.emailCode, + deviceId: sessionToken.deviceId, acceptLanguage: request.app.acceptLanguage, email: emailData.email, primaryEmail: primaryEmail, @@ -643,6 +659,7 @@ module.exports = (log, db, mailer, config, customs, push) => { uaBrowserVersion: sessionToken.uaBrowserVersion, uaOS: sessionToken.uaOS, uaOSVersion: sessionToken.uaOSVersion, + uid }) }) } @@ -695,7 +712,11 @@ module.exports = (log, db, mailer, config, customs, push) => { return item } }) - return mailer.sendPostRemoveSecondaryEmail(emails, account, {secondaryEmail: email}) + return mailer.sendPostRemoveSecondaryEmail(emails, account, { + deviceId: sessionToken.deviceId, + secondaryEmail: email, + uid + }) }) .then( () => reply({}), diff --git a/lib/routes/password.js b/lib/routes/password.js index 85d1d78c..08217517 100644 --- a/lib/routes/password.js +++ b/lib/routes/password.js @@ -282,7 +282,8 @@ module.exports = function ( uaBrowserVersion, uaOS, uaOSVersion, - uaDeviceType + uaDeviceType, + uid: passwordChangeToken.uid }) .catch(e => { // If we couldn't email them, no big deal. Log @@ -466,7 +467,8 @@ module.exports = function ( uaBrowserVersion, uaOS, uaOSVersion, - uaDeviceType + uaDeviceType, + uid: passwordForgotToken.uid }) }) .then( @@ -571,7 +573,8 @@ module.exports = function ( uaBrowserVersion, uaOS, uaOSVersion, - uaDeviceType + uaDeviceType, + uid: passwordForgotToken.uid }) }) } @@ -649,7 +652,8 @@ module.exports = function ( code: code, acceptLanguage: request.app.acceptLanguage, flowId: flowId, - flowBeginTime: flowBeginTime + flowBeginTime: flowBeginTime, + uid: passwordForgotToken.uid } ) }) diff --git a/lib/senders/email.js b/lib/senders/email.js index cf23f64c..84f4a017 100644 --- a/lib/senders/email.js +++ b/lib/senders/email.js @@ -226,10 +226,18 @@ module.exports = function (log) { var localized = this.localize(message) - if (message.flowBeginTime && message.flowId) { - message.headers['X-Flow-Id'] = message.flowId - message.headers['X-Flow-Begin-Time'] = message.flowBeginTime - } + const headers = Object.assign( + { + 'Content-Language': localized.language, + 'X-Template-Name': message.template + }, + message.headers, + optionalHeader('X-Device-Id', message.deviceId), + optionalHeader('X-Flow-Id', message.flowId), + optionalHeader('X-Flow-Begin-Time', message.flowBeginTime), + optionalHeader('X-Service-Id', message.service), + optionalHeader('X-Uid', message.uid) + ) var emailConfig = { sender: this.sender, @@ -239,10 +247,7 @@ module.exports = function (log) { text: localized.text, html: localized.html, xMailer: false, - headers: extend({ - 'Content-Language': localized.language, - 'X-Template-Name': message.template - }, message.headers) + headers } // Utilize nodemailer's cc ability to send to multiple addresses @@ -313,8 +318,6 @@ module.exports = function (log) { var headers = { 'X-Link': links.link, - 'X-Service-ID': message.service, - 'X-Uid': message.uid, 'X-Verify-Code': message.code } @@ -329,10 +332,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: subject, template: templateName, templateValues: { @@ -364,7 +369,6 @@ module.exports = function (log) { var links = this._generateLinks(null, message.email, query, templateName) var headers = { - 'X-Uid': message.uid, 'X-Unblock-Code': message.unblockCode, 'X-Report-SignIn-Link': links.reportSignInLink } @@ -376,10 +380,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Firefox Account authorization code'), template: templateName, templateValues: { @@ -414,8 +420,6 @@ module.exports = function (log) { var headers = { 'X-Link': links.link, - 'X-Service-ID': message.service, - 'X-Uid': message.uid, 'X-Verify-Code': message.code } @@ -426,10 +430,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Confirm new sign-in to Firefox'), template: templateName, templateValues: { @@ -469,8 +475,6 @@ module.exports = function (log) { var headers = { 'X-Link': links.link, - 'X-Service-ID': message.service, - 'X-Uid': message.uid, 'X-Verify-Code': message.code } @@ -480,10 +484,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Verify email for Firefox Accounts'), template: templateName, templateValues: { @@ -533,10 +539,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Reset your Firefox Account password'), template: templateName, templateValues: { @@ -571,10 +579,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Your Firefox Account password has been changed'), template: templateName, templateValues: { @@ -607,10 +617,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Your Firefox Account password has been reset'), template: templateName, templateValues: { @@ -638,10 +650,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Firefox Account password reset required'), template: templateName, templateValues: { @@ -669,10 +683,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, ccEmails: message.ccEmails, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('New sign-in to Firefox'), template: templateName, templateValues: { @@ -706,10 +722,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Firefox Account verified'), template: templateName, templateValues: { @@ -742,10 +760,12 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, + deviceId: message.deviceId, email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Secondary Firefox Account email added'), template: templateName, templateValues: { @@ -777,11 +797,13 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage, - email: message.email, ccEmails: message.ccEmails, + deviceId: message.deviceId, + email: message.email, flowId: message.flowId, flowBeginTime: message.flowBeginTime, headers: headers, + service: message.service, subject: gettext('Secondary Firefox Account email removed'), template: templateName, templateValues: { @@ -825,7 +847,6 @@ module.exports = function (log) { var headers = { 'X-Link': links.link, - 'X-Uid': message.uid, 'X-Verify-Code': message.code } @@ -835,9 +856,13 @@ module.exports = function (log) { return this.send({ acceptLanguage: message.acceptLanguage || 'en', + deviceId: message.deviceId, email: message.email, + flowId: message.flowId, + flowBeginTime: message.flowBeginTime, headers: headers, subject: subject, + service: message.service, template: templateName, templateValues: { email: message.email, @@ -948,3 +973,10 @@ module.exports = function (log) { return Mailer } + +function optionalHeader (key, value) { + if (value) { + return { [key]: value } + } +} + diff --git a/scripts/write-api-docs.js b/scripts/write-api-docs.js index 18e25877..bc90db85 100755 --- a/scripts/write-api-docs.js +++ b/scripts/write-api-docs.js @@ -789,10 +789,10 @@ function parseMetricsContext () { .then(metricsContext => metricsContext.map(item => { item.value = marshallValidation( item.value - .replace(/{ /g, '{\n * `') - .replace(/ }/g, '\n\n }') - .replace(/, /, '\n * `') - .replace(/:/g, '`:') + .replace('{ ', '{\n * ') + .replace(/ }/, '\n\n }') + .replace(/, ([a-zA-Z]+):/g, '\n * $1:') + .replace(/([a-zA-Z]+):/g, '`$1`:') ) return item })) diff --git a/test/local/email/utils.js b/test/local/email/utils.js index 51607d3b..3951e943 100644 --- a/test/local/email/utils.js +++ b/test/local/email/utils.js @@ -5,11 +5,18 @@ 'use strict' const assert = require('insist') -const emailHelpers = require('../../../lib/email/utils/helpers') +const proxyquire = require('proxyquire') +const sinon = require('sinon') const spyLog = require('../../mocks').spyLog +const amplitude = sinon.spy() +const emailHelpers = proxyquire('../../../lib/email/utils/helpers', { + '../../metrics/amplitude': () => amplitude +}) describe('email utils helpers', () => { + afterEach(() => amplitude.reset()) + describe('getHeaderValue', () => { it('works with message.mail.headers', () => { @@ -69,7 +76,74 @@ describe('email utils helpers', () => { assert.equal(mockLog.info.args[1][0].domain, 'gmail.com') assert.equal(mockLog.info.args[2][0].domain, 'yahoo.com') }) - }) + it('logEmailEventSent should call amplitude correctly', () => { + emailHelpers.logEmailEventSent(spyLog(), { + email: 'foo@example.com', + ccEmails: [ 'bar@example.com', 'baz@example.com' ], + template: 'verifyEmail', + headers: [ + { name: 'Content-Language', value: 'aaa' }, + { name: 'X-Device-Id', value: 'bbb' }, + { name: 'X-Flow-Id', value: 'ccc' }, + { name: 'X-Service-Id', value: 'ddd' }, + { name: 'X-Uid', value: 'eee' } + ] + }) + assert.equal(amplitude.callCount, 1) + const args = amplitude.args[0] + assert.equal(args.length, 4) + assert.equal(args[0], 'email.verifyEmail.sent') + assert.deepEqual(args[1], { + app: { + locale: 'aaa', + ua: {} + }, + auth: {}, + query: {}, + payload: {} + }) + assert.deepEqual(args[2], { + device_id: 'bbb', + service: 'ddd', + uid: 'eee' + }) + assert.equal(args[3].flow_id, 'ccc') + assert.ok(args[3].time > Date.now() - 1000) + }) + + it('logEmailEventFromMessage should call amplitude correctly', () => { + emailHelpers.logEmailEventFromMessage(spyLog(), { + email: 'foo@example.com', + ccEmails: [ 'bar@example.com', 'baz@example.com' ], + headers: [ + { name: 'Content-Language', value: 'a' }, + { name: 'X-Device-Id', value: 'b' }, + { name: 'X-Flow-Id', value: 'c' }, + { name: 'X-Service-Id', value: 'd' }, + { name: 'X-Template-Name', value: 'verifyLoginEmail' }, + { name: 'X-Uid', value: 'e' } + ] + }, 'bounced', 'gmail.com') + assert.equal(amplitude.callCount, 1) + const args = amplitude.args[0] + assert.equal(args.length, 4) + assert.equal(args[0], 'email.verifyLoginEmail.bounced') + assert.deepEqual(args[1], { + app: { + locale: 'a', + ua: {} + }, + auth: {}, + query: {}, + payload: {} + }) + assert.deepEqual(args[2], { + device_id: 'b', + service: 'd', + uid: 'e' + }) + assert.equal(args[3].flow_id, 'c') + }) }) diff --git a/test/local/log.js b/test/local/log.js index bc59ec98..fa7a91a1 100644 --- a/test/local/log.js +++ b/test/local/log.js @@ -55,7 +55,11 @@ describe('log', () => { assert.equal(typeof log.begin, 'function', 'log.begin method was exported') assert.equal(typeof log.notifyAttachedServices, 'function', 'log.notifyAttachedServices method was exported') assert.equal(typeof log.activityEvent, 'function', 'log.activityEvent method was exported') + assert.equal(log.activityEvent.length, 1, 'log.activityEvent expects 1 argument') assert.equal(typeof log.flowEvent, 'function', 'log.flowEvent method was exported') + assert.equal(log.flowEvent.length, 1, 'log.flowEvent expects 1 argument') + assert.equal(typeof log.amplitudeEvent, 'function', 'log.amplitudeEvent method was exported') + assert.equal(log.amplitudeEvent.length, 1, 'log.amplitudeEvent expects 1 argument') assert.equal(typeof log.summary, 'function', 'log.summary method was exported') } ) @@ -340,6 +344,63 @@ describe('log', () => { } ) + it('.amplitudeEvent', () => { + log.amplitudeEvent({ event_type: 'foo' }) + + assert.equal(logger.info.callCount, 1, 'logger.info was called once') + const args = logger.info.args[0] + assert.equal(args.length, 2, 'logger.info was passed two arguments') + assert.equal(args[0], 'amplitudeEvent', 'first argument was correct') + assert.deepEqual(args[1], { event_type: 'foo' }, 'second argument was event data') + + assert.equal(logger.debug.callCount, 0, 'logger.debug was not called') + assert.equal(logger.error.callCount, 0, 'logger.error was not called') + assert.equal(logger.critical.callCount, 0, 'logger.critical was not called') + assert.equal(logger.warn.callCount, 0, 'logger.warn was not called') + + logger.info.reset() + }) + + it('.amplitudeEvent with missing data', () => { + log.amplitudeEvent() + + assert.equal(logger.error.callCount, 1, 'logger.error was called once') + const args = logger.error.args[0] + assert.equal(args.length, 2, 'logger.error was passed two arguments') + assert.equal(args[0], 'log.amplitudeEvent', 'first argument was function name') + assert.deepEqual(args[1], { + op: 'log.amplitudeEvent', + data: undefined + }, 'second argument was correct') + + assert.equal(logger.info.callCount, 0, 'logger.info was not called') + assert.equal(logger.debug.callCount, 0, 'logger.debug was not called') + assert.equal(logger.critical.callCount, 0, 'logger.critical was not called') + assert.equal(logger.warn.callCount, 0, 'logger.warn was not called') + + logger.error.reset() + }) + + it('.amplitudeEvent with missing event_type', () => { + log.amplitudeEvent({}) + + assert.equal(logger.error.callCount, 1, 'logger.error was called once') + const args = logger.error.args[0] + assert.equal(args.length, 2, 'logger.error was passed two arguments') + assert.equal(args[0], 'log.amplitudeEvent', 'first argument was function name') + assert.deepEqual(args[1], { + op: 'log.amplitudeEvent', + data: {} + }, 'second argument was correct') + + assert.equal(logger.info.callCount, 0, 'logger.info was not called') + assert.equal(logger.debug.callCount, 0, 'logger.debug was not called') + assert.equal(logger.critical.callCount, 0, 'logger.critical was not called') + assert.equal(logger.warn.callCount, 0, 'logger.warn was not called') + + logger.error.reset() + }) + it( '.error removes PII from error objects', () => { diff --git a/test/local/metrics/amplitude.js b/test/local/metrics/amplitude.js new file mode 100644 index 00000000..f7459598 --- /dev/null +++ b/test/local/metrics/amplitude.js @@ -0,0 +1,1007 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +'use strict' + +const assert = require('insist') +const amplitudeModule = require('../../../lib/metrics/amplitude') +const mocks = require('../../mocks') + +describe('metrics/amplitude', () => { + it('interface is correct', () => { + assert.equal(typeof amplitudeModule, 'function') + assert.equal(amplitudeModule.length, 1) + }) + + it('returns undefined if log argument is missing', () => { + assert.equal(amplitudeModule(), undefined) + }) + + describe('instantiate', () => { + let log, amplitude + + beforeEach(() => { + log = mocks.spyLog() + amplitude = amplitudeModule(log) + }) + + it('interface is correct', () => { + assert.equal(typeof amplitude, 'function') + assert.equal(amplitude.length, 2) + }) + + describe('empty event argument', () => { + beforeEach(() => { + amplitude('', mocks.mockRequest({})) + }) + + it('called log.error correctly', () => { + assert.equal(log.error.callCount, 1) + assert.equal(log.error.args[0].length, 1) + assert.deepEqual(log.error.args[0][0], { + op: 'amplitudeMetrics', + err: 'Bad argument', + event: '', + hasRequest: true + }) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('missing request argument', () => { + beforeEach(() => { + amplitude('foo') + }) + + it('called log.error correctly', () => { + assert.equal(log.error.callCount, 1) + assert.equal(log.error.args[0].length, 1) + assert.deepEqual(log.error.args[0][0], { + op: 'amplitudeMetrics', + err: 'Bad argument', + event: 'foo', + hasRequest: false + }) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('account.confirmed', () => { + beforeEach(() => { + amplitude('account.confirmed', mocks.mockRequest({ + uaBrowser: 'foo', + uaBrowserVersion: 'bar', + uaOS: 'baz', + uaOSVersion: 'qux', + uaDeviceType: 'qux', + uaFormFactor: 'qux', + locale: 'wibble', + credentials: { + uid: 'blee' + }, + query: { + service: 'melm' + }, + payload: { + service: 'piff', + metricsContext: { + deviceId: 'juff', + flowId: 'udge', + flowBeginTime: 'kwop' + } + } + })) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args.length, 1) + assert.equal(args[0].event_type, 'fxa_login - email_confirmed') + assert.equal(args[0].session_id, 'kwop') + assert.equal(args[0].language, 'wibble') + assert.deepEqual(args[0].event_properties, { + device_id: 'juff', + service: 'melm' + }) + assert.deepEqual(args[0].user_properties, { + flow_id: 'udge', + ua_browser: 'foo', + ua_version: 'bar', + ua_os: 'baz', + fxa_uid: 'blee' + }) + assert.ok(args[0].time > Date.now() - 1000) + assert.ok(/^[1-9][0-9]+$/.test(args[0].app_version)) + }) + }) + + describe('account.created', () => { + beforeEach(() => { + amplitude('account.created', mocks.mockRequest({ + uaBrowser: 'a', + uaBrowserVersion: 'b', + uaOS: 'c', + uaOSVersion: 'd', + uaDeviceType: 'd', + uaFormFactor: 'd', + locale: 'e', + credentials: { + uid: 'f' + }, + payload: { + service: 'g' + } + })) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_reg - created') + assert.equal(args[0].session_id, undefined) + assert.equal(args[0].language, 'e') + assert.deepEqual(args[0].event_properties, { + device_id: undefined, + service: 'g' + }) + assert.deepEqual(args[0].user_properties, { + flow_id: undefined, + ua_browser: 'a', + ua_version: 'b', + ua_os: 'c', + fxa_uid: 'f' + }) + }) + }) + + describe('account.login', () => { + beforeEach(() => { + amplitude('account.login', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - success') + }) + }) + + describe('account.login.blocked', () => { + beforeEach(() => { + amplitude('account.login.blocked', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - blocked') + }) + }) + + describe('account.login.confirmedUnblockCode', () => { + beforeEach(() => { + amplitude('account.login.confirmedUnblockCode', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - unblock_success') + }) + }) + + describe('account.reset', () => { + beforeEach(() => { + amplitude('account.reset', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - forgot_complete') + }) + }) + + describe('account.signed', () => { + beforeEach(() => { + amplitude('account.signed', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_activity - cert_signed') + }) + }) + + describe('account.verified', () => { + beforeEach(() => { + amplitude('account.verified', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_reg - email_confirmed') + }) + }) + + describe('flow.complete (sign-up)', () => { + beforeEach(() => { + amplitude('flow.complete', mocks.mockRequest({}), {}, { + flowType: 'registration' + }) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_reg - complete') + }) + }) + + describe('flow.complete (sign-in)', () => { + beforeEach(() => { + amplitude('flow.complete', mocks.mockRequest({}), {}, { + flowType: 'login' + }) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - complete') + }) + }) + + describe('flow.complete (reset)', () => { + beforeEach(() => { + amplitude('flow.complete', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('password.forgot.resend_code.completed', () => { + beforeEach(() => { + amplitude('password.forgot.resend_code.completed', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - forgot_sent') + }) + }) + + describe('password.forgot.send_code.completed', () => { + beforeEach(() => { + amplitude('password.forgot.send_code.completed', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_login - forgot_sent') + }) + }) + + describe('sms.installFirefox.sent', () => { + beforeEach(() => { + amplitude('sms.installFirefox.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_sms - sent') + }) + }) + + describe('device.created', () => { + beforeEach(() => { + amplitude('device.created', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('email.newDeviceLoginEmail.bounced', () => { + beforeEach(() => { + amplitude('email.newDeviceLoginEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'login') + }) + }) + + describe('email.newDeviceLoginEmail.sent', () => { + beforeEach(() => { + amplitude('email.newDeviceLoginEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'login') + }) + }) + + describe('email.passwordChangedEmail.bounced', () => { + beforeEach(() => { + amplitude('email.passwordChangedEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'change_password') + }) + }) + + describe('email.passwordChangedEmail.sent', () => { + beforeEach(() => { + amplitude('email.passwordChangedEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'change_password') + }) + }) + + describe('email.passwordResetEmail.bounced', () => { + beforeEach(() => { + amplitude('email.passwordResetEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.passwordResetEmail.sent', () => { + beforeEach(() => { + amplitude('email.passwordResetEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.passwordResetRequiredEmail.bounced', () => { + beforeEach(() => { + amplitude('email.passwordResetRequiredEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.passwordResetRequiredEmail.sent', () => { + beforeEach(() => { + amplitude('email.passwordResetRequiredEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.postRemoveSecondaryEmail.bounced', () => { + beforeEach(() => { + amplitude('email.postRemoveSecondaryEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.postRemoveSecondaryEmail.sent', () => { + beforeEach(() => { + amplitude('email.postRemoveSecondaryEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.postVerifyEmail.bounced', () => { + beforeEach(() => { + amplitude('email.postVerifyEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.postVerifyEmail.sent', () => { + beforeEach(() => { + amplitude('email.postVerifyEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.postVerifySecondaryEmail.bounced', () => { + beforeEach(() => { + amplitude('email.postVerifySecondaryEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.postVerifySecondaryEmail.sent', () => { + beforeEach(() => { + amplitude('email.postVerifySecondaryEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.recoveryEmail.bounced', () => { + beforeEach(() => { + amplitude('email.recoveryEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.recoveryEmail.sent', () => { + beforeEach(() => { + amplitude('email.recoveryEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'reset_password') + }) + }) + + describe('email.unblockCode.bounced', () => { + beforeEach(() => { + amplitude('email.unblockCode.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'unblock') + }) + }) + + describe('email.unblockCode.sent', () => { + beforeEach(() => { + amplitude('email.unblockCode.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'unblock') + }) + }) + + describe('email.verificationReminderFirstEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verificationReminderFirstEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verificationReminderFirstEmail.sent', () => { + beforeEach(() => { + amplitude('email.verificationReminderFirstEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verificationReminderSecondEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verificationReminderSecondEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verificationReminderSecondEmail.sent', () => { + beforeEach(() => { + amplitude('email.verificationReminderSecondEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verificationReminderEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verificationReminderEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verificationReminderEmail.sent', () => { + beforeEach(() => { + amplitude('email.verificationReminderEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verifyEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verifyEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verifyEmail.sent', () => { + beforeEach(() => { + amplitude('email.verifyEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verifyLoginEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verifyLoginEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'login') + }) + }) + + describe('email.verifyLoginEmail.sent', () => { + beforeEach(() => { + amplitude('email.verifyLoginEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'login') + }) + }) + + describe('email.verifySyncEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verifySyncEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verifySyncEmail.sent', () => { + beforeEach(() => { + amplitude('email.verifySyncEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'registration') + }) + }) + + describe('email.verifySecondaryEmail.bounced', () => { + beforeEach(() => { + amplitude('email.verifySecondaryEmail.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - bounced') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.verifySecondaryEmail.sent', () => { + beforeEach(() => { + amplitude('email.verifySecondaryEmail.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('called log.amplitudeEvent correctly', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_type, 'fxa_email - sent') + assert.equal(args[0].event_properties.email_type, 'secondary_email') + }) + }) + + describe('email.wibble.bounced', () => { + beforeEach(() => { + amplitude('email.wibble.bounced', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('email.wibble.sent', () => { + beforeEach(() => { + amplitude('email.wibble.sent', mocks.mockRequest({})) + }) + + it('did not call log.error', () => { + assert.equal(log.error.callCount, 0) + }) + + it('did not call log.amplitudeEvent', () => { + assert.equal(log.amplitudeEvent.callCount, 0) + }) + }) + + describe('with data', () => { + beforeEach(() => { + amplitude('account.signed', mocks.mockRequest({ + credentials: { + uid: 'foo' + }, + payload: { + service: 'bar' + }, + query: { + service: 'baz' + } + }), { + service: 'zang', + uid: 'frip' + }) + }) + + it('data properties were set', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_properties.service, 'zang') + assert.equal(args[0].user_properties.fxa_uid, 'frip') + }) + }) + + describe('with metricsContext', () => { + beforeEach(() => { + amplitude('sms.installFirefox.sent', mocks.mockRequest({ + payload: { + metricsContext: { + deviceId: 'foo', + flowId: 'bar', + flowBeginTime: 'baz' + } + } + }), {}, { + device_id: 'plin', + flow_id: 'gorb', + flowBeginTime: 'yerx', + time: 'wenf' + }) + }) + + it('metricsContext properties were set', () => { + assert.equal(log.amplitudeEvent.callCount, 1) + const args = log.amplitudeEvent.args[0] + assert.equal(args[0].event_properties.device_id, 'plin') + assert.equal(args[0].user_properties.flow_id, 'gorb') + assert.equal(args[0].session_id, 'yerx') + assert.equal(args[0].time, 'wenf') + }) + }) + }) +}) diff --git a/test/local/metrics/context.js b/test/local/metrics/context.js index ffb48af5..8dade7ce 100644 --- a/test/local/metrics/context.js +++ b/test/local/metrics/context.js @@ -68,7 +68,7 @@ describe('metricsContext', () => { assert.equal(metricsContext.validate.length, 0, 'metricsContext.validate expects no arguments') assert.equal(typeof metricsContext.setFlowCompleteSignal, 'function', 'metricsContext.setFlowCompleteSignal is function') - assert.equal(metricsContext.setFlowCompleteSignal.length, 1, 'metricsContext.setFlowCompleteSignal expects 1 argument') + assert.equal(metricsContext.setFlowCompleteSignal.length, 2, 'metricsContext.setFlowCompleteSignal expects 2 arguments') } ) @@ -187,9 +187,11 @@ describe('metricsContext', () => { return metricsContext.gather.call({ payload: { metricsContext: { + deviceId: 'mock device id', flowId: 'mock flow id', flowBeginTime: time, flowCompleteSignal: 'mock flow complete signal', + flowType: 'mock flow type', context: 'mock context', entrypoint: 'mock entry point', migration: 'mock migration', @@ -205,12 +207,15 @@ describe('metricsContext', () => { }, {}).then(function (result) { assert.equal(typeof result, 'object', 'result is object') assert.notEqual(result, null, 'result is not null') - assert.equal(Object.keys(result).length, 4, 'result has 4 properties') + assert.equal(Object.keys(result).length, 7, 'result has 7 properties') assert.ok(result.time > time, 'result.time seems correct') + assert.equal(result.device_id, 'mock device id', 'result.device_id is correct') assert.equal(result.flow_id, 'mock flow id', 'result.flow_id is correct') assert.ok(result.flow_time > 0, 'result.flow_time is greater than zero') assert.ok(result.flow_time < time, 'result.flow_time is less than the current time') + assert.equal(result.flowBeginTime, time, 'result.flowBeginTime is correct') assert.equal(result.flowCompleteSignal, 'mock flow complete signal', 'result.flowCompleteSignal is correct') + assert.equal(result.flowType, 'mock flow type', 'result.flowType is correct') assert.equal(cache.get.callCount, 0, 'cache.get was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') @@ -247,9 +252,11 @@ describe('metricsContext', () => { id: 'wibble' } results.get = P.resolve({ + deviceId: 'deviceId', flowId: 'flowId', flowBeginTime: time, - flowCompleteSignal: 'flowCompleteSignal' + flowCompleteSignal: 'flowCompleteSignal', + flowType: 'flowType' }) return metricsContext.gather.call({ auth: { @@ -262,12 +269,15 @@ describe('metricsContext', () => { assert.equal(typeof result, 'object', 'result is object') assert.notEqual(result, null, 'result is not null') - assert.equal(Object.keys(result).length, 4, 'result has 4 properties') + assert.equal(Object.keys(result).length, 7, 'result has 7 properties') assert.ok(result.time > time, 'result.time seems correct') + assert.equal(result.device_id, 'deviceId', 'result.device_id is correct') assert.equal(result.flow_id, 'flowId', 'result.flow_id is correct') assert.ok(result.flow_time > 0, 'result.flow_time is greater than zero') assert.ok(result.flow_time < time, 'result.flow_time is less than the current time') + assert.equal(result.flowBeginTime, time, 'result.flowBeginTime is correct') assert.equal(result.flowCompleteSignal, 'flowCompleteSignal', 'result.flowCompleteSignal is correct') + assert.equal(result.flowType, 'flowType', 'result.flowType is correct') assert.equal(log.error.callCount, 0, 'log.error was not called') }) @@ -296,7 +306,7 @@ describe('metricsContext', () => { assert.equal(typeof result, 'object', 'result is object') assert.notEqual(result, null, 'result is not null') - assert.equal(Object.keys(result).length, 4, 'result has 4 properties') + assert.equal(Object.keys(result).length, 7, 'result has 7 properties') assert.ok(result.time > time, 'result.time seems correct') assert.equal(result.flow_id, 'flowId', 'result.flow_id is correct') assert.ok(result.flow_time > 0, 'result.flow_time is greater than zero') @@ -356,26 +366,29 @@ describe('metricsContext', () => { () => { const time = Date.now() - 1 results.get = P.resolve({ - flowId: 'foo', - flowBeginTime: time + deviceId: 'foo', + flowId: 'bar', + flowBeginTime: time - 1 }) return metricsContext.gather.call({ auth: { credentials: { uid: Array(16).fill('f').join(''), - id: 'bar' + id: 'baz' } }, payload: { metricsContext: { - flowId: 'baz', + deviceId: 'qux', + flowId: 'wibble', flowBeginTime: time } } }, {}).then(function (result) { assert.equal(typeof result, 'object', 'result is object') assert.notEqual(result, null, 'result is not null') - assert.equal(result.flow_id, 'baz', 'result.flow_id is correct') + assert.equal(result.device_id, 'qux', 'result.device_id is correct') + assert.equal(result.flow_id, 'wibble', 'result.flow_id is correct') assert.equal(cache.get.callCount, 0, 'cache.get was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') @@ -896,8 +909,11 @@ describe('metricsContext', () => { metricsContext: {} } } - metricsContext.setFlowCompleteSignal.call(request, 'wibble') - assert.deepEqual(request.payload.metricsContext, { flowCompleteSignal: 'wibble' }, 'flowCompleteSignal was set correctly') + metricsContext.setFlowCompleteSignal.call(request, 'wibble', 'blee') + assert.deepEqual(request.payload.metricsContext, { + flowCompleteSignal: 'wibble', + flowType: 'blee' + }, 'flowCompleteSignal and flowType were set correctly') } ) @@ -907,8 +923,8 @@ describe('metricsContext', () => { const request = { payload: {} } - metricsContext.setFlowCompleteSignal.call(request, 'wibble') - assert.deepEqual(request.payload, {}, 'flowCompleteSignal was not set') + metricsContext.setFlowCompleteSignal.call(request, 'wibble', 'blee') + assert.deepEqual(request.payload, {}, 'flowCompleteSignal and flowType were not set') } ) diff --git a/test/local/metrics/events.js b/test/local/metrics/events.js index de212f6d..edb6f014 100644 --- a/test/local/metrics/events.js +++ b/test/local/metrics/events.js @@ -8,6 +8,7 @@ const assert = require('insist') const sinon = require('sinon') const log = { activityEvent: sinon.spy(), + amplitudeEvent: sinon.spy(), error: sinon.spy(), flowEvent: sinon.spy() } @@ -15,6 +16,13 @@ const events = require('../../../lib/metrics/events')(log) const mocks = require('../../mocks') describe('metrics/events', () => { + afterEach(() => { + log.activityEvent.reset() + log.amplitudeEvent.reset() + log.error.reset() + log.flowEvent.reset() + }) + it('interface is correct', () => { assert.equal(typeof events, 'object', 'events is object') assert.notEqual(events, null, 'events is not null') @@ -44,11 +52,10 @@ describe('metrics/events', () => { }, 'argument was correct') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') - }).finally(() => { - log.error.reset() }) }) @@ -78,12 +85,11 @@ describe('metrics/events', () => { uid: 'baz' }, 'argument was event data') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() }) }) @@ -106,12 +112,11 @@ describe('metrics/events', () => { service: 'bar' }, 'argument was event data') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() }) }) @@ -129,12 +134,11 @@ describe('metrics/events', () => { userAgent: 'test user-agent' }, 'argument was event data') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() }) }) @@ -167,7 +171,9 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time, uid: 'deadbeef', @@ -175,11 +181,10 @@ describe('metrics/events', () => { }, 'argument was event data') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -217,18 +222,19 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en', time, userAgent: 'foo' }, 'argument was event data') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -258,7 +264,9 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time, uid: 'deadbeef', @@ -266,11 +274,10 @@ describe('metrics/events', () => { }, 'argument was event data') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -300,7 +307,9 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time, uid: 'deadbeef', @@ -308,11 +317,10 @@ describe('metrics/events', () => { }, 'argument was event data') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -342,18 +350,19 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' }, 'argument was event data') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -369,7 +378,8 @@ describe('metrics/events', () => { metricsContext: { flowId: 'bar', flowBeginTime: time - 2000, - flowCompleteSignal: 'account.reminder' + flowCompleteSignal: 'account.reminder', + flowType: 'registration' } } }) @@ -382,7 +392,9 @@ describe('metrics/events', () => { event: 'account.reminder', flow_id: 'bar', flow_time: 2000, + flowBeginTime: time - 2000, flowCompleteSignal: 'account.reminder', + flowType: 'registration', locale: 'fr', time, uid: 'qux', @@ -392,22 +404,25 @@ describe('metrics/events', () => { event: 'flow.complete', flow_id: 'bar', flow_time: 2000, + flowBeginTime: time - 2000, flowCompleteSignal: 'account.reminder', + flowType: 'registration', locale: 'fr', time, uid: 'qux', userAgent: 'test user-agent' }, 'argument was complete event data second time') + assert.equal(log.amplitudeEvent.callCount, 1, 'log.amplitudeEvent was called once') + assert.equal(log.amplitudeEvent.args[0].length, 1, 'log.amplitudeEvent was passed one argument') + assert.equal(log.amplitudeEvent.args[0][0].event_type, 'fxa_reg - complete', 'log.amplitudeEvent was passed correct event_type') + assert.equal(metricsContext.clear.callCount, 1, 'metricsContext.clear was called once') assert.equal(metricsContext.clear.args[0].length, 0, 'metricsContext.clear was passed no arguments') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() - metricsContext.clear.reset() Date.now.restore() }) }) @@ -436,11 +451,10 @@ describe('metrics/events', () => { }, 'argument was correct') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') - }).finally(() => { - log.error.reset() }) }) @@ -466,11 +480,9 @@ describe('metrics/events', () => { }, 'argument was correct') assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') - }).finally(() => { - metricsContext.gather.reset() - log.error.reset() }) }) @@ -508,18 +520,18 @@ describe('metrics/events', () => { event: 'account.keyfetch', flow_id: 'bar', flow_time: 42, + flowBeginTime: time - 42, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', uid: 'baz', userAgent: 'test user-agent' }, 'flow event data was correct') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - log.activityEvent.reset() - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -542,12 +554,10 @@ describe('metrics/events', () => { assert.equal(log.activityEvent.callCount, 1, 'log.activityEvent was called once') assert.equal(metricsContext.gather.callCount, 1, 'metricsContext.gather was called once') + assert.equal(log.amplitudeEvent.callCount, 0, 'log.amplitudeEvent was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() - metricsContext.gather.reset() }) }) @@ -571,12 +581,26 @@ describe('metrics/events', () => { return events.emit.call(request, 'account.signed', data) .then(() => { assert.equal(log.activityEvent.callCount, 1, 'log.activityEvent was called once') + + assert.equal(log.amplitudeEvent.callCount, 1, 'log.amplitudeEvent was called once') + assert.equal(log.amplitudeEvent.args[0].length, 1, 'log.amplitudeEvent was passed one argument') + assert.equal(log.amplitudeEvent.args[0][0].event_type, 'fxa_activity - cert_signed', 'log.amplitudeEvent was passed correct event_type') + assert.deepEqual(log.amplitudeEvent.args[0][0].event_properties, { + device_id: undefined, + service: 'content-server' + }, 'log.amplitudeEvent was passed correct event properties') + assert.deepEqual(log.amplitudeEvent.args[0][0].user_properties, { + flow_id: 'bar', + ua_browser: request.app.ua.browser, + ua_version: request.app.ua.browserVersion, + ua_os: request.app.ua.os, + fxa_uid: 'baz' + }, 'log.amplitudeEvent was passed correct event properties') + assert.equal(metricsContext.gather.callCount, 0, 'metricsContext.gather was not called') assert.equal(log.flowEvent.callCount, 0, 'log.flowEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() }) }) @@ -599,15 +623,14 @@ describe('metrics/events', () => { } return events.emit.call(request, 'account.signed', data) .then(() => { + assert.equal(log.amplitudeEvent.callCount, 1, 'log.amplitudeEvent was called once') + assert.equal(log.amplitudeEvent.args[0][0].event_properties.service, 'sync', 'log.amplitudeEvent was passed correct service') + assert.equal(log.activityEvent.callCount, 1, 'log.activityEvent was called once') assert.equal(metricsContext.gather.callCount, 1, 'metricsContext.gather was called once') assert.equal(log.flowEvent.callCount, 1, 'log.flowEvent was called once') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.activityEvent.reset() - metricsContext.gather.reset() - log.flowEvent.reset() }) }) @@ -638,7 +661,9 @@ describe('metrics/events', () => { event: 'route./account/create.200', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' @@ -650,7 +675,9 @@ describe('metrics/events', () => { event: 'route.performance./account/create', flow_id: 'bar', flow_time: 42, + flowBeginTime: time - 1000, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' @@ -660,8 +687,6 @@ describe('metrics/events', () => { assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -689,7 +714,9 @@ describe('metrics/events', () => { event: 'route./account/login.399', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' @@ -699,8 +726,6 @@ describe('metrics/events', () => { assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -728,7 +753,9 @@ describe('metrics/events', () => { event: 'route./recovery_email/resend_code.400.999', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' @@ -738,8 +765,6 @@ describe('metrics/events', () => { assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -767,7 +792,9 @@ describe('metrics/events', () => { event: 'route./account/destroy.400.42', flow_id: 'bar', flow_time: 1000, + flowBeginTime: time - 1000, flowCompleteSignal: undefined, + flowType: undefined, locale: 'en-US', time, userAgent: 'test user-agent' @@ -777,8 +804,6 @@ describe('metrics/events', () => { assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') }).finally(() => { - metricsContext.gather.reset() - log.flowEvent.reset() Date.now.restore() }) }) @@ -851,8 +876,6 @@ describe('metrics/events', () => { assert.equal(log.activityEvent.callCount, 0, 'log.activityEvent was not called') assert.equal(metricsContext.clear.callCount, 0, 'metricsContext.clear was not called') assert.equal(log.error.callCount, 0, 'log.error was not called') - }).finally(() => { - log.flowEvent.reset() }) }) }) diff --git a/test/local/routes/account.js b/test/local/routes/account.js index 12470cc8..2343ac0d 100644 --- a/test/local/routes/account.js +++ b/test/local/routes/account.js @@ -157,7 +157,7 @@ describe('/account/reset', function () { assert.equal(mockMetricsContext.setFlowCompleteSignal.callCount, 1, 'metricsContext.setFlowCompleteSignal was called once') args = mockMetricsContext.setFlowCompleteSignal.args[0] assert.equal(args.length, 1, 'metricsContext.setFlowCompleteSignal was passed one argument') - assert.deepEqual(args[0], 'account.signed', 'argument was event name') + assert.equal(args[0], 'account.signed', 'argument was event name') assert.equal(mockMetricsContext.stash.callCount, 2, 'metricsContext.stash was called twice') @@ -321,7 +321,9 @@ describe('/account/create', () => { assert.equal(eventData.data.service, 'sync', 'it was for sync') assert.equal(eventData.data.email, TEST_EMAIL, 'it was for the correct email') assert.deepEqual(eventData.data.metricsContext, { + flowBeginTime: mockRequest.payload.metricsContext.flowBeginTime, flowCompleteSignal: 'account.signed', + flowType: undefined, flow_id: mockRequest.payload.metricsContext.flowId, flow_time: now - mockRequest.payload.metricsContext.flowBeginTime, time: now @@ -342,7 +344,9 @@ describe('/account/create', () => { assert.equal(args.length, 1, 'log.flowEvent was passed one argument') assert.deepEqual(args[0], { event: 'account.created', + flowBeginTime: mockRequest.payload.metricsContext.flowBeginTime, flowCompleteSignal: 'account.signed', + flowType: undefined, flow_time: now - mockRequest.payload.metricsContext.flowBeginTime, flow_id: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103', locale: 'en-GB', @@ -376,8 +380,9 @@ describe('/account/create', () => { assert.equal(mockMetricsContext.setFlowCompleteSignal.callCount, 1, 'metricsContext.setFlowCompleteSignal was called once') args = mockMetricsContext.setFlowCompleteSignal.args[0] - assert.equal(args.length, 1, 'metricsContext.setFlowCompleteSignal was passed one argument') - assert.deepEqual(args[0], 'account.signed', 'argument was event name') + assert.equal(args.length, 2, 'metricsContext.setFlowCompleteSignal was passed two arguments') + assert.equal(args[0], 'account.signed', 'first argument was event name') + assert.equal(args[1], 'registration', 'second argument was flow type') var securityEvent = mockDB.securityEvent assert.equal(securityEvent.callCount, 1, 'db.securityEvent is called') @@ -395,6 +400,10 @@ describe('/account/create', () => { assert.equal(args[2].uaOS, 'Mac OS X') assert.equal(args[2].uaOSVersion, '10.10') assert.strictEqual(args[2].uaDeviceType, undefined) + assert.equal(args[2].flowId, mockRequest.payload.metricsContext.flowId) + assert.equal(args[2].flowBeginTime, mockRequest.payload.metricsContext.flowBeginTime) + assert.equal(args[2].service, 'sync') + assert.equal(args[2].uid, uid) assert.equal(mockLog.error.callCount, 0) }).finally(() => Date.now.restore()) @@ -462,7 +471,6 @@ describe('/account/login', function () { }) const mockRequestWithUnblockCode = mocks.mockRequest({ log: mockLog, - query: {}, payload: { authPW: hexString(32), email: TEST_EMAIL, @@ -471,8 +479,7 @@ describe('/account/login', function () { reason: 'signin', metricsContext: { flowBeginTime: Date.now(), - flowId: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103', - service: 'dcdb5ae7add825d2' + flowId: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103' } } }) @@ -559,7 +566,9 @@ describe('/account/login', function () { time: now, flow_id: mockRequest.payload.metricsContext.flowId, flow_time: now - mockRequest.payload.metricsContext.flowBeginTime, - flowCompleteSignal: 'account.signed' + flowBeginTime: mockRequest.payload.metricsContext.flowBeginTime, + flowCompleteSignal: 'account.signed', + flowType: undefined }, 'metrics context was correct') assert.equal(mockLog.activityEvent.callCount, 1, 'log.activityEvent was called once') @@ -579,7 +588,9 @@ describe('/account/login', function () { event: 'account.login', flow_time: now - mockRequest.payload.metricsContext.flowBeginTime, flow_id: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103', + flowBeginTime: mockRequest.payload.metricsContext.flowBeginTime, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time: now, uid: uid, @@ -591,7 +602,9 @@ describe('/account/login', function () { event: 'email.confirmation.sent', flow_time: now - mockRequest.payload.metricsContext.flowBeginTime, flow_id: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103', + flowBeginTime: mockRequest.payload.metricsContext.flowBeginTime, flowCompleteSignal: 'account.signed', + flowType: undefined, locale: 'en-US', time: now, userAgent: 'test user-agent' @@ -622,8 +635,9 @@ describe('/account/login', function () { assert.equal(mockMetricsContext.setFlowCompleteSignal.callCount, 1, 'metricsContext.setFlowCompleteSignal was called once') args = mockMetricsContext.setFlowCompleteSignal.args[0] - assert.equal(args.length, 1, 'metricsContext.setFlowCompleteSignal was passed one argument') - assert.deepEqual(args[0], 'account.signed', 'argument was event name') + assert.equal(args.length, 2, 'metricsContext.setFlowCompleteSignal was passed two arguments') + assert.equal(args[0], 'account.signed', 'argument was event name') + assert.equal(args[1], 'login', 'second argument was flow type') assert.equal(mockMailer.sendVerifyLoginEmail.callCount, 1, 'mailer.sendVerifyLoginEmail was called') args = mockMailer.sendVerifyLoginEmail.args[0] @@ -635,6 +649,10 @@ describe('/account/login', function () { assert.equal(args[2].uaOS, 'Android') assert.equal(args[2].uaOSVersion, '6') assert.equal(args[2].uaDeviceType, 'mobile') + assert.equal(args[2].flowId, mockRequest.payload.metricsContext.flowId) + assert.equal(args[2].flowBeginTime, mockRequest.payload.metricsContext.flowBeginTime) + assert.equal(args[2].service, 'sync') + assert.equal(args[2].uid, uid) assert.equal(mockMailer.sendNewDeviceLoginNotification.callCount, 0, 'mailer.sendNewDeviceLoginNotification was not called') assert.ok(! response.verified, 'response indicates account is not verified') @@ -878,6 +896,10 @@ describe('/account/login', function () { assert.equal(tokenData.tokenVerificationId, null, 'sessionToken was created verified') assert.equal(mockMailer.sendVerifyCode.callCount, 0, 'mailer.sendVerifyLoginEmail was not called') assert.equal(mockMailer.sendNewDeviceLoginNotification.callCount, 1, 'mailer.sendNewDeviceLoginNotification was called') + assert.equal(mockMailer.sendNewDeviceLoginNotification.args[0][2].flowId, mockRequest.payload.metricsContext.flowId) + assert.equal(mockMailer.sendNewDeviceLoginNotification.args[0][2].flowBeginTime, mockRequest.payload.metricsContext.flowBeginTime) + assert.equal(mockMailer.sendNewDeviceLoginNotification.args[0][2].service, 'sync') + assert.equal(mockMailer.sendNewDeviceLoginNotification.args[0][2].uid, uid) assert.ok(response.verified, 'response indicates account is verified') }) }) diff --git a/test/local/routes/emails.js b/test/local/routes/emails.js index 4eec9916..4b74399b 100644 --- a/test/local/routes/emails.js +++ b/test/local/routes/emails.js @@ -288,6 +288,7 @@ describe('/recovery_email/resend_code', () => { metricsContext: mockMetricsContext, credentials: { uid: uuid.v4('binary').toString('hex'), + deviceId: 'wibble', email: TEST_EMAIL, emailVerified: false, tokenVerified: false, @@ -298,6 +299,7 @@ describe('/recovery_email/resend_code', () => { }, query: {}, payload: { + service: 'sync', metricsContext: { flowBeginTime: Date.now(), flowId: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103' @@ -316,6 +318,11 @@ describe('/recovery_email/resend_code', () => { assert.equal(args[2].uaOS, 'Mac OS X') assert.equal(args[2].uaOSVersion, '10.10') assert.strictEqual(args[2].uaDeviceType, undefined) + assert.equal(args[2].deviceId, mockRequest.auth.credentials.deviceId) + assert.equal(args[2].flowId, mockRequest.payload.metricsContext.flowId) + assert.equal(args[2].flowBeginTime, mockRequest.payload.metricsContext.flowBeginTime) + assert.equal(args[2].service, mockRequest.payload.service) + assert.equal(args[2].uid, mockRequest.auth.credentials.uid) }) .then(() => { mockMailer.sendVerifyCode.reset() @@ -329,6 +336,7 @@ describe('/recovery_email/resend_code', () => { metricsContext: mockMetricsContext, credentials: { uid: uuid.v4('binary').toString('hex'), + deviceId: uuid.v4('binary').toString('hex'), email: TEST_EMAIL, emailVerified: true, tokenVerified: false, @@ -338,7 +346,9 @@ describe('/recovery_email/resend_code', () => { uaOSVersion: '6', uaDeviceType: 'tablet' }, - query: {}, + query: { + service: 'foo' + }, payload: { email : 'secondEmail@email.com' } @@ -346,6 +356,12 @@ describe('/recovery_email/resend_code', () => { return runTest(route, mockRequest, response => { assert.equal(mockMailer.sendVerifySecondaryEmail.callCount, 1) + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].deviceId, mockRequest.auth.credentials.deviceId) + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].flowId, mockMetricsContext.flowId) + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].flowBeginTime, mockMetricsContext.flowBeginTime) + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].service, 'foo') + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].uid, mockRequest.auth.credentials.uid) + assert.equal(mockMailer.sendVerifyCode.callCount, 0) assert.equal(mockMailer.sendVerifyLoginEmail.callCount, 0) const args = mockMailer.sendVerifySecondaryEmail.getCall(0).args @@ -363,6 +379,7 @@ describe('/recovery_email/resend_code', () => { metricsContext: mockMetricsContext, credentials: { uid: uuid.v4('binary').toString('hex'), + deviceId: uuid.v4('binary').toString('hex'), email: TEST_EMAIL, emailVerified: true, tokenVerified: false, @@ -374,6 +391,7 @@ describe('/recovery_email/resend_code', () => { }, query: {}, payload: { + service: 'foo', metricsContext: { flowBeginTime: Date.now(), flowId: 'F1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF1031DF103' @@ -393,6 +411,11 @@ describe('/recovery_email/resend_code', () => { assert.equal(args[2].uaOS, 'Android') assert.equal(args[2].uaOSVersion, '6') assert.strictEqual(args[2].uaDeviceType, 'tablet') + assert.equal(args[2].deviceId, mockRequest.auth.credentials.deviceId) + assert.equal(args[2].flowId, mockRequest.payload.metricsContext.flowId) + assert.equal(args[2].flowBeginTime, mockRequest.payload.metricsContext.flowBeginTime) + assert.equal(args[2].service, mockRequest.payload.service) + assert.equal(args[2].uid, mockRequest.auth.credentials.uid) }) }) @@ -467,6 +490,8 @@ describe('/recovery_email/verify_code', function () { assert.equal(args[2].marketingOptIn, undefined) assert.equal(mockMailer.sendPostVerifyEmail.callCount, 1, 'sendPostVerifyEmail was called once') + assert.equal(mockMailer.sendPostVerifyEmail.args[0][2].service, mockRequest.payload.service) + assert.equal(mockMailer.sendPostVerifyEmail.args[0][2].uid, uid) assert.equal(mockLog.activityEvent.callCount, 1, 'activityEvent was called once') args = mockLog.activityEvent.args[0] @@ -643,6 +668,8 @@ describe('/recovery_email/verify_code', function () { assert.equal(args.length, 3, 'mockMailer.sendPostVerifySecondaryEmail was passed correct arguments') assert.equal(args[1].email, dbData.email, 'correct account primary email was passed') assert.equal(args[2].secondaryEmail, dbData.secondEmail, 'correct secondary email was passed') + assert.equal(args[2].service, mockRequest.payload.service) + assert.equal(args[2].uid, uid) }) .then(function () { mockDB.verifyEmail.reset() @@ -666,6 +693,7 @@ describe('/recovery_email', () => { mockRequest = mocks.mockRequest({ credentials: { uid: uuid.v4('binary').toString('hex'), + deviceId: uuid.v4('binary').toString('hex'), email: TEST_EMAIL, emailVerified: true, normalizedEmail: TEST_EMAIL.toLowerCase() @@ -713,6 +741,8 @@ describe('/recovery_email', () => { assert.ok(response) assert.equal(mockDB.createEmail.callCount, 1, 'call db.createEmail') assert.equal(mockMailer.sendVerifySecondaryEmail.callCount, 1, 'call db.sendVerifySecondaryEmail') + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].deviceId, mockRequest.auth.credentials.deviceId) + assert.equal(mockMailer.sendVerifySecondaryEmail.args[0][2].uid, mockRequest.auth.credentials.uid) }) .then(function () { mockDB.createEmail.reset() diff --git a/test/local/routes/password.js b/test/local/routes/password.js index 2fa76a1a..cd96305b 100644 --- a/test/local/routes/password.js +++ b/test/local/routes/password.js @@ -122,6 +122,7 @@ describe('/password', () => { assert.equal(mockMailer.sendRecoveryCode.getCall(0).args[2].location.city, 'Mountain View') assert.equal(mockMailer.sendRecoveryCode.getCall(0).args[2].location.country, 'United States') assert.equal(mockMailer.sendRecoveryCode.getCall(0).args[2].timeZone, 'America/Los_Angeles') + assert.equal(mockMailer.sendRecoveryCode.getCall(0).args[2].uid, uid) }) } ) @@ -177,6 +178,7 @@ describe('/password', () => { return runRoute(passwordRoutes, '/password/forgot/resend_code', mockRequest) .then(function(response) { assert.equal(mockMailer.sendRecoveryCode.callCount, 1, 'mailer.sendRecoveryCode was called once') + assert.equal(mockMailer.sendRecoveryCode.args[0][2].uid, uid) assert.equal(mockRequest.validateMetricsContext.callCount, 1, 'validateMetricsContext was called') assert.equal(mockLog.flowEvent.callCount, 2, 'log.flowEvent was called twice') @@ -256,6 +258,9 @@ describe('/password', () => { assert.equal(mockLog.flowEvent.callCount, 2, 'log.flowEvent was called twice') assert.equal(mockLog.flowEvent.args[0][0].event, 'password.forgot.verify_code.start', 'password.forgot.verify_code.start event was logged') assert.equal(mockLog.flowEvent.args[1][0].event, 'password.forgot.verify_code.completed', 'password.forgot.verify_code.completed event was logged') + + assert.equal(mockMailer.sendPasswordResetNotification.callCount, 1, 'mailer.sendPasswordResetNotification was called once') + assert.equal(mockMailer.sendPasswordResetNotification.args[0][2].uid, uid, 'mailer.sendPasswordResetNotification was passed uid') }) } ) @@ -317,6 +322,7 @@ describe('/password', () => { assert.equal(mockMailer.sendPasswordChangedNotification.getCall(0).args[2].location.city, 'Mountain View') assert.equal(mockMailer.sendPasswordChangedNotification.getCall(0).args[2].location.country, 'United States') assert.equal(mockMailer.sendPasswordChangedNotification.getCall(0).args[2].timeZone, 'America/Los_Angeles') + assert.equal(mockMailer.sendPasswordChangedNotification.getCall(0).args[2].uid, uid) assert.equal(mockLog.activityEvent.callCount, 1, 'log.activityEvent was called once') var args = mockLog.activityEvent.args[0] diff --git a/test/local/senders/email.js b/test/local/senders/email.js index 3749f6a0..0a14fc9a 100644 --- a/test/local/senders/email.js +++ b/test/local/senders/email.js @@ -12,9 +12,10 @@ var sinon = require('sinon') var P = require('bluebird') var mockLog = { - trace: function () {}, + amplitudeEvent () {}, + trace () {}, info: sinon.spy(), - error: function () {} + error () {} } var config = require(`${ROOT_DIR}/config`) @@ -125,6 +126,7 @@ describe( function (type) { var message = { code: 'abc123', + deviceId: 'foo', email: 'a@b.com', locations: [], service: 'sync', @@ -158,21 +160,17 @@ describe( } ) - it( - 'Contains flow headers for ' + type, - function () { - if (type !== 'verificationReminderEmail') { - mailer.mailer.sendMail = function (emailConfig) { - var flowIdHeader = emailConfig.headers['X-Flow-Id'] - assert.equal(flowIdHeader, message.flowId) - - var flowBeginHeader = emailConfig.headers['X-Flow-Begin-Time'] - assert.equal(flowBeginHeader, message.flowBeginTime) - } - mailer[type](message) - } + it(`Contains device, flow, service and uid headers for ${type}`, () => { + mailer.mailer.sendMail = emailConfig => { + const headers = emailConfig.headers + assert.equal(headers['X-Device-Id'], message.deviceId, 'device id header is correct') + assert.equal(headers['X-Flow-Id'], message.flowId, 'flow id header is correct') + assert.equal(headers['X-Flow-Begin-Time'], message.flowBeginTime, 'flow begin time header is correct') + assert.equal(headers['X-Service-Id'], message.service, 'service id header is correct') + assert.equal(headers['X-Uid'], message.uid, 'uid header is correct') } - ) + mailer[type](message) + }) it( 'test privacy link is in email template output for ' + type, diff --git a/test/mocks.js b/test/mocks.js index 979699ea..aafefedf 100644 --- a/test/mocks.js +++ b/test/mocks.js @@ -71,6 +71,7 @@ const DB_METHOD_NAMES = [ const LOG_METHOD_NAMES = [ 'activityEvent', + 'amplitudeEvent', 'begin', 'error', 'flowEvent', @@ -415,7 +416,9 @@ function mockMetricsContext (methods) { time: time, flow_id: this.payload.metricsContext.flowId, flow_time: time - this.payload.metricsContext.flowBeginTime, - flowCompleteSignal: this.payload.metricsContext.flowCompleteSignal + flowBeginTime: this.payload.metricsContext.flowBeginTime, + flowCompleteSignal: this.payload.metricsContext.flowCompleteSignal, + flowType: this.payload.metricsContext.flowType }) } @@ -484,7 +487,7 @@ function mockRequest (data) { received: data.received || Date.now() - 1 }, path: data.path, - payload: data.payload, + payload: data.payload || {}, query: data.query || {}, setMetricsFlowCompleteSignal: metricsContext.setFlowCompleteSignal, stashMetricsContext: metricsContext.stash,