Merge pull request #2950 from mozilla/standard-mozlog-logging

https://github.com/mozilla/fxa-auth-server/pull/2950
r=philbooth
This commit is contained in:
Phil Booth 2019-03-08 17:56:42 +00:00 коммит произвёл GitHub
Родитель 9c774548ef 0b3e970de1
Коммит 7fe15bfc5e
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: 4AEE18F83AFDEB23
82 изменённых файлов: 642 добавлений и 733 удалений

Просмотреть файл

@ -126,8 +126,7 @@ module.exports = function createBackendServiceAPI(log, config, serviceName, meth
if (! err) {
return resolve(value)
}
log.error({
op: fullMethodName,
log.error(fullMethodName, {
error: `${location} schema validation failed`,
message: err.message,
value
@ -141,7 +140,7 @@ module.exports = function createBackendServiceAPI(log, config, serviceName, meth
// This assumes you've done all the hard work of formulating params, body, etc.
async function sendRequest(pool, method, path, params, query, payload, headers) {
log.trace({ op: fullMethodName, params, query, payload })
log.trace(fullMethodName, { params, query, payload })
try {
return await pool.request(method, path, params, query, payload, headers)
} catch (err) {
@ -150,7 +149,7 @@ module.exports = function createBackendServiceAPI(log, config, serviceName, meth
if (err.errno || (err.statusCode && err.statusCode < 500)) {
throw err
} else {
log.error({ op: `${fullMethodName}.1`, params, query, payload, err })
log.error(`${fullMethodName}.1`, { params, query, payload, err })
throw error.backendServiceFailure(serviceName, methodName)
}
}

Просмотреть файл

@ -87,7 +87,7 @@ module.exports = (log, config, namespace) => {
return _cache
})
.catch(err => {
log.error({ op: 'cache.getCache', err: err })
log.error('cache.getCache', { err: err })
return NULL_CACHE
})
}

Просмотреть файл

@ -49,7 +49,7 @@ module.exports = function(log, config) {
function hash(input, salt, N, r, p, len) {
var d = P.defer()
if (scrypt.maxPending > 0 && scrypt.numPending > scrypt.maxPending) {
log.warn({ op: 'scrypt.maxPendingExceeded' })
log.warn('scrypt.maxPendingExceeded')
d.reject(new Error('too many pending scrypt hashes'))
} else {
scrypt.numPending += 1

144
lib/db.js
Просмотреть файл

@ -100,7 +100,7 @@ module.exports = (
SAFE_URLS.createAccount = new SafeUrl('/account/:uid', 'db.createAccount')
DB.prototype.createAccount = function (data) {
const { uid, email } = data
log.trace({ op: 'DB.createAccount', uid, email })
log.trace('DB.createAccount', { uid, email })
data.createdAt = data.verifierSetAt = Date.now()
data.normalizedEmail = data.email.toLowerCase()
return this.pool.put(SAFE_URLS.createAccount, { uid }, data)
@ -119,7 +119,7 @@ module.exports = (
DB.prototype.createSessionToken = function (authToken) {
const { uid } = authToken
log.trace({ op: 'DB.createSessionToken', uid })
log.trace('DB.createSessionToken', { uid })
return SessionToken.create(authToken)
.then(sessionToken => {
@ -140,7 +140,7 @@ module.exports = (
SAFE_URLS.createKeyFetchToken = new SafeUrl('/keyFetchToken/:id', 'db.createKeyFetchToken')
DB.prototype.createKeyFetchToken = function (authToken) {
log.trace({ op: 'DB.createKeyFetchToken', uid: authToken && authToken.uid })
log.trace('DB.createKeyFetchToken', { uid: authToken && authToken.uid })
return KeyFetchToken.create(authToken)
.then(
function (keyFetchToken) {
@ -171,7 +171,7 @@ module.exports = (
'db.createPasswordForgotToken'
)
DB.prototype.createPasswordForgotToken = function (emailRecord) {
log.trace({ op: 'DB.createPasswordForgotToken', uid: emailRecord && emailRecord.uid })
log.trace('DB.createPasswordForgotToken', { uid: emailRecord && emailRecord.uid })
return PasswordForgotToken.create(emailRecord)
.then(
function (passwordForgotToken) {
@ -202,7 +202,7 @@ module.exports = (
'db.createPasswordChangeToken'
)
DB.prototype.createPasswordChangeToken = function (data) {
log.trace({ op: 'DB.createPasswordChangeToken', uid: data.uid })
log.trace('DB.createPasswordChangeToken', { uid: data.uid })
return PasswordChangeToken.create(data)
.then(
function (passwordChangeToken) {
@ -230,7 +230,7 @@ module.exports = (
SAFE_URLS.checkPassword = new SafeUrl('/account/:uid/checkPassword', 'db.checkPassword')
DB.prototype.checkPassword = function (uid, verifyHash) {
log.trace({ op: 'DB.checkPassword', uid, verifyHash })
log.trace('DB.checkPassword', { uid, verifyHash })
return this.pool.post(SAFE_URLS.checkPassword,
{ uid },
{
@ -250,7 +250,7 @@ module.exports = (
}
DB.prototype.accountExists = function (email) {
log.trace({ op: 'DB.accountExists', email: email })
log.trace('DB.accountExists', { email: email })
return this.accountRecord(email)
.then(
function () {
@ -267,7 +267,7 @@ module.exports = (
SAFE_URLS.sessions = new SafeUrl('/account/:uid/sessions', 'db.sessions')
DB.prototype.sessions = function (uid) {
log.trace({ op: 'DB.sessions', uid })
log.trace('DB.sessions', { uid })
const promises = [
this.pool.get(SAFE_URLS.sessions, { uid })
.then(sessionTokens => {
@ -334,8 +334,7 @@ module.exports = (
}
return mergedToken
})
log.info({
op: 'db.sessions.count',
log.info('db.sessions.count', {
mysql: mysqlSessionTokens.length,
redis: redisSessionTokens.length
})
@ -345,7 +344,7 @@ module.exports = (
SAFE_URLS.keyFetchToken = new SafeUrl('/keyFetchToken/:id', 'db.keyFetchToken')
DB.prototype.keyFetchToken = function (id) {
log.trace({ op: 'DB.keyFetchToken', id })
log.trace('DB.keyFetchToken', { id })
return this.pool.get(SAFE_URLS.keyFetchToken, { id })
.then(
function (data) {
@ -363,7 +362,7 @@ module.exports = (
'db.keyFetchTokenWithVerificationStatus'
)
DB.prototype.keyFetchTokenWithVerificationStatus = function (id) {
log.trace({ op: 'DB.keyFetchTokenWithVerificationStatus', id })
log.trace('DB.keyFetchTokenWithVerificationStatus', { id })
return this.pool.get(SAFE_URLS.keyFetchTokenWithVerificationStatus, { id })
.then(
function (data) {
@ -378,7 +377,7 @@ module.exports = (
SAFE_URLS.accountResetToken = new SafeUrl('/accountResetToken/:id', 'db.accountResetToken')
DB.prototype.accountResetToken = function (id) {
log.trace({ op: 'DB.accountResetToken', id })
log.trace('DB.accountResetToken', { id })
return this.pool.get(SAFE_URLS.accountResetToken, { id })
.then(
function (data) {
@ -393,7 +392,7 @@ module.exports = (
SAFE_URLS.passwordForgotToken = new SafeUrl('/passwordForgotToken/:id', 'db.passwordForgotToken')
DB.prototype.passwordForgotToken = function (id) {
log.trace({ op: 'DB.passwordForgotToken', id })
log.trace('DB.passwordForgotToken', { id })
return this.pool.get(SAFE_URLS.passwordForgotToken, { id })
.then(
function (data) {
@ -408,7 +407,7 @@ module.exports = (
SAFE_URLS.passwordChangeToken = new SafeUrl('/passwordChangeToken/:id', 'db.passwordChangeToken')
DB.prototype.passwordChangeToken = function (id) {
log.trace({ op: 'DB.passwordChangeToken', id })
log.trace('DB.passwordChangeToken', { id })
return this.pool.get(SAFE_URLS.passwordChangeToken, { id })
.then(
function (data) {
@ -427,7 +426,7 @@ module.exports = (
*/
SAFE_URLS.emailRecord = new SafeUrl('/emailRecord/:email', 'db.emailRecord')
DB.prototype.emailRecord = function (email) {
log.trace({ op: 'DB.emailRecord', email })
log.trace('DB.emailRecord', { email })
return this.pool.get(SAFE_URLS.emailRecord, { email: hexEncode(email) })
.then(
(body) => {
@ -444,7 +443,7 @@ module.exports = (
SAFE_URLS.accountRecord = new SafeUrl('/email/:email/account', 'db.accountRecord')
DB.prototype.accountRecord = function (email) {
log.trace({ op: 'DB.accountRecord', email })
log.trace('DB.accountRecord', { email })
return this.pool.get(SAFE_URLS.accountRecord, { email: hexEncode(email) })
.then(
(body) => {
@ -463,7 +462,7 @@ module.exports = (
SAFE_URLS.setPrimaryEmail = new SafeUrl('/email/:email/account/:uid', 'db.setPrimaryEmail')
DB.prototype.setPrimaryEmail = function (uid, email) {
log.trace({ op: 'DB.setPrimaryEmail', email })
log.trace('DB.setPrimaryEmail', { email })
return this.pool.post(SAFE_URLS.setPrimaryEmail, { email: hexEncode(email), uid })
.then(
function (body) {
@ -480,7 +479,7 @@ module.exports = (
SAFE_URLS.account = new SafeUrl('/account/:uid', 'db.account')
DB.prototype.account = function (uid) {
log.trace({ op: 'DB.account', uid })
log.trace('DB.account', { uid })
return this.pool.get(SAFE_URLS.account, { uid })
.then((body) => {
body.emailVerified = !! body.emailVerified
@ -496,7 +495,7 @@ module.exports = (
SAFE_URLS.devices = new SafeUrl('/account/:uid/devices', 'db.devices')
DB.prototype.devices = function (uid) {
log.trace({ op: 'DB.devices', uid })
log.trace('DB.devices', { uid })
if (! uid) {
return P.reject(error.unknownAccount())
@ -536,7 +535,7 @@ module.exports = (
SAFE_URLS.sessionToken = new SafeUrl('/sessionToken/:id', 'db.sessionToken')
DB.prototype.sessionToken = function (id) {
log.trace({ op: 'DB.sessionToken', id })
log.trace('DB.sessionToken', { id })
return this.pool.get(SAFE_URLS.sessionToken, { id })
.then(
function (data) {
@ -556,7 +555,7 @@ module.exports = (
'db.updatePasswordForgotToken'
)
DB.prototype.updatePasswordForgotToken = function (token) {
log.trace({ op: 'DB.udatePasswordForgotToken', uid: token && token.uid })
log.trace('DB.udatePasswordForgotToken', { uid: token && token.uid })
const { id } = token
return this.pool.post(
SAFE_URLS.updatePasswordForgotToken,
@ -579,7 +578,7 @@ module.exports = (
DB.prototype.touchSessionToken = function (token, geo) {
const { id, uid } = token
log.trace({ op: 'DB.touchSessionToken', id, uid })
log.trace('DB.touchSessionToken', { id, uid })
if (! this.redis || ! features.isLastAccessTimeEnabledForUser(uid)) {
return P.resolve()
@ -627,7 +626,7 @@ module.exports = (
DB.prototype.updateSessionToken = function (sessionToken, geo) {
const { id, uid } = sessionToken
log.trace({ op: 'DB.updateSessionToken', id, uid })
log.trace('DB.updateSessionToken', { id, uid })
return this.touchSessionToken(sessionToken, geo)
.then(() => {
@ -650,7 +649,7 @@ module.exports = (
}
DB.prototype.pruneSessionTokens = function (uid, sessionTokens) {
log.trace({ op: 'DB.pruneSessionTokens', uid, tokenCount: sessionTokens.length })
log.trace('DB.pruneSessionTokens', { uid, tokenCount: sessionTokens.length })
if (! this.redis || ! TOKEN_PRUNING_ENABLED || ! features.isLastAccessTimeEnabledForUser(uid)) {
return P.resolve()
@ -681,7 +680,7 @@ module.exports = (
SAFE_URLS.device = new SafeUrl('/account/:uid/device/:deviceId', 'db.device')
DB.prototype.device = function (uid, deviceId) {
log.trace({ op: 'DB.device', uid: uid, id: deviceId })
log.trace('DB.device', { uid: uid, id: deviceId })
const promises = [
this.pool.get(SAFE_URLS.device, { uid, deviceId })
@ -716,7 +715,7 @@ module.exports = (
SAFE_URLS.createDevice = new SafeUrl('/account/:uid/device/:id', 'db.createDevice')
DB.prototype.createDevice = function (uid, sessionTokenId, deviceInfo) {
log.trace({ op: 'DB.createDevice', uid: uid, id: deviceInfo.id })
log.trace('DB.createDevice', { uid: uid, id: deviceInfo.id })
return random.hex(16)
.then(id => {
@ -780,7 +779,7 @@ module.exports = (
SAFE_URLS.updateDevice = new SafeUrl('/account/:uid/device/:id/update', 'db.updateDevice')
DB.prototype.updateDevice = function (uid, sessionTokenId, deviceInfo) {
const { id } = deviceInfo
log.trace({ op: 'DB.updateDevice', uid, id })
log.trace('DB.updateDevice', { uid, id })
return this.pool.post(
SAFE_URLS.updateDevice,
{ uid, id },
@ -827,7 +826,7 @@ module.exports = (
DB.prototype.deleteAccount = function (authToken) {
const { uid } = authToken
log.trace({ op: 'DB.deleteAccount', uid })
log.trace('DB.deleteAccount', { uid })
return P.resolve()
.then(() => {
@ -842,7 +841,7 @@ module.exports = (
DB.prototype.deleteSessionToken = function (sessionToken) {
const { id, uid } = sessionToken
log.trace({ op: 'DB.deleteSessionToken', id, uid })
log.trace('DB.deleteSessionToken', { id, uid })
return this.deleteSessionTokenFromRedis(uid, id)
.then(() => this.pool.del(SAFE_URLS.deleteSessionToken, { id }))
@ -851,7 +850,7 @@ module.exports = (
SAFE_URLS.deleteKeyFetchToken = new SafeUrl('/keyFetchToken/:id', 'db.deleteKeyFetchToken')
DB.prototype.deleteKeyFetchToken = function (keyFetchToken) {
const { id, uid } = keyFetchToken
log.trace({ op: 'DB.deleteKeyFetchToken', id, uid })
log.trace('DB.deleteKeyFetchToken', { id, uid })
return this.pool.del(SAFE_URLS.deleteKeyFetchToken, { id })
}
@ -861,7 +860,7 @@ module.exports = (
)
DB.prototype.deleteAccountResetToken = function (accountResetToken) {
const { id, uid } = accountResetToken
log.trace({ op: 'DB.deleteAccountResetToken', id, uid })
log.trace('DB.deleteAccountResetToken', { id, uid })
return this.pool.del(SAFE_URLS.deleteAccountResetToken, { id })
}
@ -871,7 +870,7 @@ module.exports = (
)
DB.prototype.deletePasswordForgotToken = function (passwordForgotToken) {
const { id, uid } = passwordForgotToken
log.trace({ op: 'DB.deletePasswordForgotToken', id, uid })
log.trace('DB.deletePasswordForgotToken', { id, uid })
return this.pool.del(SAFE_URLS.deletePasswordForgotToken, { id })
}
@ -881,13 +880,13 @@ module.exports = (
)
DB.prototype.deletePasswordChangeToken = function (passwordChangeToken) {
const { id, uid } = passwordChangeToken
log.trace({ op: 'DB.deletePasswordChangeToken', id, uid })
log.trace('DB.deletePasswordChangeToken', { id, uid })
return this.pool.del(SAFE_URLS.deletePasswordChangeToken, { id })
}
SAFE_URLS.deleteDevice = new SafeUrl('/account/:uid/device/:deviceId', 'db.deleteDevice')
DB.prototype.deleteDevice = function (uid, deviceId) {
log.trace({ op: 'DB.deleteDevice', uid, id: deviceId })
log.trace('DB.deleteDevice', { uid, id: deviceId })
return this.pool.del(SAFE_URLS.deleteDevice, { uid, deviceId })
.then(result => this.deleteSessionTokenFromRedis(uid, result.sessionTokenId))
@ -904,7 +903,7 @@ module.exports = (
'db.deviceFromTokenVerificationId'
)
DB.prototype.deviceFromTokenVerificationId = function (uid, tokenVerificationId) {
log.trace({ op: 'DB.deviceFromTokenVerificationId', uid, tokenVerificationId })
log.trace('DB.deviceFromTokenVerificationId', { uid, tokenVerificationId })
return this.pool.get(SAFE_URLS.deviceFromTokenVerificationId, { uid, tokenVerificationId })
.catch(err => {
if (isNotFoundError(err)) {
@ -920,7 +919,7 @@ module.exports = (
DB.prototype.resetAccount = function (accountResetToken, data) {
const { uid } = accountResetToken
log.trace({ op: 'DB.resetAccount', uid })
log.trace('DB.resetAccount', { uid })
return P.resolve()
.then(() => {
@ -937,13 +936,13 @@ module.exports = (
SAFE_URLS.verifyEmail = new SafeUrl('/account/:uid/verifyEmail/:emailCode', 'db.verifyEmail')
DB.prototype.verifyEmail = function (account, emailCode) {
const { uid } = account
log.trace({ op: 'DB.verifyEmail', uid, emailCode })
log.trace('DB.verifyEmail', { uid, emailCode })
return this.pool.post(SAFE_URLS.verifyEmail, { uid, emailCode })
}
SAFE_URLS.verifyTokens = new SafeUrl('/tokens/:tokenVerificationId/verify', 'db.verifyTokens')
DB.prototype.verifyTokens = function (tokenVerificationId, accountData) {
log.trace({ op: 'DB.verifyTokens', tokenVerificationId })
log.trace('DB.verifyTokens', { tokenVerificationId })
return this.pool.post(
SAFE_URLS.verifyTokens,
{ tokenVerificationId },
@ -967,7 +966,7 @@ module.exports = (
'db.verifyTokensWithMethod'
)
DB.prototype.verifyTokensWithMethod = function (tokenId, verificationMethod) {
log.trace({op: 'DB.verifyTokensWithMethod', tokenId, verificationMethod})
log.trace('DB.verifyTokensWithMethod', { tokenId, verificationMethod})
return this.pool.post(
SAFE_URLS.verifyTokensWithMethod,
{ tokenId },
@ -977,7 +976,7 @@ module.exports = (
SAFE_URLS.verifyTokenCode = new SafeUrl('/tokens/:code/verifyCode', 'db.verifyTokenCode')
DB.prototype.verifyTokenCode = function (code, accountData) {
log.trace({ op: 'DB.verifyTokenCode', code })
log.trace('DB.verifyTokenCode', { code })
return this.pool.post(
SAFE_URLS.verifyTokenCode,
{ code },
@ -1004,7 +1003,7 @@ module.exports = (
)
DB.prototype.forgotPasswordVerified = function (passwordForgotToken) {
const { id, uid } = passwordForgotToken
log.trace({ op: 'DB.forgotPasswordVerified', uid })
log.trace('DB.forgotPasswordVerified', { uid })
return AccountResetToken.create({ uid })
.then(
function (accountResetToken) {
@ -1029,7 +1028,7 @@ module.exports = (
SAFE_URLS.updateLocale = new SafeUrl('/account/:uid/locale', 'db.updateLocale')
DB.prototype.updateLocale = function (uid, locale) {
log.trace({ op: 'DB.updateLocale', uid, locale })
log.trace('DB.updateLocale', { uid, locale })
return this.pool.post(
SAFE_URLS.updateLocale,
{ uid },
@ -1039,8 +1038,7 @@ module.exports = (
SAFE_URLS.securityEvent = new SafeUrl('/securityEvents', 'db.securityEvent')
DB.prototype.securityEvent = function (event) {
log.trace({
op: 'DB.securityEvent',
log.trace('DB.securityEvent', {
securityEvent: event
})
@ -1049,8 +1047,7 @@ module.exports = (
SAFE_URLS.securityEvents = new SafeUrl('/securityEvents/:uid/ip/:ipAddr', 'db.securityEvents')
DB.prototype.securityEvents = function (params) {
log.trace({
op: 'DB.securityEvents',
log.trace('DB.securityEvents', {
params: params
})
const { ipAddr, uid } = params
@ -1059,7 +1056,7 @@ module.exports = (
SAFE_URLS.createUnblockCode = new SafeUrl('/account/:uid/unblock/:unblock', 'db.createUnblockCode')
DB.prototype.createUnblockCode = function (uid) {
log.trace({ op: 'DB.createUnblockCode', uid })
log.trace('DB.createUnblockCode', { uid })
return UnblockCode()
.then(
(unblock) => {
@ -1072,8 +1069,7 @@ module.exports = (
// duplicates should be super rare, but it's feasible that a
// uid already has an existing unblockCode. Just try again.
if (isRecordAlreadyExistsError(err)) {
log.error({
op: 'DB.createUnblockCode.duplicate',
log.error('DB.createUnblockCode.duplicate', {
err: err,
uid: uid
})
@ -1088,7 +1084,7 @@ module.exports = (
SAFE_URLS.consumeUnblockCode = new SafeUrl('/account/:uid/unblock/:code', 'db.consumeUnblockCode')
DB.prototype.consumeUnblockCode = function (uid, code) {
log.trace({ op: 'DB.consumeUnblockCode', uid })
log.trace('DB.consumeUnblockCode', { uid })
return this.pool.del(SAFE_URLS.consumeUnblockCode, { uid, code })
.catch(
function (err) {
@ -1102,8 +1098,7 @@ module.exports = (
SAFE_URLS.createEmailBounce = new SafeUrl('/emailBounces', 'db.createEmailBounce')
DB.prototype.createEmailBounce = function (bounceData) {
log.trace({
op: 'DB.createEmailBounce',
log.trace('DB.createEmailBounce', {
bouceData: bounceData
})
@ -1112,21 +1107,21 @@ module.exports = (
SAFE_URLS.emailBounces = new SafeUrl('/emailBounces/:email', 'db.emailBounces')
DB.prototype.emailBounces = function (email) {
log.trace({ op: 'DB.emailBounces', email })
log.trace('DB.emailBounces', { email })
return this.pool.get(SAFE_URLS.emailBounces, { email: hexEncode(email) })
}
SAFE_URLS.accountEmails = new SafeUrl('/account/:uid/emails', 'db.accountEmails')
DB.prototype.accountEmails = function (uid) {
log.trace({ op: 'DB.accountEmails', uid })
log.trace('DB.accountEmails', { uid })
return this.pool.get(SAFE_URLS.accountEmails, { uid })
}
SAFE_URLS.getSecondaryEmail = new SafeUrl('/email/:email', 'db.getSecondaryEmail')
DB.prototype.getSecondaryEmail = function (email) {
log.trace({ op: 'DB.getSecondaryEmail', email })
log.trace('DB.getSecondaryEmail', { email })
return this.pool.get(SAFE_URLS.getSecondaryEmail, { email: hexEncode(email) })
.catch((err) => {
@ -1139,9 +1134,8 @@ module.exports = (
SAFE_URLS.createEmail = new SafeUrl('/account/:uid/emails', 'db.createEmail')
DB.prototype.createEmail = function (uid, emailData) {
log.trace({
log.trace('DB.createEmail', {
email: emailData.email,
op: 'DB.createEmail',
uid
})
@ -1158,7 +1152,7 @@ module.exports = (
SAFE_URLS.deleteEmail = new SafeUrl('/account/:uid/emails/:email', 'db.deleteEmail')
DB.prototype.deleteEmail = function (uid, email) {
log.trace({ op: 'DB.deleteEmail', uid })
log.trace('DB.deleteEmail', { uid })
return this.pool.del(SAFE_URLS.deleteEmail, { uid, email: hexEncode(email) })
.catch(
@ -1173,7 +1167,7 @@ module.exports = (
SAFE_URLS.createSigninCode = new SafeUrl('/signinCodes/:code', 'db.createSigninCode')
DB.prototype.createSigninCode = function (uid, flowId) {
log.trace({ op: 'DB.createSigninCode' })
log.trace('DB.createSigninCode')
return random.hex(config.signinCodeSize)
.then(code => {
@ -1181,7 +1175,7 @@ module.exports = (
return this.pool.put(SAFE_URLS.createSigninCode, { code }, data)
.then(() => code, err => {
if (isRecordAlreadyExistsError(err)) {
log.warn({ op: 'DB.createSigninCode.duplicate' })
log.warn('DB.createSigninCode.duplicate')
return this.createSigninCode(uid)
}
@ -1192,7 +1186,7 @@ module.exports = (
SAFE_URLS.consumeSigninCode = new SafeUrl('/signinCodes/:code/consume', 'db.consumeSigninCode')
DB.prototype.consumeSigninCode = function (code) {
log.trace({ op: 'DB.consumeSigninCode', code })
log.trace('DB.consumeSigninCode', { code })
return this.pool.post(SAFE_URLS.consumeSigninCode, { code })
.catch(err => {
@ -1206,14 +1200,14 @@ module.exports = (
SAFE_URLS.resetAccountTokens = new SafeUrl('/account/:uid/resetTokens', 'db.resetAccountTokens')
DB.prototype.resetAccountTokens = function (uid) {
log.trace({ op: 'DB.resetAccountTokens', uid })
log.trace('DB.resetAccountTokens', { uid })
return this.pool.post(SAFE_URLS.resetAccountTokens, { uid })
}
SAFE_URLS.createTotpToken = new SafeUrl('/totp/:uid', 'db.createTotpToken')
DB.prototype.createTotpToken = function (uid, sharedSecret, epoch) {
log.trace({op: 'DB.createTotpToken', uid})
log.trace('DB.createTotpToken', { uid})
return this.pool.put(SAFE_URLS.createTotpToken, { uid }, {
sharedSecret: sharedSecret,
@ -1229,7 +1223,7 @@ module.exports = (
SAFE_URLS.totpToken = new SafeUrl('/totp/:uid', 'db.totpToken')
DB.prototype.totpToken = function (uid) {
log.trace({ op: 'DB.totpToken', uid})
log.trace('DB.totpToken', { uid})
return this.pool.get(SAFE_URLS.totpToken, { uid })
.catch(err => {
@ -1242,7 +1236,7 @@ module.exports = (
SAFE_URLS.deleteTotpToken = new SafeUrl('/totp/:uid', 'db.deleteTotpToken')
DB.prototype.deleteTotpToken = function (uid) {
log.trace({ op: 'DB.deleteTotpToken', uid})
log.trace('DB.deleteTotpToken', { uid})
return this.pool.del(SAFE_URLS.deleteTotpToken, { uid })
.catch(err => {
@ -1255,7 +1249,7 @@ module.exports = (
SAFE_URLS.updateTotpToken = new SafeUrl('/totp/:uid/update', 'db.updateTotpToken')
DB.prototype.updateTotpToken = function (uid, data) {
log.trace({ op: 'DB.updateTotpToken', uid, data})
log.trace('DB.updateTotpToken', { uid, data})
return this.pool.post(SAFE_URLS.updateTotpToken, { uid }, {
verified: data.verified,
@ -1274,7 +1268,7 @@ module.exports = (
'db.replaceRecoveryCodes'
)
DB.prototype.replaceRecoveryCodes = function (uid, count) {
log.trace({op: 'DB.replaceRecoveryCodes', uid})
log.trace('DB.replaceRecoveryCodes', { uid})
return this.pool.post(SAFE_URLS.replaceRecoveryCodes, { uid }, { count })
}
@ -1284,7 +1278,7 @@ module.exports = (
'db.consumeRecoveryCode'
)
DB.prototype.consumeRecoveryCode = function (uid, code) {
log.trace({op: 'DB.consumeRecoveryCode', uid})
log.trace('DB.consumeRecoveryCode', { uid})
return this.pool.post(SAFE_URLS.consumeRecoveryCode, { uid, code })
.catch((err) => {
@ -1300,7 +1294,7 @@ module.exports = (
'db.createRecoveryKey'
)
DB.prototype.createRecoveryKey = function (uid, recoveryKeyId, recoveryData) {
log.trace({op: 'DB.createRecoveryKey', uid})
log.trace('DB.createRecoveryKey', { uid})
return this.pool.post(SAFE_URLS.createRecoveryKey, { uid }, { recoveryKeyId, recoveryData })
.catch((err) => {
@ -1317,7 +1311,7 @@ module.exports = (
'db.getRecoveryKey'
)
DB.prototype.getRecoveryKey = function (uid, recoveryKeyId) {
log.trace({op: 'DB.getRecoveryKey', uid})
log.trace('DB.getRecoveryKey', { uid})
return this.pool.get(SAFE_URLS.getRecoveryKey, {uid, recoveryKeyId})
.catch(err => {
@ -1338,7 +1332,7 @@ module.exports = (
'db.recoveryKeyExists'
)
DB.prototype.recoveryKeyExists = function (uid) {
log.trace({op: 'DB.recoveryKeyExists', uid})
log.trace('DB.recoveryKeyExists', { uid})
return this.pool.get(SAFE_URLS.recoveryKeyExists, {uid})
}
@ -1348,7 +1342,7 @@ module.exports = (
'db.deleteRecoveryKey'
)
DB.prototype.deleteRecoveryKey = function (uid) {
log.trace({op: 'DB.deleteRecoveryKey', uid})
log.trace('DB.deleteRecoveryKey', { uid})
return this.pool.del(SAFE_URLS.deleteRecoveryKey, { uid })
}
@ -1356,7 +1350,7 @@ module.exports = (
DB.prototype.safeRedisGet = function (key) {
return this.redis.get(key)
.catch(err => {
log.error({ op: 'redis.get.error', key, err: err.message })
log.error('redis.get.error', { key, err: err.message })
// Allow callers to distinguish between the null result and connection errors
return false
})
@ -1373,7 +1367,7 @@ module.exports = (
return P.resolve()
.then(() => unpackTokensFromRedis(tokens))
.catch(err => {
log.error({ op: 'db.unpackTokensFromRedis.error', err: err.message })
log.error('db.unpackTokensFromRedis.error', { err: err.message })
if (err instanceof SyntaxError) {
return this.redis.del(uid)

Просмотреть файл

@ -113,8 +113,7 @@ module.exports = (log, db, push) => {
})
}
if (isPlaceholderDevice) {
log.info({
op: 'device:createPlaceholder',
log.info('device:createPlaceholder', {
uid: sessionToken.uid,
id: result.id
})

Просмотреть файл

@ -15,11 +15,11 @@ module.exports = function (log, error) {
return function start(bounceQueue, db) {
function accountDeleted(uid, email) {
log.info({ op: 'accountDeleted', uid: uid, email: email })
log.info('accountDeleted', { uid: uid, email: email })
}
function gotError(email, err) {
log.error({ op: 'databaseError', email: email, err: err })
log.error('databaseError', { email: email, err: err })
}
function findEmailRecord(email) {
@ -77,8 +77,7 @@ module.exports = function (log, error) {
// We couldn't make the recipient address look like a valid email.
// Log a warning but don't error out because we still want to
// emit flow metrics etc.
log.warn({
op: 'handleBounce.addressParseFailure',
log.warn('handleBounce.addressParseFailure', {
email: email,
action: recipient.action,
diagnosticCode: recipient.diagnosticCode
@ -87,7 +86,6 @@ module.exports = function (log, error) {
}
const emailDomain = utils.getAnonymizedEmailDomain(email)
const logData = {
op: 'handleBounce',
action: recipient.action,
email: email,
domain: emailDomain,
@ -134,7 +132,7 @@ module.exports = function (log, error) {
// Log the bounced flowEvent and emailEvent metrics
utils.logFlowEventFromMessage(log, message, 'bounced')
utils.logEmailEventFromMessage(log, message, 'bounced', emailDomain)
log.info(logData)
log.info('handleBounce', logData)
/**
* Docs: https://docs.aws.amazon.com/ses/latest/DeveloperGuide/notification-contents.html#bounce-types

Просмотреть файл

@ -30,7 +30,6 @@ module.exports = function (log) {
var email = recipient
var emailDomain = utils.getAnonymizedEmailDomain(email)
var logData = {
op: 'handleDelivery',
email: email,
domain: emailDomain,
processingTimeMillis: message.delivery.processingTimeMillis
@ -45,7 +44,7 @@ module.exports = function (log) {
utils.logFlowEventFromMessage(log, message, 'delivered')
utils.logEmailEventFromMessage(log, message, 'delivered', emailDomain)
log.info(logData)
log.info('handleDelivery', logData)
}).then(
function () {
// We always delete the message, even if handling some addrs failed.

Просмотреть файл

@ -45,12 +45,12 @@ module.exports = (log, error) => {
// A bounce or complaint on a new unverified account is grounds for deletion
await db.deleteAccount(emailRecord)
log.info({ op: 'accountDeleted', ...emailRecord })
log.info('accountDeleted', { ...emailRecord })
}
}
}))
} catch (err) {
log.error({ op: 'email.notification.error', err })
log.error('email.notification.error', { err })
}
message.del()

Просмотреть файл

@ -67,24 +67,22 @@ function logErrorIfHeadersAreWeirdOrMissing (log, message, origin) {
const deviceId = getHeaderValue('X-Device-Id', message)
const uid = getHeaderValue('X-Uid', message)
if (! deviceId && ! uid) {
log.warn({
op: 'emailHeaders.keys',
log.warn('emailHeaders.keys', {
keys: Object.keys(headers).join(','),
template: getHeaderValue('X-Template-Name', message),
origin
})
}
} else {
log.error({ op: 'emailHeaders.weird', type, origin })
log.error('emailHeaders.weird', { type, origin })
}
} else {
log.error({ op: 'emailHeaders.missing', origin })
log.error('emailHeaders.missing', { origin })
}
}
function logEmailEventSent(log, message) {
const emailEventInfo = {
op: 'emailEvent',
template: message.template,
templateVersion: message.templateVersion,
type: 'sent',
@ -98,7 +96,7 @@ function logEmailEventSent(log, message) {
addrs.forEach(addr => {
const msg = Object.assign({}, emailEventInfo)
msg.domain = getAnonymizedEmailDomain(addr)
log.info(msg)
log.info('emailEvent', msg)
})
logAmplitudeEvent(log, message, Object.assign({
@ -147,7 +145,6 @@ function logEmailEventFromMessage(log, message, type, emailDomain) {
const emailEventInfo = {
domain: emailDomain,
locale,
op: 'emailEvent',
template: templateName,
templateVersion,
type
@ -165,7 +162,7 @@ function logEmailEventFromMessage(log, message, type, emailDomain) {
emailEventInfo.complaint = true
}
log.info(emailEventInfo)
log.info('emailEvent', emailEventInfo)
logAmplitudeEvent(log, message, emailEventInfo)
}
@ -193,7 +190,7 @@ function logFlowEventFromMessage(log, message, type) {
log.flowEvent(flowEventInfo)
} else {
log.error({ op: 'handleBounce.flowEvent', templateName, type, flowId, flowBeginTime, currentTime})
log.error('handleBounce.flowEvent', { templateName, type, flowId, flowBeginTime, currentTime})
}
}

Просмотреть файл

@ -15,7 +15,7 @@ const ACCURACY_MIN_KM = 25
* `location` data. On failure, returns an empty object
**/
module.exports = log => {
log.info({ op: 'geodb.start', enabled: config.enabled, dbPath: config.dbPath })
log.info('geodb.start', { enabled: config.enabled, dbPath: config.dbPath })
return ip => {
if (config.enabled === false) {
@ -37,8 +37,8 @@ module.exports = log => {
confidence += 'no_accuracy_data'
}
log.info({ op: 'geodb.accuracy', accuracy })
log.info({ op: 'geodb.accuracy_confidence', accuracy_confidence: confidence })
log.info('geodb.accuracy', { accuracy })
log.info('geodb.accuracy_confidence', { accuracy_confidence: confidence })
return {
location: {
@ -51,7 +51,7 @@ module.exports = log => {
timeZone: location.timeZone
}
} catch (err) {
log.error({ op: 'geodb.1', err: err.message })
log.error('geodb.1', { err: err.message })
return {}
}
}

Просмотреть файл

@ -33,11 +33,11 @@ Lug.prototype.close = function() {
// Expose the standard error/warn/info/debug/etc log methods.
Lug.prototype.trace = function (data) {
this.logger.debug(data.op, data)
Lug.prototype.trace = function (op, data) {
this.logger.debug(op, data)
}
Lug.prototype.error = function (data) {
Lug.prototype.error = function (op, data) {
// If the error object contains an email address,
// lift it into top-level fields so that our
// PII-scrubbing tool is able to find it.
@ -47,19 +47,19 @@ Lug.prototype.error = function (data) {
}
data.err.email = null
}
this.logger.error(data.op, data)
this.logger.error(op, data)
}
Lug.prototype.fatal = function (data) {
this.logger.critical(data.op, data)
Lug.prototype.fatal = function (op, data) {
this.logger.critical(op, data)
}
Lug.prototype.warn = function (data) {
this.logger.warn(data.op, data)
Lug.prototype.warn = function (op, data) {
this.logger.warn(op, data)
}
Lug.prototype.info = function (data) {
this.logger.info(data.op, data)
Lug.prototype.info = function (op, data) {
this.logger.info(op, data)
}
Lug.prototype.begin = function (op, request) {
@ -88,7 +88,6 @@ Lug.prototype.summary = function (request, response) {
const responseBody = (response && response.source) || {}
const line = {
op: 'request.summary',
status: (response.isBoom) ? response.output.statusCode : response.statusCode,
errno: response.errno || 0,
rid: request.id,
@ -116,10 +115,10 @@ Lug.prototype.summary = function (request, response) {
if (line.status >= 500) {
line.trace = request.app.traced
line.stack = response.stack
this.error(line, response.message)
this.error('request.summary', line, response.message)
}
else {
this.info(line)
this.info('request.summary', line)
}
}
@ -149,7 +148,7 @@ Lug.prototype.notifyAttachedServices = function (name, request, data) {
Lug.prototype.activityEvent = function (data) {
if (! data || ! data.event || ! data.uid) {
this.error({ op: 'log.activityEvent', data: data })
this.error('log.activityEvent', { data })
return
}
@ -161,7 +160,7 @@ Lug.prototype.activityEvent = function (data) {
Lug.prototype.flowEvent = function (data) {
if (! data || ! data.event || ! data.flow_id || ! data.flow_time || ! data.time) {
this.error({ op: 'flow.missingData', data })
this.error('flow.missingData', { data })
return
}
@ -170,7 +169,7 @@ Lug.prototype.flowEvent = function (data) {
Lug.prototype.amplitudeEvent = function (data) {
if (! data || ! data.event_type || (! data.device_id && ! data.user_id)) {
this.error({ op: 'amplitude.missingData', data })
this.error('amplitude.missingData', { data })
return
}

Просмотреть файл

@ -111,7 +111,7 @@ module.exports = (log, config) => {
function receiveEvent (event, request, data = {}, metricsContext = {}) {
if (! event || ! request) {
log.error({ op: 'amplitude.badArgument', err: 'Bad argument', event, hasRequest: !! request })
log.error('amplitude.badArgument', { err: 'Bad argument', event, hasRequest: !! request })
return P.resolve()
}

Просмотреть файл

@ -73,10 +73,9 @@ module.exports = function (log, config) {
return P.resolve()
.then(() => {
return cache.add(getKey(token), metadata)
.catch(err => log.warn({ op: 'metricsContext.stash.add', err }))
.catch(err => log.warn('metricsContext.stash.add', { err }))
})
.catch(err => log.error({
op: 'metricsContext.stash',
.catch(err => log.error('metricsContext.stash', {
err,
hasToken: !! token,
hasId: !! (token && token.id),
@ -111,8 +110,7 @@ module.exports = function (log, config) {
return await cache.get(getKey(token)) || {}
}
} catch (err) {
log.error({
op: 'metricsContext.get',
log.error('metricsContext.get', {
err,
hasToken: !! token,
hasId: !! (token && token.id),
@ -191,11 +189,10 @@ module.exports = function (log, config) {
.then(metadata => {
if (metadata) {
return cache.add(getKey(newToken), metadata)
.catch(err => log.warn({ op: 'metricsContext.propagate.add', err }))
.catch(err => log.warn('metricsContext.propagate.add', { err }))
}
})
.catch(err => log.error({
op: 'metricsContext.propagate',
.catch(err => log.error('metricsContext.propagate', {
err,
hasOldToken: !! oldToken,
hasOldTokenId: !! (oldToken && oldToken.id),
@ -267,8 +264,7 @@ module.exports = function (log, config) {
return logInvalidContext(this, 'invalid signature')
}
log.info({
op: 'metrics.context.validate',
log.info('metrics.context.validate', {
valid: true
})
return true
@ -279,8 +275,7 @@ module.exports = function (log, config) {
delete request.payload.metricsContext.flowId
delete request.payload.metricsContext.flowBeginTime
}
log.warn({
op: 'metrics.context.validate',
log.warn('metrics.context.validate', {
valid: false,
reason: reason
})

Просмотреть файл

@ -77,7 +77,7 @@ module.exports = (log, config) => {
*/
emit (event, data) {
if (! event) {
log.error({ op: 'metricsEvents.emit', missingEvent: true })
log.error('metricsEvents.emit', { missingEvent: true })
return P.resolve()
}
@ -175,7 +175,7 @@ module.exports = (log, config) => {
function emitFlowEvent (event, request, optionalData) {
if (! request || ! request.headers) {
log.error({ op: 'metricsEvents.emitFlowEvent', event, badRequest: true })
log.error('metricsEvents.emitFlowEvent', { event, badRequest: true })
return P.resolve()
}
@ -195,7 +195,7 @@ module.exports = (log, config) => {
log.flowEvent(data)
} else if (! OPTIONAL_FLOW_EVENTS[event]) {
log.error({ op: 'metricsEvents.emitFlowEvent', event, missingFlowId: true })
log.error('metricsEvents.emitFlowEvent', { event, missingFlowId: true })
}
return data

Просмотреть файл

@ -55,9 +55,9 @@ module.exports = function notifierLog(log) {
MessageAttributes: formatMessageAttributes(msg)
}, (err, data) => {
if (err) {
log.error({op: 'Notifier.publish', err: err})
log.error('Notifier.publish', { err: err})
} else {
log.trace({op: 'Notifier.publish', success: true, data: data})
log.trace('Notifier.publish', { success: true, data: data})
}
if (callback) {

Просмотреть файл

@ -26,8 +26,7 @@ module.exports = {
case 119:
return error.staleAuthAt(err.authAt)
default:
log.warn({
op: 'oauthdb.mapOAuthError',
log.warn('oauthdb.mapOAuthError', {
err: err,
errno: err.errno,
warning: 'unmapped oauth-server errno'

Просмотреть файл

@ -11,13 +11,13 @@ module.exports = function (log) {
function handleProfileUpdated(message) {
const uid = message && message.uid
log.info({ op: 'handleProfileUpdated', uid, action: 'notify' })
log.info('handleProfileUpdated', { uid, action: 'notify' })
return db.devices(uid)
.then(devices => push.notifyProfileUpdated(uid, devices))
.catch(err => log.error({ op: 'handleProfileUpdated', uid, action: 'error', err, stack: err && err.stack }))
.catch(err => log.error('handleProfileUpdated', { uid, action: 'error', err, stack: err && err.stack }))
.then(() => {
log.info({ op: 'handleProfileUpdated', uid, action: 'delete' })
log.info('handleProfileUpdated', { uid, action: 'delete' })
// We always delete the message, we are not really mission critical
message.del()
})

Просмотреть файл

@ -81,8 +81,7 @@ module.exports = function (log, db, config) {
* @param {String} deviceId
*/
function reportPushError(err, uid, deviceId) {
log.error({
op: LOG_OP_PUSH_TO_DEVICES,
log.error(LOG_OP_PUSH_TO_DEVICES, {
uid: uid,
deviceId: deviceId,
err: err
@ -96,8 +95,7 @@ module.exports = function (log, db, config) {
*/
function incrementPushAction(name) {
if (name) {
log.info({
op: LOG_OP_PUSH_TO_DEVICES,
log.info(LOG_OP_PUSH_TO_DEVICES, {
name: name
})
}
@ -142,8 +140,7 @@ module.exports = function (log, db, config) {
const deviceVersion = device.uaBrowserVersion ? parseFloat(device.uaBrowserVersion) : 0
const deviceBrowserName = device.uaBrowser
if (! canSendToIOSVersion(deviceVersion, deviceBrowserName)) {
log.info({
op: 'push.filteredUnsupportedDevice',
log.info('push.filteredUnsupportedDevice', {
command: command,
uaOS: device.uaOS,
uaBrowserVersion: device.uaBrowserVersion
@ -179,8 +176,7 @@ module.exports = function (log, db, config) {
dummyCurve.computeSecret(base64url.toBuffer(publicKey))
return true
} catch (err) {
log.info({
op: 'push.isValidPublicKey',
log.info('push.isValidPublicKey', {
name: 'Bad public key detected'
})
// However! The above call might have left some junk
@ -377,8 +373,7 @@ module.exports = function (log, db, config) {
return P.each(devices, function(device) {
var deviceId = device.id
log.trace({
op: LOG_OP_PUSH_TO_DEVICES,
log.trace(LOG_OP_PUSH_TO_DEVICES, {
uid: uid,
deviceId: deviceId,
pushCallback: device.pushCallback

Просмотреть файл

@ -130,9 +130,9 @@ module.exports = function (log, config) {
query.index = index.toString()
}
const body = await api.retrieve(uid, deviceId, query)
log.info({ op: 'pushbox.retrieve.response', body: body })
log.info('pushbox.retrieve.response', { body: body })
if (body.error) {
log.error({ op: 'pushbox.retrieve', status: body.status, error: body.error })
log.error('pushbox.retrieve', { status: body.status, error: body.error })
throw error.backendServiceFailure()
}
return {
@ -163,9 +163,9 @@ module.exports = function (log, config) {
ttl = maxTTL
}
const body = await api.store(uid, deviceId, {data: encodeForStorage(data), ttl})
log.info({ op: 'pushbox.store.response', body: body })
log.info('pushbox.store.response', { body: body })
if (body.error) {
log.error({ op: 'pushbox.store', status: body.status, error: body.error })
log.error('pushbox.store', { status: body.status, error: body.error })
throw error.backendServiceFailure()
}
return body

Просмотреть файл

@ -39,7 +39,7 @@ module.exports = (log, client) => {
*/
update (key, getUpdatedValue) {
if (isUpdating) {
log.error({ op: 'redis.update.conflict', key })
log.error('redis.update.conflict', { key })
return P.reject(error.unexpectedError())
}
@ -61,7 +61,7 @@ module.exports = (log, client) => {
})
.catch(err => {
client.unwatch()
log.error({ op: 'redis.update.error', key, err: err.message })
log.error('redis.update.error', { key, err: err.message })
isUpdating = false
throw err
})
@ -70,7 +70,7 @@ module.exports = (log, client) => {
if (! result) {
// Really this isn't an error as such, it just indicates that
// this function is operating sanely in concurrent conditions.
log.warn({ op: 'redis.watch.conflict', key })
log.warn('redis.watch.conflict', { key })
throw error.unexpectedError()
}
})

Просмотреть файл

@ -52,11 +52,11 @@ const REDIS_COMMANDS = [ 'get', 'set', 'del', 'update' ]
module.exports = (config, log) => {
if (! config.enabled) {
log.info({ op: 'redis.disabled' })
log.info('redis.disabled')
return
}
log.info({ op: 'redis.enabled', config })
log.info('redis.enabled', { config })
const pool = require('./pool')(config, log)

Просмотреть файл

@ -50,7 +50,7 @@ module.exports = (config, log) => {
})
client.on('error', err => {
log.error({ op: 'redis.error', err: err.message })
log.error('redis.error', { err: err.message })
})
})
},
@ -80,7 +80,7 @@ module.exports = (config, log) => {
testOnBorrow: true
})
pool.on('factoryCreateError', err => log.error({ op: 'redisFactory.error', err: err.message }))
pool.on('factoryCreateError', err => log.error('redisFactory.error', { err: err.message }))
return {
/**

Просмотреть файл

@ -102,7 +102,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
}
request.app.accountRecreated = true
return db.deleteAccount(secondaryEmailRecord)
.then(() => log.info({ op: 'accountDeleted.unverifiedSecondaryEmail', ...secondaryEmailRecord }))
.then(() => log.info('accountDeleted.unverifiedSecondaryEmail', { ...secondaryEmailRecord }))
} else {
if (secondaryEmailRecord.isVerified) {
throw error.verifiedSecondaryEmailAlreadyExists()
@ -154,8 +154,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
if (! locale) {
// We're seeing a surprising number of accounts created
// without a proper locale. Log details to help debug this.
log.info({
op: 'account.create.emptyLocale',
log.info('account.create.emptyLocale', {
email: email,
locale: locale,
agent: userAgentString
@ -287,20 +286,18 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
.then(function () {
if (tokenVerificationId) {
// Log server-side metrics for confirming verification rates
log.info({
op: 'account.create.confirm.start',
log.info('account.create.confirm.start', {
uid: account.uid,
tokenVerificationId: tokenVerificationId
})
}
})
.catch(function (err) {
log.error({op: 'mailer.sendVerifyCode.1', err: err})
log.error('mailer.sendVerifyCode.1', { err: err})
if (tokenVerificationId) {
// Log possible email bounce, used for confirming verification rates
log.error({
op: 'account.create.confirm.error',
log.error('account.create.confirm.error', {
uid: account.uid,
err: err,
tokenVerificationId: tokenVerificationId
@ -487,15 +484,13 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
coarseRecency = 'old'
}
log.info({
op: 'Account.history.verified',
log.info('Account.history.verified', {
uid: accountRecord.uid,
events: events.length,
recency: coarseRecency
})
} else {
log.info({
op: 'Account.history.unverified',
log.info('Account.history.unverified', {
uid: accountRecord.uid,
events: events.length
})
@ -506,8 +501,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
// Security event history allows some convenience during login,
// but errors here shouldn't fail the entire request.
// so errors shouldn't stop the login attempt
log.error({
op: 'Account.history.error',
log.error('Account.history.error', {
err: err,
uid: accountRecord.uid
})
@ -629,8 +623,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
// verified as well without going through the loop again.
const allowedRecency = config.securityHistory.ipProfiling.allowedRecency || 0
if (securityEventVerified && securityEventRecency < allowedRecency) {
log.info({
op: 'Account.ipprofiling.seenAddress',
log.info('Account.ipprofiling.seenAddress', {
uid: account.uid
})
return true
@ -643,8 +636,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
if (skipForNewAccounts && skipForNewAccounts.enabled) {
const accountAge = requestNow - account.createdAt
if (accountAge <= skipForNewAccounts.maxAge) {
log.info({
op: 'account.signin.confirm.bypass.age',
log.info('account.signin.confirm.bypass.age', {
uid: account.uid
})
return true
@ -657,8 +649,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
const lowerCaseEmail = account.primaryEmail.normalizedEmail.toLowerCase()
const alwaysSkip = skipConfirmationForEmailAddresses && skipConfirmationForEmailAddresses.includes(lowerCaseEmail)
if (alwaysSkip) {
log.info({
op: 'account.signin.confirm.bypass.always',
log.info('account.signin.confirm.bypass.always', {
uid: account.uid
})
return true
@ -705,8 +696,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
} catch (err) {
// If we couldn't email them, no big deal. Log
// and pretend everything worked.
log.trace({
op: 'Account.login.sendNewDeviceLoginNotification.error',
log.trace('Account.login.sendNewDeviceLoginNotification.error', {
error: err
})
}
@ -928,7 +918,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
}
},
handler: async function (request) {
log.error({ op: 'Account.UnlockCodeResend', request: request })
log.error('Account.UnlockCodeResend', { request: request })
throw error.gone()
}
},
@ -941,7 +931,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
}
},
handler: async function (request) {
log.error({ op: 'Account.UnlockCodeVerify', request: request })
log.error('Account.UnlockCodeVerify', { request: request })
throw error.gone()
}
},
@ -1257,7 +1247,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
.then((devices) => {
devicesToNotify = devices
return db.deleteAccount(emailRecord)
.then(() => log.info({ op: 'accountDeleted.byRequest', ...emailRecord }))
.then(() => log.info('accountDeleted.byRequest', { ...emailRecord }))
})
.then(() => {
push.notifyAccountDestroyed(uid, devicesToNotify)
@ -1301,7 +1291,7 @@ module.exports = (log, db, mailer, Password, config, customs, signinUtils, push)
}
},
handler: async function (request) {
log.error({ op: 'Account.lock', request: request })
log.error('Account.lock', { request: request })
throw error.gone()
}
})

Просмотреть файл

@ -88,7 +88,7 @@ module.exports = (log, db) => {
return {}
},
function (err) {
log.error({ op: 'heartbeat', err: err })
log.error('heartbeat', { err: err })
throw error.serviceUnavailable()
}
)

Просмотреть файл

@ -99,8 +99,7 @@ module.exports = (log, db, config, customs, push, pushbox, devices) => {
country: territories.main[language].localeDisplayNames.territories[location.countryCode]
}
} catch (err) {
log.warn({
op: 'devices.marshallLocation.warning',
log.warn('devices.marshallLocation.warning', {
err: err.message,
languages: request.app.acceptLanguage,
language,
@ -279,7 +278,7 @@ module.exports = (log, db, config, customs, push, pushbox, devices) => {
return pushbox.retrieve(uid, deviceId, limit, index)
.then(resp => {
log.info({ op: 'commands.fetch', resp: resp })
log.info('commands.fetch', { resp: resp })
return resp
})
}
@ -402,8 +401,7 @@ module.exports = (log, db, config, customs, push, pushbox, devices) => {
devices = devices.filter(device => include.has(device.id))
if (devices.length === 0) {
log.error({
op: 'Account.devicesNotify',
log.error('Account.devicesNotify', {
uid: uid,
error: 'devices empty'
})
@ -446,8 +444,7 @@ module.exports = (log, db, config, customs, push, pushbox, devices) => {
function catchPushError (err) {
// push may fail due to not found devices or a bad push action
// log the error but still respond with a 200.
log.error({
op: 'Account.devicesNotify',
log.error('Account.devicesNotify', {
uid: uid,
error: err
})

Просмотреть файл

@ -45,8 +45,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
const sessionToken = request.auth.credentials
if (request.query && request.query.reason === 'push') {
// log to the push namespace that account was verified via push
log.info({
op: 'push.pushToDevices',
log.info('push.pushToDevices', {
name: 'recovery_email_reason.push'
})
}
@ -59,8 +58,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
const staleTime = now - config.emailStatusPollingTimeout
if (sessionToken.createdAt < staleTime) {
log.info({
op: 'recovery_email.status.stale',
log.info('recovery_email.status.stale', {
email: sessionToken.email,
createdAt: sessionToken.createdAt,
lifeTime: sessionToken.lifetime,
@ -77,7 +75,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
if (! validators.isValidEmailAddress(sessionToken.email)) {
return db.deleteAccount(sessionToken)
.then(() => {
log.info({ op: 'accountDeleted.invalidEmailAddress', ...sessionToken })
log.info('accountDeleted.invalidEmailAddress', { ...sessionToken })
// Act as though we deleted the account asynchronously
// and caused the sessionToken to become invalid.
throw error.invalidToken('This account was invalid and has been deleted')
@ -329,8 +327,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
const isEmailVerification = emails.some((email) => {
if (email.emailCode && (code === email.emailCode)) {
matchedEmail = email
log.info({
op: 'account.verifyEmail.secondary.started',
log.info('account.verifyEmail.secondary.started', {
uid: uid,
code: request.payload.code
})
@ -346,8 +343,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
// User is attempting to verify a secondary email that has already been verified.
// Silently succeed and don't send post verification email.
if (matchedEmail.isVerified) {
log.info({
op: 'account.verifyEmail.secondary.already-verified',
log.info('account.verifyEmail.secondary.already-verified', {
uid: uid,
code: request.payload.code
})
@ -356,8 +352,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
return db.verifyEmail(account, code)
.then(() => {
log.info({
op: 'account.verifyEmail.secondary.confirmed',
log.info('account.verifyEmail.secondary.confirmed', {
uid: uid,
code: request.payload.code
})
@ -382,8 +377,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
},
err => {
if (err.errno !== error.ERRNO.DEVICE_UNKNOWN) {
log.error({
op: 'Account.RecoveryEmailVerify',
log.error('Account.RecoveryEmailVerify', {
err: err,
uid: uid,
code: code
@ -409,8 +403,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
if (! isAccountVerification) {
// Don't log sign-in confirmation success for the account verification case
log.info({
op: 'account.signin.confirm.success',
log.info('account.signin.confirm.success', {
uid: uid,
code: request.payload.code
})
@ -429,8 +422,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
return
}
log.error({
op: 'account.signin.confirm.invalid',
log.error('account.signin.confirm.invalid', {
uid: uid,
code: request.payload.code,
error: err
@ -592,7 +584,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
const minUnverifiedAccountTime = config.secondaryEmail.minUnverifiedAccountTime
if (msSinceCreated >= minUnverifiedAccountTime) {
return db.deleteAccount(secondaryEmailRecord)
.then(() => log.info({ op: 'accountDeleted.unverifiedSecondaryEmail', ...secondaryEmailRecord }))
.then(() => log.info('accountDeleted.unverifiedSecondaryEmail', { ...secondaryEmailRecord }))
} else {
throw error.unverifiedPrimaryEmailNewlyCreated()
}
@ -640,7 +632,7 @@ module.exports = (log, db, mailer, config, customs, push) => {
uid
})
.catch((err) => {
log.error({op: 'mailer.sendVerifySecondaryEmail', err: err})
log.error('mailer.sendVerifySecondaryEmail', { err: err})
return db.deleteEmail(emailData.uid, emailData.normalizedEmail)
.then(() => {
throw emailUtils.sendError(err, true)

Просмотреть файл

@ -307,8 +307,7 @@ module.exports = function (
.catch(e => {
// If we couldn't email them, no big deal. Log
// and pretend everything worked.
log.trace({
op: 'Password.changeFinish.sendPasswordChangedNotification.error',
log.trace('Password.changeFinish.sendPasswordChangedNotification.error', {
error: e
})
})

Просмотреть файл

@ -77,8 +77,7 @@ module.exports = (log, db, config, customs, mailer) => {
}
function emitMetrics() {
log.info({
op: 'account.recoveryCode.replaced',
log.info('account.recoveryCode.replaced', {
uid: uid
})
@ -131,8 +130,7 @@ module.exports = (log, db, config, customs, mailer) => {
.then((result) => {
remainingRecoveryCodes = result.remaining
if (remainingRecoveryCodes === 0) {
log.info({
op: 'account.recoveryCode.consumedAllCodes',
log.info('account.recoveryCode.consumedAllCodes', {
uid
})
}
@ -165,8 +163,7 @@ module.exports = (log, db, config, customs, mailer) => {
defers.push(sendConsumeEmail)
if (remainingRecoveryCodes <= codeConfig.notifyLowCount) {
log.info({
op: 'account.recoveryCode.notifyLowCount',
log.info('account.recoveryCode.notifyLowCount', {
uid,
remaining: remainingRecoveryCodes
})
@ -182,8 +179,7 @@ module.exports = (log, db, config, customs, mailer) => {
}
function emitMetrics() {
log.info({
op: 'account.recoveryCode.verified',
log.info('account.recoveryCode.verified', {
uid: uid
})

Просмотреть файл

@ -47,8 +47,7 @@ module.exports = (log, db, Password, verifierVersion, customs, mailer) => {
}
function emitMetrics() {
log.info({
op: 'account.recoveryKey.created',
log.info('account.recoveryKey.created', {
uid
})

Просмотреть файл

@ -69,8 +69,7 @@ module.exports = (log, signer, db, domain, devices) => {
// No need to wait for a response, update in the background.
db.touchSessionToken(sessionToken, request.app.geo)
} else {
log.warn({
op: 'signer.updateSessionToken', message: 'no user agent string, session token not updated'
log.warn('signer.updateSessionToken', { message: 'no user agent string, session token not updated'
})
}
@ -139,8 +138,7 @@ module.exports = (log, signer, db, domain, devices) => {
if (! sessionToken.locale) {
if (request.app.acceptLanguage) {
// Log details to sanity-check locale backfilling.
log.info({
op: 'signer.updateLocale',
log.info('signer.updateLocale', {
locale: request.app.acceptLanguage
})
db.updateLocale(sessionToken.uid, request.app.acceptLanguage)
@ -148,8 +146,7 @@ module.exports = (log, signer, db, domain, devices) => {
} else {
// We're seeing a surprising number of accounts that don't get
// a proper locale. Log details to help debug this.
log.info({
op: 'signer.emptyLocale',
log.info('signer.emptyLocale', {
email: sessionToken.email,
locale: request.app.acceptLanguage,
agent: request.headers['user-agent']

Просмотреть файл

@ -131,7 +131,7 @@ module.exports = (log, db, config, customs, sms) => {
if (! country) {
if (! IS_STATUS_GEO_ENABLED) {
log.warn({ op: 'sms.getGeoData', warning: 'skipping geolocation step' })
log.warn('sms.getGeoData', { warning: 'skipping geolocation step' })
return true
}
@ -145,7 +145,7 @@ module.exports = (log, db, config, customs, sms) => {
return REGIONS.has(country)
}
log.error({ op: 'sms.getGeoData', err: 'missing location data' })
log.error('sms.getGeoData', { err: 'missing location data' })
return false
}

Просмотреть файл

@ -55,8 +55,7 @@ module.exports = (log, db, config, customs) => {
return db.verifyTokenCode(code, {uid: uid})
.then(() => {}, (err) => {
if (err.errno === errors.ERRNO.EXPIRED_TOKEN_VERIFICATION_CODE) {
log.error({
op: 'account.token.code.expired',
log.error('account.token.code.expired', {
uid: uid,
err: err
})
@ -66,8 +65,7 @@ module.exports = (log, db, config, customs) => {
}
function emitMetrics() {
log.info({
op: 'account.token.code.verified',
log.info('account.token.code.verified', {
uid: uid
})

Просмотреть файл

@ -93,8 +93,7 @@ module.exports = (log, db, mailer, customs, config) => {
}
function emitMetrics() {
log.info({
op: 'totpToken.created',
log.info('totpToken.created', {
uid: uid
})
return request.emitMetricsEvent('totpToken.created', {uid: uid})
@ -319,14 +318,12 @@ module.exports = (log, db, mailer, customs, config) => {
function emitMetrics() {
if (isValidCode) {
log.info({
op: 'totp.verified',
log.info('totp.verified', {
uid: uid
})
request.emitMetricsEvent('totpToken.verified', {uid: uid})
} else {
log.info({
op: 'totp.unverified',
log.info('totp.unverified', {
uid: uid
})
request.emitMetricsEvent('totpToken.unverified', {uid: uid})

Просмотреть файл

@ -104,7 +104,7 @@ module.exports = (log, db, mailer, config, customs) => {
return db.consumeUnblockCode(uid, code)
.then(() => {
log.info({ op: 'account.login.rejectedUnblockCode', uid, unblockCode: code })
log.info('account.login.rejectedUnblockCode', { uid, unblockCode: code })
return {}
})
}

Просмотреть файл

@ -121,8 +121,7 @@ module.exports = (log, config, customs, db, mailer) => {
accountRecord = result
return db.consumeUnblockCode(accountRecord.uid, unblockCode).then(code => {
if (Date.now() - code.createdAt > unblockCodeLifetime) {
log.info({
op: 'Account.login.unblockCode.expired',
log.info('Account.login.unblockCode.expired', {
uid: accountRecord.uid
})
throw error.invalidUnblockCode()
@ -229,8 +228,7 @@ module.exports = (log, config, customs, db, mailer) => {
// There's no spec-compliant way to error out
// as a result of having too many active sessions.
// For now, just log metrics about it.
log.error({
op: 'Account.login',
log.error('Account.login', {
uid: accountRecord.uid,
userAgent: request.headers['user-agent'],
numSessions: sessions.length
@ -318,8 +316,7 @@ module.exports = (log, config, customs, db, mailer) => {
}
function sendVerifyLoginEmail() {
log.info({
op: 'account.signin.confirm.start',
log.info('account.signin.confirm.start', {
uid: accountRecord.uid,
tokenVerificationId: sessionToken.tokenVerificationId
})
@ -350,15 +347,14 @@ module.exports = (log, config, customs, db, mailer) => {
)
.then(() => request.emitMetricsEvent('email.confirmation.sent'))
.catch(err => {
log.error({ op: 'mailer.confirmation.error', err })
log.error('mailer.confirmation.error', { err })
throw emailUtils.sendError(err, isUnverifiedAccount)
})
}
function sendVerifyLoginCodeEmail() {
log.info({
op: 'account.token.code.start',
log.info('account.token.code.start', {
uid: accountRecord.uid
})

Просмотреть файл

@ -86,7 +86,7 @@ module.exports = log => class SafeUrl {
}
_fail (op, data) {
log.error(Object.assign({ op, caller: this._caller }, data))
log.error(op, Object.assign({ caller: this._caller }, data))
throw error.internalValidationError(op, data)
}
}

Просмотреть файл

@ -266,13 +266,13 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.send = function (message) {
log.trace({ op: 'mailer.' + message.template, email: message.email, uid: message.uid })
log.trace(`mailer.${message.template}`, { email: message.email, uid: message.uid })
const localized = this.localize(message)
const template = message.template
let templateVersion = TEMPLATE_VERSIONS[template]
if (! templateVersion) {
log.error({ op: 'emailTemplateVersion.missing', template })
log.error('emailTemplateVersion.missing', { template })
templateVersion = 1
}
message.templateVersion = templateVersion
@ -308,9 +308,8 @@ module.exports = function (log, config, oauthdb) {
headers[X_SES_MESSAGE_TAGS] = sesMessageTagsHeaderValue(message.metricsTemplate || template, emailService)
}
log.info({
log.info('mailer.send', {
email: emailAddresses[0],
op: 'mailer.send',
template,
headers: Object.keys(headers).join(',')
})
@ -337,8 +336,7 @@ module.exports = function (log, config, oauthdb) {
const d = P.defer()
mailer.sendMail(emailConfig, (err, status) => {
if (err) {
log.error({
op: 'mailer.send.error',
log.error('mailer.send.error', {
err: err.message,
code: err.code,
errno: err.errno,
@ -351,8 +349,7 @@ module.exports = function (log, config, oauthdb) {
return d.reject(err)
}
log.info({
op: 'mailer.send.1',
log.info('mailer.send.1', {
status: status && status.message,
id: status && status.messageId,
to: emailConfig && emailConfig.to,
@ -431,13 +428,13 @@ module.exports = function (log, config, oauthdb) {
}
return redis.get('config')
.catch(err => log.error({ op: 'emailConfig.read.error', err: err.message }))
.catch(err => log.error('emailConfig.read.error', { err: err.message }))
.then(liveConfig => {
if (liveConfig) {
try {
liveConfig = JSON.parse(liveConfig)
} catch (err) {
log.error({ op: 'emailConfig.parse.error', err: err.message })
log.error('emailConfig.parse.error', { err: err.message })
}
}
@ -540,7 +537,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.verifyEmail = async function (message) {
log.trace({ op: 'mailer.verifyEmail', email: message.email, uid: message.uid })
log.trace('mailer.verifyEmail', { email: message.email, uid: message.uid })
var templateName = 'verifyEmail'
const metricsTemplateName = templateName
@ -593,7 +590,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.unblockCodeEmail = function (message) {
log.trace({ op: 'mailer.unblockCodeEmail', email: message.email, uid: message.uid })
log.trace('mailer.unblockCodeEmail', { email: message.email, uid: message.uid })
var templateName = 'unblockCodeEmail'
var query = {
@ -628,7 +625,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.verifyLoginEmail = function (message) {
log.trace({ op: 'mailer.verifyLoginEmail', email: message.email, uid: message.uid })
log.trace('mailer.verifyLoginEmail', { email: message.email, uid: message.uid })
var templateName = 'verifyLoginEmail'
var query = {
@ -679,7 +676,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.verifyLoginCodeEmail = function (message) {
log.trace({ op: 'mailer.verifyLoginCodeEmail', email: message.email, uid: message.uid })
log.trace('mailer.verifyLoginCodeEmail', { email: message.email, uid: message.uid })
var templateName = 'verifyLoginCodeEmail'
var query = {
@ -718,7 +715,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.verifyPrimaryEmail = function (message) {
log.trace({ op: 'mailer.verifyPrimaryEmail', email: message.email, uid: message.uid })
log.trace('mailer.verifyPrimaryEmail', { email: message.email, uid: message.uid })
const templateName = 'verifyPrimaryEmail'
const query = {
@ -761,7 +758,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.verifySecondaryEmail = function (message) {
log.trace({ op: 'mailer.verifySecondaryEmail', email: message.email, uid: message.uid })
log.trace('mailer.verifySecondaryEmail', { email: message.email, uid: message.uid })
var templateName = 'verifySecondaryEmail'
var query = {
@ -915,7 +912,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.newDeviceLoginEmail = function (message) {
log.trace({ op: 'mailer.newDeviceLoginEmail', email: message.email, uid: message.uid })
log.trace('mailer.newDeviceLoginEmail', { email: message.email, uid: message.uid })
var templateName = 'newDeviceLoginEmail'
var links = this._generateSettingLinks(message, templateName)
var translator = this.translator(message.acceptLanguage)
@ -953,7 +950,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postVerifyEmail = function (message) {
log.trace({ op: 'mailer.postVerifyEmail', email: message.email, uid: message.uid })
log.trace('mailer.postVerifyEmail', { email: message.email, uid: message.uid })
var templateName = 'postVerifyEmail'
var links = this._generateLinks(this.syncUrl, message.email, {}, templateName)
@ -980,7 +977,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postVerifySecondaryEmail = function (message) {
log.trace({ op: 'mailer.postVerifySecondaryEmail', email: message.email, uid: message.uid })
log.trace('mailer.postVerifySecondaryEmail', { email: message.email, uid: message.uid })
var templateName = 'postVerifySecondaryEmail'
var links = this._generateSettingLinks(message, templateName)
@ -1008,7 +1005,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postChangePrimaryEmail = function (message) {
log.trace({ op: 'mailer.postChangePrimaryEmail', email: message.email, uid: message.uid })
log.trace('mailer.postChangePrimaryEmail', { email: message.email, uid: message.uid })
const templateName = 'postChangePrimaryEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1036,7 +1033,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postRemoveSecondaryEmail = function (message) {
log.trace({ op: 'mailer.postRemoveSecondaryEmail', email: message.email, uid: message.uid })
log.trace('mailer.postRemoveSecondaryEmail', { email: message.email, uid: message.uid })
const templateName = 'postRemoveSecondaryEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1062,7 +1059,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postAddTwoStepAuthenticationEmail = function (message) {
log.trace({ op: 'mailer.postAddTwoStepAuthenticationEmail', email: message.email, uid: message.uid })
log.trace('mailer.postAddTwoStepAuthenticationEmail', { email: message.email, uid: message.uid })
const templateName = 'postAddTwoStepAuthenticationEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1094,7 +1091,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postRemoveTwoStepAuthenticationEmail = function (message) {
log.trace({op: 'mailer.postRemoveTwoStepAuthenticationEmail', email: message.email, uid: message.uid})
log.trace('mailer.postRemoveTwoStepAuthenticationEmail', { email: message.email, uid: message.uid})
const templateName = 'postRemoveTwoStepAuthenticationEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1126,7 +1123,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postNewRecoveryCodesEmail = function (message) {
log.trace({ op: 'mailer.postNewRecoveryCodesEmail', email: message.email, uid: message.uid })
log.trace('mailer.postNewRecoveryCodesEmail', { email: message.email, uid: message.uid })
const templateName = 'postNewRecoveryCodesEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1158,7 +1155,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postConsumeRecoveryCodeEmail = function (message) {
log.trace({ op: 'mailer.postConsumeRecoveryCodeEmail', email: message.email, uid: message.uid })
log.trace('mailer.postConsumeRecoveryCodeEmail', { email: message.email, uid: message.uid })
const templateName = 'postConsumeRecoveryCodeEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1190,7 +1187,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.lowRecoveryCodesEmail = function (message) {
log.trace({ op: 'mailer.lowRecoveryCodesEmail', email: message.email, uid: message.uid })
log.trace('mailer.lowRecoveryCodesEmail', { email: message.email, uid: message.uid })
const templateName = 'lowRecoveryCodesEmail'
const links = this._generateLowRecoveryCodesLinks(message, templateName)
@ -1218,7 +1215,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postAddAccountRecoveryEmail = function (message) {
log.trace({ op: 'mailer.postAddAccountRecoveryEmail', email: message.email, uid: message.uid })
log.trace('mailer.postAddAccountRecoveryEmail', { email: message.email, uid: message.uid })
const templateName = 'postAddAccountRecoveryEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1252,7 +1249,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.postRemoveAccountRecoveryEmail = function (message) {
log.trace({ op: 'mailer.postRemoveAccountRecoveryEmail', email: message.email, uid: message.uid })
log.trace('mailer.postRemoveAccountRecoveryEmail', { email: message.email, uid: message.uid })
const templateName = 'postRemoveAccountRecoveryEmail'
const links = this._generateSettingLinks(message, templateName)
@ -1284,7 +1281,7 @@ module.exports = function (log, config, oauthdb) {
}
Mailer.prototype.passwordResetAccountRecoveryEmail = function (message) {
log.trace({ op: 'mailer.passwordResetAccountRecoveryEmail', email: message.email, uid: message.uid })
log.trace('mailer.passwordResetAccountRecoveryEmail', { email: message.email, uid: message.uid })
const templateName = 'passwordResetAccountRecoveryEmail'
const links = this._generateCreateAccountRecoveryLinks(message, templateName)

Просмотреть файл

@ -31,14 +31,13 @@ module.exports = (log, config, error, bounces, translator, oauthdb, sender) => {
.return(ungatedMailer)
.catch(function (e) {
const info = {
op: 'mailer.blocked',
errno: e.errno
}
const bouncedAt = e.output && e.output.payload && e.output.payload.bouncedAt
if (bouncedAt) {
info.bouncedAt = bouncedAt
}
log.info(info)
log.info('mailer.blocked', info)
throw e
})
}

Просмотреть файл

@ -26,17 +26,17 @@ module.exports = (log, config, oauthdb) => {
* @returns {Promise<any>}
*/
async function fetch(clientId) {
log.trace({ op: 'fetch.start' })
log.trace('fetch.start')
if (! clientId || clientId === 'sync') {
log.trace({ op: 'fetch.sync' })
log.trace('fetch.sync')
return FIREFOX_CLIENT
}
const cachedRecord = await clientCache.get(clientId)
if (cachedRecord) {
// used the cachedRecord if it exists
log.trace({ op: 'fetch.usedCache' })
log.trace('fetch.usedCache')
return cachedRecord
}
@ -46,14 +46,14 @@ module.exports = (log, config, oauthdb) => {
} catch (err) {
// fallback to the Firefox client if request fails
if (! err.statusCode) {
log.fatal({ op: 'fetch.failed', err: err })
log.fatal('fetch.failed', { err: err })
} else {
log.warn({ op: 'fetch.failedForClient', clientId })
log.warn('fetch.failedForClient', { clientId })
}
return FIREFOX_CLIENT
}
log.trace({ op: 'fetch.usedServer', body: clientInfo })
log.trace('fetch.usedServer', { body: clientInfo })
// We deliberately don't wait for this to resolve, since the
// client doesn't need to wait for us to write to the cache.
clientCache.set(clientId, clientInfo)

Просмотреть файл

@ -40,7 +40,7 @@ module.exports = (log, translator, templates, config) => {
isBudgetOk: () => isBudgetOk,
send (phoneNumber, templateName, acceptLanguage, signinCode) {
log.trace({ op: 'sms.send', templateName, acceptLanguage })
log.trace('sms.send', { templateName, acceptLanguage })
return P.resolve()
.then(() => {
@ -69,8 +69,7 @@ module.exports = (log, translator, templates, config) => {
return sns.publish(params).promise()
.then(result => {
log.info({
op: 'sms.send.success',
log.info('sms.send.success', {
templateName,
acceptLanguage,
messageId: result.MessageId
@ -78,7 +77,7 @@ module.exports = (log, translator, templates, config) => {
})
.catch(sendError => {
const { message, code, statusCode } = sendError
log.error({ op: 'sms.send.error', message, code, statusCode })
log.error('sms.send.error', { message, code, statusCode })
throw error.messageRejected(message, code)
})
@ -122,10 +121,10 @@ module.exports = (log, translator, templates, config) => {
}
isBudgetOk = current <= limit - CREDIT_THRESHOLD
log.info({ op: 'sms.budget.ok', isBudgetOk, current, limit, threshold: CREDIT_THRESHOLD })
log.info('sms.budget.ok', { isBudgetOk, current, limit, threshold: CREDIT_THRESHOLD })
})
.catch(err => {
log.error({ op: 'sms.budget.error', err: err.message, result: err.result })
log.error('sms.budget.error', { err: err.message, result: err.result })
// If we failed to query the data, assume current spend is fine
isBudgetOk = true
@ -137,7 +136,7 @@ module.exports = (log, translator, templates, config) => {
const template = templates[`sms.${templateName}`]
if (! template) {
log.error({ op: 'sms.getMessage.error', templateName })
log.error('sms.getMessage.error', { templateName })
throw error.invalidMessageId()
}

Просмотреть файл

@ -36,7 +36,6 @@ function logEndpointErrors(response, log) {
// to better understand the DB timeouts.
if (response.__proto__ && response.__proto__.name === 'EndpointError') {
var endpointLog = {
op: 'server.EndpointError',
message: response.message,
reason: response.reason
}
@ -44,7 +43,7 @@ function logEndpointErrors(response, log) {
// log the DB attempt to understand the action
endpointLog.method = response.attempt.method
}
log.error(endpointLog)
log.error('server.EndpointError', endpointLog)
}
}
@ -99,14 +98,14 @@ async function create (log, error, config, routes, db, oauthdb, translator) {
// keeping a nonce cache. Instead we use this as an opportunity
// to report on the clock skew values seen in the wild.
var skew = (Date.now() / 1000) - (+ts)
log.trace({ op: 'server.nonceFunc', skew: skew })
log.trace('server.nonceFunc', { skew: skew })
}
}
function makeCredentialFn(dbGetFn) {
return function (id) {
log.trace({ op: 'DB.getToken', id: id })
log.trace('DB.getToken', { id: id })
if (! HEX_STRING.test(id)) {
return null
}
@ -227,8 +226,7 @@ async function create (log, error, config, routes, db, oauthdb, translator) {
if (request.headers.authorization) {
// Log some helpful details for debugging authentication problems.
log.trace({
op: 'server.onPreAuth',
log.trace('server.onPreAuth', {
rid: request.id,
path: request.path,
auth: request.headers.authorization,

Просмотреть файл

@ -19,7 +19,7 @@ module.exports = function (log) {
function checkDeleteError(err) {
if (err) {
log.error({ op: 'deleteMessage', err: err })
log.error('deleteMessage', { err: err })
}
}
@ -34,7 +34,7 @@ module.exports = function (log) {
},
function (err, data) {
if (err) {
log.error({ op: 'fetch', url: url, err: err })
log.error('fetch', { url: url, err: err })
if (! errTimer) {
// unacceptable! this aws lib will call the callback
// more than once with different errors. ಠ_ಠ
@ -62,7 +62,7 @@ module.exports = function (log) {
this.emit('data', message)
}
catch (e) {
log.error({ op: 'fetch', url: url, err: e })
log.error('fetch', { url: url, err: e })
deleteFromQueue()
}
}

Просмотреть файл

@ -17,12 +17,12 @@ module.exports = function (log, Token, lifetime) {
AccountResetToken.tokenTypeID = 'accountResetToken'
AccountResetToken.create = function (details) {
log.trace({ op: 'AccountResetToken.create', uid: details && details.uid })
log.trace('AccountResetToken.create', { uid: details && details.uid })
return Token.createNewToken(AccountResetToken, details || {})
}
AccountResetToken.fromHex = function (string, details) {
log.trace({ op: 'AccountResetToken.fromHex' })
log.trace('AccountResetToken.fromHex')
details = details || {}
return Token.createTokenFromHexData(AccountResetToken, string, details)
}

Просмотреть файл

@ -23,7 +23,7 @@ module.exports = function (log, Token) {
KeyFetchToken.tokenTypeID = 'keyFetchToken'
KeyFetchToken.create = function (details) {
log.trace({ op: 'KeyFetchToken.create', uid: details && details.uid })
log.trace('KeyFetchToken.create', { uid: details && details.uid })
return Token.createNewToken(KeyFetchToken, details || {})
.then(
function (token) {
@ -39,24 +39,24 @@ module.exports = function (log, Token) {
}
KeyFetchToken.fromId = function (id, details) {
log.trace({ op: 'KeyFetchToken.fromId' })
log.trace('KeyFetchToken.fromId')
return P.resolve(new KeyFetchToken({ id, authKey: details.authKey }, details))
}
KeyFetchToken.fromHex = function (string, details) {
log.trace({ op: 'KeyFetchToken.fromHex' })
log.trace('KeyFetchToken.fromHex')
return Token.createTokenFromHexData(KeyFetchToken, string, details || {})
}
KeyFetchToken.prototype.bundleKeys = function (kA, wrapKb) {
log.trace({ op: 'keyFetchToken.bundleKeys', id: this.id })
log.trace('keyFetchToken.bundleKeys', { id: this.id })
kA = Buffer.from(kA, 'hex')
wrapKb = Buffer.from(wrapKb, 'hex')
return this.bundle('account/keys', Buffer.concat([kA, wrapKb]))
}
KeyFetchToken.prototype.unbundleKeys = function (bundle) {
log.trace({ op: 'keyFetchToken.unbundleKeys', id: this.id })
log.trace('keyFetchToken.unbundleKeys', { id: this.id })
return this.unbundle('account/keys', bundle)
.then(
function (plaintext) {

Просмотреть файл

@ -17,12 +17,12 @@ module.exports = function (log, Token, lifetime) {
PasswordChangeToken.tokenTypeID = 'passwordChangeToken'
PasswordChangeToken.create = function (details) {
log.trace({ op: 'PasswordChangeToken.create', uid: details && details.uid })
log.trace('PasswordChangeToken.create', { uid: details && details.uid })
return Token.createNewToken(PasswordChangeToken, details || {})
}
PasswordChangeToken.fromHex = function (string, details) {
log.trace({ op: 'PasswordChangeToken.fromHex' })
log.trace('PasswordChangeToken.fromHex')
return Token.createTokenFromHexData(PasswordChangeToken, string, details || {})
}

Просмотреть файл

@ -22,8 +22,7 @@ module.exports = (log, Token, lifetime) => {
PasswordForgotToken.create = function (details) {
details = details || {}
log.trace({
op: 'PasswordForgotToken.create',
log.trace('PasswordForgotToken.create', {
uid: details.uid,
email: details.email
})
@ -36,7 +35,7 @@ module.exports = (log, Token, lifetime) => {
}
PasswordForgotToken.fromHex = function (string, details) {
log.trace({ op: 'PasswordForgotToken.fromHex' })
log.trace('PasswordForgotToken.fromHex')
details = details || {}
return Token.createTokenFromHexData(PasswordForgotToken, string, details)
}

Просмотреть файл

@ -54,12 +54,12 @@ module.exports = (log, Token, config) => {
static create(details) {
details = details || {}
log.trace({ op: 'SessionToken.create', uid: details.uid })
log.trace('SessionToken.create', { uid: details.uid })
return Token.createNewToken(SessionToken, details)
}
static fromHex(string, details) {
log.trace({ op: 'SessionToken.fromHex' })
log.trace('SessionToken.fromHex')
return Token.createTokenFromHexData(SessionToken, string, details || {})
}

Просмотреть файл

@ -90,7 +90,7 @@ module.exports = (log, config) => {
// Convenience method to bundle a payload using token bundleKey.
//
Token.prototype.bundle = function(keyInfo, payload) {
log.trace({ op: 'Token.bundle' })
log.trace('Token.bundle')
return Bundle.bundle(this.bundleKey, keyInfo, payload)
}
@ -98,7 +98,7 @@ module.exports = (log, config) => {
// Convenience method to unbundle a payload using token bundleKey.
//
Token.prototype.unbundle = function(keyInfo, payload) {
log.trace({ op: 'Token.unbundle' })
log.trace('Token.unbundle')
return Bundle.unbundle(this.bundleKey, keyInfo, payload)
}

Просмотреть файл

@ -26,7 +26,7 @@ describe('e2e/push', () => {
.then(subscription => {
let count = 0
const thisSpyLog = mockLog({
info (log) {
info (op, log) {
if (log.name === 'push.account_verify.success') {
count++
}

Просмотреть файл

@ -131,9 +131,9 @@ describe('createBackendServiceAPI', () => {
}
})
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testSimplePost')
assert.equal(log.error.getCall(0).args[0].error, 'request schema validation failed')
assert.ok(/"foo" must be a string/.test(log.error.getCall(0).args[0].message))
assert.equal(log.error.getCall(0).args[0], 'mock-service.testSimplePost')
assert.equal(log.error.getCall(0).args[1].error, 'request schema validation failed')
assert.ok(/"foo" must be a string/.test(log.error.getCall(0).args[1].message))
}
})
@ -152,9 +152,9 @@ describe('createBackendServiceAPI', () => {
}
})
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[0].error, 'params schema validation failed')
assert.ok(/fails to match the required pattern/.test(log.error.getCall(0).args[0].message))
assert.equal(log.error.getCall(0).args[0], 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[1].error, 'params schema validation failed')
assert.ok(/fails to match the required pattern/.test(log.error.getCall(0).args[1].message))
}
log.error.resetHistory()
try {
@ -163,9 +163,9 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[0].error, 'params schema validation failed')
assert.ok(/"second" must be a string/.test(log.error.getCall(0).args[0].message))
assert.equal(log.error.getCall(0).args[0], 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[1].error, 'params schema validation failed')
assert.ok(/"second" must be a string/.test(log.error.getCall(0).args[1].message))
}
})
@ -176,8 +176,8 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'safeUrl.unsafe')
assert.equal(log.error.getCall(0).args[0].key, 'first')
assert.equal(log.error.getCall(0).args[0], 'safeUrl.unsafe')
assert.equal(log.error.getCall(0).args[1].key, 'first')
}
})
@ -195,9 +195,9 @@ describe('createBackendServiceAPI', () => {
}
})
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[0].error, 'query schema validation failed')
assert.ok(/"foo" must be a string/.test(log.error.getCall(0).args[0].message))
assert.equal(log.error.getCall(0).args[0], 'mock-service.testGetWithValidation')
assert.equal(log.error.getCall(0).args[1].error, 'query schema validation failed')
assert.ok(/"foo" must be a string/.test(log.error.getCall(0).args[1].message))
}
})
@ -208,8 +208,8 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'safeUrl.unsafe')
assert.equal(log.error.getCall(0).args[0].key, 'foo')
assert.equal(log.error.getCall(0).args[0], 'safeUrl.unsafe')
assert.equal(log.error.getCall(0).args[1].key, 'foo')
}
})
@ -254,9 +254,9 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testPostWithValidation')
assert.equal(log.error.getCall(0).args[0].error, 'response schema validation failed')
assert.ok(/"status" must be a number/.test(log.error.getCall(0).args[0].message))
assert.equal(log.error.getCall(0).args[0], 'mock-service.testPostWithValidation')
assert.equal(log.error.getCall(0).args[1].error, 'response schema validation failed')
assert.ok(/"status" must be a number/.test(log.error.getCall(0).args[1].message))
}
})
@ -307,11 +307,11 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.BACKEND_SERVICE_FAILURE)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testPostWithValidation.1')
assert.deepEqual(log.error.getCall(0).args[0].params, { id: 'abc' })
assert.deepEqual(log.error.getCall(0).args[0].query, {})
assert.deepEqual(log.error.getCall(0).args[0].payload, { foo: 'bar' })
assert.deepEqual(log.error.getCall(0).args[0].err.message, 'invalid frobble')
assert.equal(log.error.getCall(0).args[0], 'mock-service.testPostWithValidation.1')
assert.deepEqual(log.error.getCall(0).args[1].params, { id: 'abc' })
assert.deepEqual(log.error.getCall(0).args[1].query, {})
assert.deepEqual(log.error.getCall(0).args[1].payload, { foo: 'bar' })
assert.deepEqual(log.error.getCall(0).args[1].err.message, 'invalid frobble')
}
})
@ -324,11 +324,11 @@ describe('createBackendServiceAPI', () => {
} catch (err) {
assert.equal(err.errno, error.ERRNO.BACKEND_SERVICE_FAILURE)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'mock-service.testPostWithValidation.1')
assert.deepEqual(log.error.getCall(0).args[0].params, { id: 'abc' })
assert.deepEqual(log.error.getCall(0).args[0].query, {})
assert.deepEqual(log.error.getCall(0).args[0].payload, { foo: 'bar' })
assert.ok(log.error.getCall(0).args[0].err.message.indexOf('ruh-roh!') >= 0)
assert.equal(log.error.getCall(0).args[0], 'mock-service.testPostWithValidation.1')
assert.deepEqual(log.error.getCall(0).args[1].params, { id: 'abc' })
assert.deepEqual(log.error.getCall(0).args[1].query, {})
assert.deepEqual(log.error.getCall(0).args[1].payload, { foo: 'bar' })
assert.ok(log.error.getCall(0).args[1].err.message.indexOf('ruh-roh!') >= 0)
}
})

Просмотреть файл

@ -50,7 +50,7 @@ describe('scrypt', () => {
function (err) {
assert.equal(err.message, 'too many pending scrypt hashes')
assert.equal(scrypt.numPendingHWM, 6, 'HWM should be maxPending+1')
assert.equal(log.buffer[0].op, 'scrypt.maxPendingExceeded')
assert.equal(log.buffer[0], 'scrypt.maxPendingExceeded')
}
)
}

Просмотреть файл

@ -826,9 +826,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.callCount, 0)
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'redis.get.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.get.error')
assert.deepEqual(log.error.args[0][1], {
key: 'wibble',
err: 'mock redis.get error'
})
@ -842,9 +842,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.callCount, 0)
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'redis.get.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.get.error')
assert.deepEqual(log.error.args[0][1], {
key: 'wibble',
err: 'mock redis.get error'
})
@ -858,9 +858,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.callCount, 0)
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'redis.get.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.get.error')
assert.deepEqual(log.error.args[0][1], {
key: 'wibble',
err: 'mock redis.get error'
})
@ -885,9 +885,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.args[0][0], 'wibble')
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'db.unpackTokensFromRedis.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'db.unpackTokensFromRedis.error')
assert.deepEqual(log.error.args[0][1], {
err: 'Unexpected token o in JSON at position 11'
})
})
@ -902,9 +902,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.callCount, 1)
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'db.unpackTokensFromRedis.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'db.unpackTokensFromRedis.error')
assert.deepEqual(log.error.args[0][1], {
err: 'Unexpected token o in JSON at position 11'
})
})
@ -917,9 +917,9 @@ describe('redis enabled, token-pruning enabled:', () => {
assert.equal(redis.del.callCount, 1)
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'db.unpackTokensFromRedis.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'db.unpackTokensFromRedis.error')
assert.deepEqual(log.error.args[0][1], {
err: 'Unexpected token o in JSON at position 11'
})
})

Просмотреть файл

@ -316,9 +316,9 @@ describe('lib/devices:', () => {
assert.equal(log.activityEvent.args[0][0].is_placeholder, true, 'is_placeholder was correct')
assert.equal(log.info.callCount, 1, 'log.info was called once')
assert.equal(log.info.args[0].length, 1, 'log.info was passed one argument')
assert.deepEqual(log.info.args[0][0], {
op: 'device:createPlaceholder',
assert.equal(log.info.args[0].length, 2)
assert.equal(log.info.args[0][0], 'device:createPlaceholder')
assert.deepEqual(log.info.args[0][1], {
uid: sessionToken.uid,
id: result.id
}, 'argument was event data')

Просмотреть файл

@ -72,7 +72,7 @@ describe('bounce messages', () => {
assert.equal(log.info.callCount, 0)
assert.equal(log.error.callCount, 0)
assert.equal(log.warn.callCount, 1)
assert.equal(log.warn.args[0][0].op, 'emailHeaders.keys')
assert.equal(log.warn.args[0][0], 'emailHeaders.keys')
})
})
@ -94,8 +94,8 @@ describe('bounce messages', () => {
assert.equal(mockDB.accountRecord.args[0][0], 'test@example.com')
assert.equal(mockDB.accountRecord.args[1][0], 'foobar@example.com')
assert.equal(log.info.callCount, 6)
assert.equal(log.info.args[5][0].op, 'accountDeleted')
assert.equal(log.info.args[5][0].email, 'foobar@example.com')
assert.equal(log.info.args[5][0], 'accountDeleted')
assert.equal(log.info.args[5][1].email, 'foobar@example.com')
assert.equal(mockMsg.del.callCount, 1)
})
})
@ -236,12 +236,12 @@ describe('bounce messages', () => {
assert.equal(mockDB.accountRecord.args[0][0], 'test@example.com')
assert.equal(mockDB.accountRecord.args[1][0], 'foobar@example.com')
assert.equal(log.info.callCount, 6)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].domain, 'other')
assert.equal(log.info.args[0][0].type, 'bounced')
assert.equal(log.info.args[4][0].complaint, true)
assert.equal(log.info.args[4][0].complaintFeedbackType, complaintType)
assert.equal(log.info.args[4][0].complaintUserAgent, 'AnyCompany Feedback Loop (V0.01)')
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].domain, 'other')
assert.equal(log.info.args[0][1].type, 'bounced')
assert.equal(log.info.args[4][1].complaint, true)
assert.equal(log.info.args[4][1].complaintFeedbackType, complaintType)
assert.equal(log.info.args[4][1].complaintUserAgent, 'AnyCompany Feedback Loop (V0.01)')
})
})
@ -271,17 +271,17 @@ describe('bounce messages', () => {
assert.equal(mockDB.deleteAccount.callCount, 1)
assert.equal(mockDB.deleteAccount.args[0][0].email, 'test@example.com')
assert.equal(log.info.callCount, 5)
assert.equal(log.info.args[1][0].op, 'handleBounce')
assert.equal(log.info.args[1][0].email, 'test@example.com')
assert.equal(log.info.args[1][0].domain, 'other')
assert.equal(log.info.args[1][0].status, '5.0.0')
assert.equal(log.info.args[1][0].action, 'failed')
assert.equal(log.info.args[1][0].diagnosticCode, 'smtp; 550 user unknown')
assert.equal(log.info.args[2][0].op, 'accountDeleted')
assert.equal(log.info.args[2][0].email, 'test@example.com')
assert.equal(log.info.args[4][0].op, 'handleBounce')
assert.equal(log.info.args[4][0].email, 'verified@example.com')
assert.equal(log.info.args[4][0].status, '4.0.0')
assert.equal(log.info.args[1][0], 'handleBounce')
assert.equal(log.info.args[1][1].email, 'test@example.com')
assert.equal(log.info.args[1][1].domain, 'other')
assert.equal(log.info.args[1][1].status, '5.0.0')
assert.equal(log.info.args[1][1].action, 'failed')
assert.equal(log.info.args[1][1].diagnosticCode, 'smtp; 550 user unknown')
assert.equal(log.info.args[2][0], 'accountDeleted')
assert.equal(log.info.args[2][1].email, 'test@example.com')
assert.equal(log.info.args[4][0], 'handleBounce')
assert.equal(log.info.args[4][1].email, 'verified@example.com')
assert.equal(log.info.args[4][1].status, '4.0.0')
})
})
@ -299,11 +299,11 @@ describe('bounce messages', () => {
assert.equal(mockDB.accountRecord.callCount, 1)
assert.equal(mockDB.accountRecord.args[0][0], 'test@example.com')
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[1][0].op, 'handleBounce')
assert.equal(log.info.args[1][0].email, 'test@example.com')
assert.equal(log.info.args[1][0], 'handleBounce')
assert.equal(log.info.args[1][1].email, 'test@example.com')
assert.equal(log.error.callCount, 2)
assert.equal(log.error.args[1][0].op, 'databaseError')
assert.equal(log.error.args[1][0].email, 'test@example.com')
assert.equal(log.error.args[1][0], 'databaseError')
assert.equal(log.error.args[1][1].email, 'test@example.com')
assert.equal(mockMsg.del.callCount, 1)
})
})
@ -324,12 +324,12 @@ describe('bounce messages', () => {
assert.equal(mockDB.deleteAccount.callCount, 1)
assert.equal(mockDB.deleteAccount.args[0][0].email, 'test@example.com')
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[1][0].op, 'handleBounce')
assert.equal(log.info.args[1][0].email, 'test@example.com')
assert.equal(log.info.args[1][0], 'handleBounce')
assert.equal(log.info.args[1][1].email, 'test@example.com')
assert.equal(log.error.callCount, 2)
assert.equal(log.error.args[1][0].op, 'databaseError')
assert.equal(log.error.args[1][0].email, 'test@example.com')
assert.equal(log.error.args[1][0].err.errno, error.ERRNO.ACCOUNT_UNKNOWN)
assert.equal(log.error.args[1][0], 'databaseError')
assert.equal(log.error.args[1][1].email, 'test@example.com')
assert.equal(log.error.args[1][1].err.errno, error.ERRNO.ACCOUNT_UNKNOWN)
assert.equal(mockMsg.del.callCount, 1)
})
})
@ -413,7 +413,7 @@ describe('bounce messages', () => {
assert.equal(mockDB.accountRecord.callCount, 0)
assert.equal(mockDB.deleteAccount.callCount, 0)
assert.equal(log.warn.callCount, 2)
assert.equal(log.warn.args[1][0].op, 'handleBounce.addressParseFailure')
assert.equal(log.warn.args[1][0], 'handleBounce.addressParseFailure')
})
})
@ -446,12 +446,12 @@ describe('bounce messages', () => {
assert.equal(mockDB.deleteAccount.callCount, 1)
assert.equal(mockDB.deleteAccount.args[0][0].email, 'test@example.com')
assert.equal(log.info.callCount, 3)
assert.equal(log.info.args[1][0].op, 'handleBounce')
assert.equal(log.info.args[1][0].email, 'test@example.com')
assert.equal(log.info.args[1][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][0].bounceType, 'Permanent')
assert.equal(log.info.args[1][0].bounceSubType, 'General')
assert.equal(log.info.args[1][0].lang, 'db-LB')
assert.equal(log.info.args[1][0], 'handleBounce')
assert.equal(log.info.args[1][1].email, 'test@example.com')
assert.equal(log.info.args[1][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][1].bounceType, 'Permanent')
assert.equal(log.info.args[1][1].bounceSubType, 'General')
assert.equal(log.info.args[1][1].lang, 'db-LB')
})
})
@ -497,10 +497,10 @@ describe('bounce messages', () => {
assert.equal(log.flowEvent.args[0][0].flow_time > 0, true)
assert.equal(log.flowEvent.args[0][0].time > 0, true)
assert.equal(log.info.callCount, 3)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].type, 'bounced')
assert.equal(log.info.args[0][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][0].flow_id, 'someFlowId')
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].type, 'bounced')
assert.equal(log.info.args[0][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][1].flow_id, 'someFlowId')
})
})
@ -542,14 +542,14 @@ describe('bounce messages', () => {
assert.equal(log.flowEvent.args[0][0].flow_time > 0, true)
assert.equal(log.flowEvent.args[0][0].time > 0, true)
assert.equal(log.info.callCount, 3)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].domain, 'aol.com')
assert.equal(log.info.args[0][0].type, 'bounced')
assert.equal(log.info.args[0][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][0].locale, 'en')
assert.equal(log.info.args[0][0].flow_id, 'someFlowId')
assert.equal(log.info.args[1][0].email, 'test@aol.com')
assert.equal(log.info.args[1][0].domain, 'aol.com')
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].domain, 'aol.com')
assert.equal(log.info.args[0][1].type, 'bounced')
assert.equal(log.info.args[0][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][1].locale, 'en')
assert.equal(log.info.args[0][1].flow_id, 'someFlowId')
assert.equal(log.info.args[1][1].email, 'test@aol.com')
assert.equal(log.info.args[1][1].domain, 'aol.com')
})
})
})

Просмотреть файл

@ -52,7 +52,7 @@ describe('delivery messages', () => {
junk: 'message'
})).then(function () {
assert.equal(log.warn.callCount, 1)
assert.equal(log.warn.args[0][0].op, 'emailHeaders.keys')
assert.equal(log.warn.args[0][0], 'emailHeaders.keys')
})
}
)
@ -83,14 +83,14 @@ describe('delivery messages', () => {
return mockedDelivery(log).handleDelivery(mockMsg).then(function () {
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].domain, 'other')
assert.equal(log.info.args[0][0].type, 'delivered')
assert.equal(log.info.args[0][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][0].email, 'jane@example.com')
assert.equal(log.info.args[1][0].op, 'handleDelivery')
assert.equal(log.info.args[1][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][0].processingTimeMillis, 546)
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].domain, 'other')
assert.equal(log.info.args[0][1].type, 'delivered')
assert.equal(log.info.args[0][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][1].email, 'jane@example.com')
assert.equal(log.info.args[1][0], 'handleDelivery')
assert.equal(log.info.args[1][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[1][1].processingTimeMillis, 546)
})
}
)
@ -138,13 +138,13 @@ describe('delivery messages', () => {
assert.equal(log.flowEvent.args[0][0].flow_time > 0, true)
assert.equal(log.flowEvent.args[0][0].time > 0, true)
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].domain, 'other')
assert.equal(log.info.args[0][0].type, 'delivered')
assert.equal(log.info.args[0][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][0].flow_id, 'someFlowId')
assert.equal(log.info.args[1][0].email, 'jane@example.com')
assert.equal(log.info.args[1][0].domain, 'other')
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].domain, 'other')
assert.equal(log.info.args[0][1].type, 'delivered')
assert.equal(log.info.args[0][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][1].flow_id, 'someFlowId')
assert.equal(log.info.args[1][1].email, 'jane@example.com')
assert.equal(log.info.args[1][1].domain, 'other')
})
}
)
@ -192,14 +192,14 @@ describe('delivery messages', () => {
assert.equal(log.flowEvent.args[0][0].flow_time > 0, true)
assert.equal(log.flowEvent.args[0][0].time > 0, true)
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[0][0].op, 'emailEvent')
assert.equal(log.info.args[0][0].domain, 'aol.com')
assert.equal(log.info.args[0][0].type, 'delivered')
assert.equal(log.info.args[0][0].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][0].locale, 'en')
assert.equal(log.info.args[0][0].flow_id, 'someFlowId')
assert.equal(log.info.args[1][0].email, 'jane@aol.com')
assert.equal(log.info.args[1][0].domain, 'aol.com')
assert.equal(log.info.args[0][0], 'emailEvent')
assert.equal(log.info.args[0][1].domain, 'aol.com')
assert.equal(log.info.args[0][1].type, 'delivered')
assert.equal(log.info.args[0][1].template, 'verifyLoginEmail')
assert.equal(log.info.args[0][1].locale, 'en')
assert.equal(log.info.args[0][1].flow_id, 'someFlowId')
assert.equal(log.info.args[1][1].email, 'jane@aol.com')
assert.equal(log.info.args[1][1].domain, 'aol.com')
})
}
)

Просмотреть файл

@ -91,13 +91,13 @@ describe('lib/email/notifications:', () => {
it('logged an email event', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailEvent')
assert.deepEqual(args[1], {
bounced: true,
domain: 'other',
flow_id: 'foo',
locale: 'en-gb',
op: 'emailEvent',
template: 'bar',
templateVersion: 'baz',
type: 'bounced'
@ -167,26 +167,26 @@ describe('lib/email/notifications:', () => {
assert.equal(log.info.callCount, 2)
let args = log.info.args[0]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailEvent')
assert.deepEqual(args[1], {
complaint: true,
domain: 'other',
flow_id: 'wibble',
locale: 'fr',
op: 'emailEvent',
template: 'blee',
templateVersion: '',
type: 'bounced'
})
args = log.info.args[1]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailEvent')
assert.deepEqual(args[1], {
complaint: true,
domain: 'gmail.com',
flow_id: 'wibble',
locale: 'fr',
op: 'emailEvent',
template: 'blee',
templateVersion: '',
type: 'bounced'
@ -242,17 +242,17 @@ describe('lib/email/notifications:', () => {
assert.equal(log.info.callCount, 4)
let args = log.info.args[2]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
op: 'accountDeleted',
assert.lengthOf(args, 2)
assert.equal(args[0], 'accountDeleted')
assert.deepEqual(args[1], {
emailVerified: false,
createdAt: emailRecord.createdAt
})
args = log.info.args[3]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
op: 'accountDeleted',
assert.lengthOf(args, 2)
assert.equal(args[0], 'accountDeleted')
assert.deepEqual(args[1], {
emailVerified: false,
createdAt: emailRecord.createdAt
})
@ -402,12 +402,12 @@ describe('lib/email/notifications:', () => {
it('logged an email event', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailEvent')
assert.deepEqual(args[1], {
domain: 'other',
flow_id: 'foo',
locale: 'en-gb',
op: 'emailEvent',
template: 'bar',
templateVersion: 'baz',
type: 'delivered'
@ -443,9 +443,9 @@ describe('lib/email/notifications:', () => {
assert.isAtLeast(log.error.callCount, 1)
const args = log.error.args[0]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
op: 'emailHeaders.missing',
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailHeaders.missing')
assert.deepEqual(args[1], {
origin: 'notification'
})
})
@ -457,12 +457,12 @@ describe('lib/email/notifications:', () => {
it('logged an email event', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
assert.lengthOf(args, 2)
assert.equal(args[0], 'emailEvent')
assert.deepEqual(args[1], {
bounced: true,
domain: 'other',
locale: '',
op: 'emailEvent',
template: '',
templateVersion: '',
type: 'bounced'

Просмотреть файл

@ -63,7 +63,7 @@ describe('email utils helpers', () => {
}
emailHelpers.logEmailEventSent(log, message)
assert.equal(log.info.callCount, 1)
assert.equal(log.info.args[0][0].locale, 'ru')
assert.equal(log.info.args[0][1].locale, 'ru')
})
it('should log an event per CC email', () => {
@ -75,9 +75,9 @@ describe('email utils helpers', () => {
}
emailHelpers.logEmailEventSent(log, message)
assert.equal(log.info.callCount, 3)
assert.equal(log.info.args[0][0].domain, 'other')
assert.equal(log.info.args[1][0].domain, 'gmail.com')
assert.equal(log.info.args[2][0].domain, 'yahoo.com')
assert.equal(log.info.args[0][1].domain, 'other')
assert.equal(log.info.args[1][1].domain, 'gmail.com')
assert.equal(log.info.args[2][1].domain, 'yahoo.com')
})
})
@ -186,21 +186,21 @@ describe('email utils helpers', () => {
it('logs an error if message.mail is missing', () => {
emailHelpers.logErrorIfHeadersAreWeirdOrMissing(log, {}, 'wibble')
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual({
op: 'emailHeaders.missing',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'emailHeaders.missing')
assert.deepEqual(log.error.args[0][1], {
origin: 'wibble'
}, log.error.args[0][0])
})
assert.equal(log.warn.callCount, 0)
})
it('logs an error if message.mail.headers is missing', () => {
emailHelpers.logErrorIfHeadersAreWeirdOrMissing(log, { mail: {} }, 'blee')
assert.equal(log.error.callCount, 1)
assert.deepEqual({
op: 'emailHeaders.missing',
assert.equal(log.error.args[0][0], 'emailHeaders.missing')
assert.deepEqual(log.error.args[0][1], {
origin: 'blee'
}, log.error.args[0][0])
})
assert.equal(log.warn.callCount, 0)
})
@ -265,9 +265,9 @@ describe('email utils helpers', () => {
}, 'wibble')
assert.equal(log.error.callCount, 0)
assert.equal(log.warn.callCount, 1)
assert.equal(log.warn.args[0].length, 1)
assert.deepEqual(log.warn.args[0][0], {
op: 'emailHeaders.keys',
assert.equal(log.warn.args[0].length, 2)
assert.equal(log.warn.args[0][0], 'emailHeaders.keys')
assert.deepEqual(log.warn.args[0][1], {
keys: 'X-Template-Name,X-Xxx,X-Yyy,X-Zzz',
template: 'foo',
origin: 'wibble'
@ -282,8 +282,8 @@ describe('email utils helpers', () => {
}, 'blee')
assert.equal(log.error.callCount, 0)
assert.equal(log.warn.callCount, 1)
assert.deepEqual(log.warn.args[0][0], {
op: 'emailHeaders.keys',
assert.equal(log.warn.args[0][0], 'emailHeaders.keys')
assert.deepEqual(log.warn.args[0][1], {
keys: 'x-template-name',
template: 'wibble',
origin: 'blee'
@ -293,22 +293,22 @@ describe('email utils helpers', () => {
it('logs an error if message.mail.headers is non-object', () => {
emailHelpers.logErrorIfHeadersAreWeirdOrMissing(log, { mail: { headers: 'foo' } }, 'wibble')
assert.equal(log.error.callCount, 1)
assert.deepEqual({
op: 'emailHeaders.weird',
assert.equal(log.error.args[0][0], 'emailHeaders.weird')
assert.deepEqual(log.error.args[0][1], {
type: 'string',
origin: 'wibble'
}, log.error.args[0][0])
})
assert.equal(log.warn.callCount, 0)
})
it('logs an error if message.headers is non-object', () => {
emailHelpers.logErrorIfHeadersAreWeirdOrMissing(log, { mail: {}, headers: 42 }, 'wibble')
assert.equal(log.error.callCount, 1)
assert.deepEqual({
op: 'emailHeaders.weird',
assert.equal(log.error.args[0][0], 'emailHeaders.weird')
assert.deepEqual(log.error.args[0][1], {
type: 'number',
origin: 'wibble'
}, log.error.args[0][0])
})
assert.equal(log.warn.callCount, 0)
})
})

Просмотреть файл

@ -108,7 +108,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'log.activityEvent', 'first argument was function name')
assert.deepEqual(args[1], {
op: 'log.activityEvent',
data: undefined
}, 'argument was correct')
@ -131,7 +130,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'log.activityEvent', 'first argument was function name')
assert.deepEqual(args[1], {
op: 'log.activityEvent',
data: {
event: 'wibble'
}
@ -156,7 +154,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'log.activityEvent', 'first argument was function name')
assert.deepEqual(args[1], {
op: 'log.activityEvent',
data: {
uid: 'wibble'
}
@ -207,7 +204,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'flow.missingData', 'first argument was op')
assert.deepEqual(args[1], {
op: 'flow.missingData',
data: undefined
}, 'argument was correct')
@ -232,7 +228,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'flow.missingData', 'first argument was op')
assert.deepEqual(args[1], {
op: 'flow.missingData',
data: {
flow_id: 'wibble',
flow_time: 1000,
@ -261,7 +256,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'flow.missingData', 'first argument was op')
assert.deepEqual(args[1], {
op: 'flow.missingData',
data: {
event: 'wibble',
flow_time: 1000,
@ -290,7 +284,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'flow.missingData', 'first argument was op')
assert.deepEqual(args[1], {
op: 'flow.missingData',
data: {
event: 'wibble',
flow_id: 'blee',
@ -319,7 +312,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'flow.missingData', 'first argument was op')
assert.deepEqual(args[1], {
op: 'flow.missingData',
data: {
event: 'wibble',
flow_id: 'blee',
@ -361,7 +353,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'amplitude.missingData', 'first argument was error op')
assert.deepEqual(args[1], {
op: 'amplitude.missingData',
data: undefined
}, 'second argument was correct')
@ -379,7 +370,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'amplitude.missingData', 'first argument was error op')
assert.deepEqual(args[1], {
op: 'amplitude.missingData',
data: { device_id: 'foo', user_id: 'bar' }
}, 'second argument was correct')
@ -397,7 +387,6 @@ describe('log', () => {
assert.equal(args.length, 2, 'logger.error was passed two arguments')
assert.equal(args[0], 'amplitude.missingData', 'first argument was error op')
assert.deepEqual(args[1], {
op: 'amplitude.missingData',
data: { event_type: 'foo' }
}, 'second argument was correct')
@ -448,12 +437,12 @@ describe('log', () => {
() => {
var err = new Error()
err.email = 'test@example.com'
log.error({ op: 'unexpectedError', err: err })
log.error('unexpectedError', { err: err })
assert.equal(logger.error.callCount, 1, 'logger.error was called once')
var args = logger.error.args[0]
assert.equal(args[0], 'unexpectedError', 'logger.error received "op" value')
assert.equal(Object.keys(args[1]).length, 3, 'log info has three fields')
assert.lengthOf(Object.keys(args[1]), 2)
assert.equal(args[1].email, 'test@example.com', 'email is reported in top-level fields')
assert(! args[1].err.email, 'email should not be reported in error object')
}
@ -501,7 +490,7 @@ describe('log', () => {
})
assert.equal(logger.info.callCount, 1)
assert.equal(logger.info.args[0][0], 'request.summary')
const line = logger.info.args[0][1]
// Because t is generated using Date.now and subtracting info.received,
@ -513,7 +502,6 @@ describe('log', () => {
delete line.t;
assert.deepEqual(line, {
op: 'request.summary',
status: 201,
errno: 109,
rid: 'quuz',

Просмотреть файл

@ -53,9 +53,9 @@ describe('metrics/amplitude', () => {
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: 'amplitude.badArgument',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'amplitude.badArgument')
assert.deepEqual(log.error.args[0][1], {
err: 'Bad argument',
event: '',
hasRequest: true
@ -74,9 +74,9 @@ describe('metrics/amplitude', () => {
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: 'amplitude.badArgument',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'amplitude.badArgument')
assert.deepEqual(log.error.args[0][1], {
err: 'Bad argument',
event: 'foo',
hasRequest: false

Просмотреть файл

@ -185,12 +185,12 @@ describe('metricsContext', () => {
assert.equal(result, undefined, 'result is undefined')
assert.equal(log.error.callCount, 1, 'log.error was called once')
assert.equal(log.error.args[0].length, 1, 'log.error was passed one argument')
assert.equal(log.error.args[0][0].op, 'metricsContext.stash', 'op property was correct')
assert.equal(log.error.args[0][0].err.message, 'Invalid token', 'err.message property was correct')
assert.strictEqual(log.error.args[0][0].hasToken, true, 'hasToken property was correct')
assert.strictEqual(log.error.args[0][0].hasId, true, 'hasId property was correct')
assert.strictEqual(log.error.args[0][0].hasUid, false, 'hasUid property was correct')
assert.equal(log.error.args[0].length, 2, 'log.error was passed one argument')
assert.equal(log.error.args[0][0], 'metricsContext.stash', 'op property was correct')
assert.equal(log.error.args[0][1].err.message, 'Invalid token', 'err.message property was correct')
assert.strictEqual(log.error.args[0][1].hasToken, true, 'hasToken property was correct')
assert.strictEqual(log.error.args[0][1].hasId, true, 'hasId property was correct')
assert.strictEqual(log.error.args[0][1].hasUid, false, 'hasUid property was correct')
assert.equal(cache.add.callCount, 0, 'cache.add was not called')
})
@ -335,12 +335,12 @@ describe('metricsContext', () => {
assert.deepEqual(result, {})
assert.equal(log.error.callCount, 1)
assert.lengthOf(log.error.args[0], 1)
assert.equal(log.error.args[0][0].op, 'metricsContext.get')
assert.equal(log.error.args[0][0].err.message, 'Invalid token')
assert.strictEqual(log.error.args[0][0].hasToken, true)
assert.strictEqual(log.error.args[0][0].hasId, false)
assert.strictEqual(log.error.args[0][0].hasUid, true)
assert.lengthOf(log.error.args[0], 2)
assert.equal(log.error.args[0][0], 'metricsContext.get')
assert.equal(log.error.args[0][1].err.message, 'Invalid token')
assert.strictEqual(log.error.args[0][1].hasToken, true)
assert.strictEqual(log.error.args[0][1].hasId, false)
assert.strictEqual(log.error.args[0][1].hasUid, true)
})
it('metricsContext.get with no token and no payload', async () => {
@ -399,12 +399,12 @@ describe('metricsContext', () => {
assert.equal(cache.get.callCount, 1)
assert.equal(log.error.callCount, 1)
assert.lengthOf(log.error.args[0], 1)
assert.equal(log.error.args[0][0].op, 'metricsContext.get')
assert.equal(log.error.args[0][0].err, 'foo')
assert.strictEqual(log.error.args[0][0].hasToken, true)
assert.strictEqual(log.error.args[0][0].hasId, true)
assert.strictEqual(log.error.args[0][0].hasUid, true)
assert.lengthOf(log.error.args[0], 2)
assert.equal(log.error.args[0][0], 'metricsContext.get')
assert.equal(log.error.args[0][1].err, 'foo')
assert.strictEqual(log.error.args[0][1].hasToken, true)
assert.strictEqual(log.error.args[0][1].hasId, true)
assert.strictEqual(log.error.args[0][1].hasUid, true)
})
it(
@ -696,9 +696,9 @@ describe('metricsContext', () => {
assert.equal(mockRequest.payload.metricsContext.flowId, '1234567890abcdef1234567890abcdef06146f1d05e7ae215885a4e45b66ff1f', 'valid flow data was not removed')
assert.equal(mockLog.warn.callCount, 0, 'log.warn was not called')
assert.equal(mockLog.info.callCount, 1, 'log.info was called once')
assert.equal(mockLog.info.args[0].length, 1, 'log.info was passed one argument')
assert.deepEqual(mockLog.info.args[0][0], {
op: 'metrics.context.validate',
assert.lengthOf(mockLog.info.args[0], 2)
assert.equal(mockLog.info.args[0][0], 'metrics.context.validate')
assert.deepEqual(mockLog.info.args[0][1], {
valid: true
}, 'log.info was passed correct argument')
@ -729,8 +729,7 @@ describe('metricsContext', () => {
assert(! valid, 'the data is treated as invalid')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'missing payload'
}), 'log.warn was called with the expected log data')
@ -764,8 +763,7 @@ describe('metricsContext', () => {
assert(! valid, 'the data is treated as invalid')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'missing context'
}), 'log.warn was called with the expected log data')
@ -801,8 +799,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowBeginTime, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'missing flowId'
}), 'log.warn was called with the expected log data')
@ -838,8 +835,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'missing flowBeginTime'
}), 'log.warn was called with the expected log data')
@ -876,8 +872,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'expired flowBeginTime'
}), 'log.warn was called with the expected log data')
@ -914,8 +909,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'invalid signature'
}), 'log.warn was called with the expected log data')
@ -962,8 +956,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'invalid signature'
}), 'log.warn was called with the expected log data')
@ -1010,8 +1003,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'invalid signature'
}), 'log.warn was called with the expected log data')
@ -1061,8 +1053,7 @@ describe('metricsContext', () => {
assert(! mockRequest.payload.metricsContext.flowId, 'the invalid flow data was removed')
assert.equal(mockLog.info.callCount, 0, 'log.info was not called')
assert.equal(mockLog.warn.callCount, 1, 'log.warn was called once')
assert.ok(mockLog.warn.calledWithExactly({
op: 'metrics.context.validate',
assert.ok(mockLog.warn.calledWithExactly('metrics.context.validate', {
valid: false,
reason: 'invalid signature'
}), 'log.warn was called with the expected log data')

Просмотреть файл

@ -50,9 +50,9 @@ describe('metrics/events', () => {
.then(() => {
assert.equal(log.error.callCount, 1, 'log.error was called once')
const args = log.error.args[0]
assert.equal(args.length, 1, 'log.error was passed one argument')
assert.deepEqual(args[0], {
op: 'metricsEvents.emit',
assert.lengthOf(args, 2)
assert.equal(args[0], 'metricsEvents.emit')
assert.deepEqual(args[1], {
missingEvent: true
}, 'argument was correct')
@ -521,9 +521,9 @@ describe('metrics/events', () => {
.then(() => {
assert.equal(log.error.callCount, 1, 'log.error was called once')
const args = log.error.args[0]
assert.equal(args.length, 1, 'log.error was passed one argument')
assert.deepEqual(args[0], {
op: 'metricsEvents.emitFlowEvent',
assert.lengthOf(args, 2)
assert.equal(args[0], 'metricsEvents.emitFlowEvent')
assert.deepEqual(args[1], {
event: 'email.verification.sent',
badRequest: true
}, 'argument was correct')
@ -552,8 +552,8 @@ describe('metrics/events', () => {
assert.equal(metricsContext.gather.callCount, 1, 'metricsContext.gather was called once')
assert.equal(log.error.callCount, 1, 'log.error was called once')
assert.deepEqual(log.error.args[0][0], {
op: 'metricsEvents.emitFlowEvent',
assert.equal(log.error.args[0][0], 'metricsEvents.emitFlowEvent')
assert.deepEqual(log.error.args[0][1], {
event: 'email.verification.sent',
missingFlowId: true
}, 'argument was correct')

Просмотреть файл

@ -47,8 +47,8 @@ describe('notifier', () => {
event: 'stuff'
})
assert.deepEqual(log.trace.args[0][0], {
op: 'Notifier.publish',
assert.equal(log.trace.args[0][0], 'Notifier.publish')
assert.deepEqual(log.trace.args[0][1], {
data: {
TopicArn: 'arn:aws:sns:us-west-2:927034868275:foo',
Message: '{\"event\":\"stuff\"}',
@ -73,8 +73,8 @@ describe('notifier', () => {
}
})
assert.deepEqual(log.trace.args[0][0], {
op: 'Notifier.publish',
assert.equal(log.trace.args[0][0], 'Notifier.publish')
assert.deepEqual(log.trace.args[0][1], {
data: {
TopicArn: 'arn:aws:sns:us-west-2:927034868275:foo',
Message: '{\"cool\":\"stuff\",\"more\":\"stuff\",\"event\":\"stuff-with-data\"}',
@ -98,8 +98,8 @@ describe('notifier', () => {
}
})
assert.deepEqual(log.trace.args[0][0], {
op: 'Notifier.publish',
assert.equal(log.trace.args[0][0], 'Notifier.publish')
assert.deepEqual(log.trace.args[0][1], {
data: {
TopicArn: 'arn:aws:sns:us-west-2:927034868275:foo',
Message: '{\"email\":\"testme@example.com\",\"event\":\"email-change\"}',
@ -135,14 +135,14 @@ describe('notifier', () => {
notifier.send({
event: 'stuff'
}, () => {
assert.deepEqual(log.trace.args[0][0], {
op: 'Notifier.publish',
assert.equal(log.trace.args[0][0], 'Notifier.publish')
assert.deepEqual(log.trace.args[0][1], {
data: {
disabled: true
},
success: true
})
assert.equal(log.trace.args[0][0].data.disabled, true)
assert.equal(log.trace.args[0][1].data.disabled, true)
assert.equal(log.error.called, false)
})

Просмотреть файл

@ -74,7 +74,7 @@ describe('push', () => {
'sendPush does not reject on empty device array',
() => {
const thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.success') {
assert.fail('must not call push.success')
}
@ -91,7 +91,7 @@ describe('push', () => {
() => {
var successCalled = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.success') {
// notification sent
successCalled++
@ -121,7 +121,7 @@ describe('push', () => {
() => {
var successCalled = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.success') {
// notification sent
successCalled++
@ -353,7 +353,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.data_but_no_keys') {
// data detected but device had no keys
count++
@ -383,7 +383,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.no_push_callback') {
// device had no push callback
count++
@ -409,7 +409,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.failed') {
// web-push failed
count++
@ -461,9 +461,9 @@ describe('push', () => {
return push.sendPush(mockUid, devices, 'accountVerify')
}).then(function () {
assert.equal(thisMockLog.error.callCount, 1, 'log.error was called')
var arg = thisMockLog.error.getCall(0).args[0]
assert.equal(arg.op, 'push.sendPush')
assert.equal(arg.err.message, 'Too many devices connected to account')
var args = thisMockLog.error.getCall(0).args
assert.equal(args[0], 'push.sendPush')
assert.equal(args[1].err.message, 'Too many devices connected to account')
})
}
)
@ -473,7 +473,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.reset_settings') {
// web-push failed
assert.equal(mockDb.updateDevice.callCount, 1, 'db.updateDevice was called once')
@ -510,7 +510,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.reset_settings') {
// web-push failed
assert.equal(mockDb.updateDevice.callCount, 1, 'db.updateDevice was called once')
@ -547,7 +547,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.failed') {
// web-push failed
assert.equal(mockDb.updateDevice.callCount, 0, 'db.updateDevice was not called')
@ -834,7 +834,7 @@ describe('push', () => {
() => {
let count = 0
var thisMockLog = mockLog({
info: function (log) {
info: function (op, log) {
if (log.name === 'push.account_verify.success') {
count++
}

Просмотреть файл

@ -80,8 +80,8 @@ describe('pushbox', () => {
assert.ok(err)
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'pushbox.retrieve')
assert.equal(log.error.getCall(0).args[0].error, 'response schema validation failed')
assert.equal(log.error.getCall(0).args[0], 'pushbox.retrieve')
assert.equal(log.error.getCall(0).args[1].error, 'response schema validation failed')
})
}
)
@ -102,9 +102,9 @@ describe('pushbox', () => {
assert.ok(err)
assert.equal(err.errno, error.ERRNO.BACKEND_SERVICE_FAILURE)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'pushbox.retrieve')
assert.equal(log.error.getCall(0).args[0].error, 'lamentably, an error hath occurred')
assert.equal(log.error.getCall(0).args[0].status, 1234)
assert.equal(log.error.getCall(0).args[0], 'pushbox.retrieve')
assert.equal(log.error.getCall(0).args[1].error, 'lamentably, an error hath occurred')
assert.equal(log.error.getCall(0).args[1].status, 1234)
})
}
)
@ -186,8 +186,8 @@ describe('pushbox', () => {
assert.ok(err)
assert.equal(err.errno, error.ERRNO.INTERNAL_VALIDATION_ERROR)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'pushbox.store')
assert.equal(log.error.getCall(0).args[0].error, 'response schema validation failed')
assert.equal(log.error.getCall(0).args[0], 'pushbox.store')
assert.equal(log.error.getCall(0).args[1].error, 'response schema validation failed')
})
}
)
@ -207,9 +207,9 @@ describe('pushbox', () => {
assert.ok(err)
assert.equal(err.errno, error.ERRNO.BACKEND_SERVICE_FAILURE)
assert.equal(log.error.callCount, 1, 'an error was logged')
assert.equal(log.error.getCall(0).args[0].op, 'pushbox.store')
assert.equal(log.error.getCall(0).args[0].error, 'Alas, an error! I knew it, Horatio.')
assert.equal(log.error.getCall(0).args[0].status, 789)
assert.equal(log.error.getCall(0).args[0], 'pushbox.store')
assert.equal(log.error.getCall(0).args[1].error, 'Alas, an error! I knew it, Horatio.')
assert.equal(log.error.getCall(0).args[1].status, 789)
})
}
)

Просмотреть файл

@ -325,9 +325,9 @@ describe('redis/connection:', () => {
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: 'redis.update.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.update.error')
assert.deepEqual(log.error.args[0][1], {
key: 'wibble',
err: 'mock get error'
})
@ -433,9 +433,9 @@ describe('redis/connection:', () => {
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: 'redis.update.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.update.error')
assert.deepEqual(log.error.args[0][1], {
key: 'wibble',
err: 'mock exec error'
})
@ -493,9 +493,9 @@ describe('redis/connection:', () => {
it('called log.warn correctly', () => {
assert.equal(log.error.callCount, 0)
assert.equal(log.warn.callCount, 1)
assert.equal(log.warn.args[0].length, 1)
assert.deepEqual(log.warn.args[0][0], {
op: 'redis.watch.conflict',
assert.equal(log.warn.args[0].length, 2)
assert.equal(log.warn.args[0][0], 'redis.watch.conflict')
assert.deepEqual(log.warn.args[0][1], {
key: 'wibble'
})
})

Просмотреть файл

@ -31,7 +31,7 @@ describe('redis disabled:', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], { op: 'redis.disabled' })
assert.equal(args[0], 'redis.disabled')
})
it('returned undefined', () => {
@ -60,8 +60,9 @@ describe('redis enabled:', () => {
it('called log.info correctly', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], { op: 'redis.enabled', config })
assert.equal(args.length, 2)
assert.equal(args[0], 'redis.enabled')
assert.deepEqual(args[1], { config })
})
it('initialised pool correctly', () => {

Просмотреть файл

@ -162,9 +162,9 @@ describe('redis/pool:', () => {
it('should log the error', () => {
assert.equal(log.error.callCount, 1)
assert.equal(log.error.args[0].length, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'redis.error',
assert.equal(log.error.args[0].length, 2)
assert.equal(log.error.args[0][0], 'redis.error')
assert.deepEqual(log.error.args[0][1], {
err: 'foo'
})
})
@ -213,9 +213,9 @@ describe('redis/pool:', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'redisFactory.error',
assert.equal(args.length, 2)
assert.equal(args[0], 'redisFactory.error')
assert.deepEqual(args[1], {
err: 'mock factory create error'
})
})

Просмотреть файл

@ -1222,8 +1222,8 @@ describe('/account/login', function () {
mockLog.error.resetHistory()
return runTest(route, mockRequest, function () {
assert.equal(mockLog.error.callCount, 1, 'log.error was called')
assert.equal(mockLog.error.firstCall.args[0].op, 'Account.login')
assert.equal(mockLog.error.firstCall.args[0].numSessions, 201)
assert.equal(mockLog.error.firstCall.args[0], 'Account.login')
assert.equal(mockLog.error.firstCall.args[1].numSessions, 201)
mockDB.sessions = oldSessions
})
})
@ -1232,9 +1232,9 @@ describe('/account/login', function () {
describe('checks security history', function () {
var record
var clientAddress = mockRequest.app.clientAddress
before(() => {
mockLog.info = sinon.spy(function (arg) {
if (arg.op.indexOf('Account.history') === 0) {
beforeEach(() => {
mockLog.info = sinon.spy(function (op, arg) {
if (op.indexOf('Account.history') === 0) {
record = arg
}
})
@ -1259,7 +1259,7 @@ describe('/account/login', function () {
assert.equal(securityQuery.ipAddr, clientAddress)
assert.equal(!! record, true, 'log.info was called for Account.history')
assert.equal(record.op, 'Account.history.verified')
assert.equal(mockLog.info.args[0][0], 'Account.history.verified')
assert.equal(record.uid, uid)
assert.equal(record.events, 1)
assert.equal(record.recency, 'day')
@ -1285,7 +1285,7 @@ describe('/account/login', function () {
assert.equal(securityQuery.ipAddr, clientAddress)
assert.equal(!! record, true, 'log.info was called for Account.history')
assert.equal(record.op, 'Account.history.unverified')
assert.equal(mockLog.info.args[0][0], 'Account.history.unverified')
assert.equal(record.uid, uid)
assert.equal(record.events, 1)
})
@ -1576,10 +1576,10 @@ describe('/account/destroy', function () {
assert.equal(mockLog.info.callCount, 1)
args = mockLog.info.args[0]
assert.lengthOf(args, 1)
assert.equal(args[0].op, 'accountDeleted.byRequest')
assert.equal(args[0].email, email)
assert.equal(args[0].uid, uid)
assert.lengthOf(args, 2)
assert.equal(args[0], 'accountDeleted.byRequest')
assert.equal(args[1].email, email)
assert.equal(args[1].uid, uid)
assert.equal(mockPush.notifyAccountDestroyed.callCount, 1)
assert.equal(mockPush.notifyAccountDestroyed.firstCall.args[0], uid)

Просмотреть файл

@ -72,7 +72,7 @@ describe('/recovery_email/status', function () {
var mockDB = mocks.mockDB()
var pushCalled
var mockLog = mocks.mockLog({
info: sinon.spy(data => {
info: sinon.spy((op, data) => {
if (data.name === 'recovery_email_reason.push') {
pushCalled = true
}
@ -113,9 +113,9 @@ describe('/recovery_email/status', function () {
assert.equal(mockLog.info.callCount, 2)
const args = mockLog.info.args[1]
assert.lengthOf(args, 1)
assert.deepEqual(args[0], {
op: 'accountDeleted.invalidEmailAddress',
assert.equal(args.length, 2)
assert.equal(args[0], 'accountDeleted.invalidEmailAddress')
assert.deepEqual(args[1], {
email: TEST_EMAIL_INVALID,
emailVerified: false
})
@ -155,11 +155,11 @@ describe('/recovery_email/status', function () {
mockRequest.auth.credentials.uaBrowserVersion = '57'
return runTest(route, mockRequest).then(() => assert.ok(false), function (response) {
const args = log.info.firstCall.args[0]
assert.equal(args.op, 'recovery_email.status.stale')
assert.equal(args.email, TEST_EMAIL_INVALID)
assert.equal(args.createdAt, date.getTime())
assert.equal(args.browser, 'Firefox 57')
const args = log.info.firstCall.args
assert.equal(args[0], 'recovery_email.status.stale')
assert.equal(args[1].email, TEST_EMAIL_INVALID)
assert.equal(args[1].createdAt, date.getTime())
assert.equal(args[1].browser, 'Firefox 57')
})
.then(function () {
mockDB.deleteAccount.resetHistory()
@ -799,9 +799,9 @@ describe('/recovery_email', () => {
assert.equal(mockLog.info.callCount, 1)
args = mockLog.info.args[0]
assert.lengthOf(args, 1)
assert.equal(args[0].op, 'accountDeleted.unverifiedSecondaryEmail')
assert.equal(args[0].normalizedEmail, TEST_EMAIL)
assert.lengthOf(args, 2)
assert.equal(args[0], 'accountDeleted.unverifiedSecondaryEmail')
assert.equal(args[1].normalizedEmail, TEST_EMAIL)
})
.then(function () {
mockDB.deleteAccount.resetHistory()

Просмотреть файл

@ -64,9 +64,9 @@ describe('recovery codes', () => {
assert.equal(args[1], 8, 'called with recovery code count')
assert.equal(log.info.callCount, 1)
args = log.info.args[0][0]
assert.equal(args.op, 'account.recoveryCode.replaced')
assert.equal(args.uid, UID)
args = log.info.args[0]
assert.equal(args[0], 'account.recoveryCode.replaced')
assert.equal(args[1].uid, UID)
})
})

Просмотреть файл

@ -52,8 +52,8 @@ describe('POST /recoveryKey', () => {
it('called log.info correctly', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.equal(args.length, 1)
assert.equal(args[0]['op'], 'account.recoveryKey.created')
assert.equal(args.length, 2)
assert.equal(args[0], 'account.recoveryKey.created')
})
it('called request.emitMetricsEvent correctly', () => {

Просмотреть файл

@ -613,9 +613,9 @@ describe('/sms/status', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.getGeoData',
assert.equal(args.length, 2)
assert.equal(args[0], 'sms.getGeoData')
assert.deepEqual(args[1], {
err: 'missing location data'
})
})
@ -649,9 +649,9 @@ describe('/sms/status', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.getGeoData',
assert.equal(args.length, 2)
assert.equal(args[0], 'sms.getGeoData')
assert.deepEqual(args[1], {
err: 'missing location data'
})
})
@ -698,9 +698,9 @@ describe('/sms/status with disabled geo-ip lookup', () => {
it('called log.warn correctly', () => {
assert.equal(log.warn.callCount, 1)
const args = log.warn.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.getGeoData',
assert.equal(args.length, 2)
assert.equal(args[0], 'sms.getGeoData')
assert.deepEqual(args[1], {
warning: 'skipping geolocation step'
})
})

Просмотреть файл

@ -47,8 +47,8 @@ describe('/session/verify/token', () => {
it('called log.info correctly', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.equal(args.length, 1)
assert.equal(args[0]['op'], 'account.token.code.verified')
assert.equal(args.length, 2)
assert.equal(args[0], 'account.token.code.verified')
})
})
@ -90,8 +90,8 @@ describe('/session/verify/token', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.equal(args[0]['op'], 'account.token.code.expired')
assert.equal(args.length, 2)
assert.equal(args[0], 'account.token.code.expired')
})
})
})

Просмотреть файл

@ -400,7 +400,7 @@ describe('checkCustomsAndLoadAccount', () => {
assert.calledWithExactly(request.emitMetricsEvent.getCall(1), 'account.login.invalidUnblockCode')
assert.calledOnce(log.info)
assert.calledWithMatch(log.info, { op: 'Account.login.unblockCode.expired'})
assert.calledWithMatch(log.info, 'Account.login.unblockCode.expired')
assert.calledOnce(customs.flag)
assert.calledWithExactly(customs.flag, CLIENT_ADDRESS, {

Просмотреть файл

@ -59,8 +59,8 @@ describe('require:', () => {
}
assert.equal(threw, true)
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'safeUrl.params.mismatch',
assert.equal(log.error.args[0][0], 'safeUrl.params.mismatch')
assert.deepEqual(log.error.args[0][1], {
keys: [],
expected: [ 'bar' ],
caller: 'baz'
@ -70,8 +70,8 @@ describe('require:', () => {
it('logs an error and throws when param has wrong key', () => {
assert.throws(() => safeUrl.render({ qux: 'wibble' }))
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
op: 'safeUrl.params.unexpected',
assert.equal(log.error.args[0][0], 'safeUrl.params.unexpected')
assert.deepEqual(log.error.args[0][1], {
key: 'qux',
expected: [ 'bar' ],
caller: 'baz'
@ -93,9 +93,9 @@ describe('require:', () => {
}
assert.equal(threw, true)
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
assert.equal(log.error.args[0][0], 'safeUrl.bad')
assert.deepEqual(log.error.args[0][1], {
location: 'paramVal',
op: 'safeUrl.bad',
key: 'bar',
value: '',
caller: 'baz'
@ -105,9 +105,9 @@ describe('require:', () => {
it('logs an error and throws when param is object', () => {
assert.throws(() => safeUrl.render({ bar: {} }))
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
assert.equal(log.error.args[0][0], 'safeUrl.bad')
assert.deepEqual(log.error.args[0][1], {
location: 'paramVal',
op: 'safeUrl.bad',
key: 'bar',
value: {},
caller: 'baz'
@ -118,9 +118,9 @@ describe('require:', () => {
it(`logs an error and throws when param contains ${grapheme}`, () => {
assert.throws(() => safeUrl.render({ bar: `wibble${grapheme}` }))
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
assert.equal(log.error.args[0][0], 'safeUrl.unsafe')
assert.deepEqual(log.error.args[0][1], {
location: 'paramVal',
op: 'safeUrl.unsafe',
key: 'bar',
value: `wibble${grapheme}`,
caller: 'baz'
@ -143,9 +143,9 @@ describe('require:', () => {
}
assert.equal(threw, true)
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
assert.equal(log.error.args[0][0], 'safeUrl.unsafe')
assert.deepEqual(log.error.args[0][1], {
location: 'queryKey',
op: 'safeUrl.unsafe',
key: '💩',
value: '💩',
caller: 'baz'
@ -155,9 +155,9 @@ describe('require:', () => {
it('logs an error and throws for bad query values', () => {
assert.throws(() => safeUrl.render({ bar: 'baz' }, {'bar': '💩'}))
assert.equal(log.error.callCount, 1)
assert.deepEqual(log.error.args[0][0], {
assert.equal(log.error.args[0][0], 'safeUrl.unsafe')
assert.deepEqual(log.error.args[0][1], {
location: 'queryVal',
op: 'safeUrl.unsafe',
key: 'bar',
value: '💩',
caller: 'baz'

Просмотреть файл

@ -897,17 +897,17 @@ describe(
return mailer.send(message)
.then(() => {
assert.equal(mockLog.info.callCount, 3, 'calls log emailEvent')
assert.equal(mockLog.info.callCount, 3)
const emailEventLog = mockLog.info.getCalls()[2]
assert.equal(emailEventLog.args[0].op, 'emailEvent', 'logs emailEvent')
assert.equal(emailEventLog.args[0].domain, 'other', 'logs domain')
assert.equal(emailEventLog.args[0].flow_id, 'wibble', 'logs flow id')
assert.equal(emailEventLog.args[0].template, 'verifyLoginEmail', 'logs correct template')
assert.equal(emailEventLog.args[0].type, 'sent', 'logs correct type')
assert.equal(emailEventLog.args[0].locale, 'en')
assert.equal(emailEventLog.args[0], 'emailEvent')
assert.equal(emailEventLog.args[1].domain, 'other')
assert.equal(emailEventLog.args[1].flow_id, 'wibble')
assert.equal(emailEventLog.args[1].template, 'verifyLoginEmail')
assert.equal(emailEventLog.args[1].type, 'sent')
assert.equal(emailEventLog.args[1].locale, 'en')
const mailerSend1 = mockLog.info.getCalls()[1]
assert.equal(mailerSend1.args[0].op, 'mailer.send.1', 'logs mailer.send.1')
assert.equal(mailerSend1.args[0].to, message.email, 'logs sender to email address')
assert.equal(mailerSend1.args[0], 'mailer.send.1')
assert.equal(mailerSend1.args[1].to, message.email)
})
})
})
@ -1653,8 +1653,10 @@ describe(
emailSender: 'ses'
}])
assert.equal(mockLog.error.callCount, 1)
assert.deepEqual(mockLog.error.args[0][0], {
op: 'emailConfig.read.error',
const args = mockLog.error.args[0]
assert.equal(args.length, 2)
assert.equal(args[0], 'emailConfig.read.error')
assert.deepEqual(args[1], {
err: 'wibble'
})
})
@ -1676,7 +1678,7 @@ describe(
emailSender: 'ses'
}])
assert.equal(mockLog.error.callCount, 1)
assert.deepEqual(mockLog.error.args[0][0].op, 'emailConfig.parse.error')
assert.equal(mockLog.error.args[0][0], 'emailConfig.parse.error')
})
})
})

Просмотреть файл

@ -306,10 +306,10 @@ describe('lib/senders/index', () => {
assert.equal(e.errno, error.ERRNO.BOUNCE_COMPLAINT)
assert.ok(log.info.callCount >= 2)
const msg = log.info.args[1][0]
assert.equal(msg.op, 'mailer.blocked')
assert.equal(msg.errno, e.errno)
assert.equal(msg.bouncedAt, DATE)
const msg = log.info.args[1]
assert.equal(msg[0], 'mailer.blocked')
assert.equal(msg[1].errno, e.errno)
assert.equal(msg[1].bouncedAt, DATE)
})
})
@ -365,10 +365,10 @@ describe('lib/senders/index', () => {
assert.equal(e.errno, error.ERRNO.BOUNCE_COMPLAINT)
assert.ok(log.info.callCount >= 2)
const msg = log.info.args[1][0]
assert.equal(msg.op, 'mailer.blocked')
assert.equal(msg.errno, e.errno)
assert.equal(msg.bouncedAt, DATE)
const msg = log.info.args[1]
assert.equal(msg[0], 'mailer.blocked')
assert.equal(msg[1].errno, e.errno)
assert.equal(msg[1].bouncedAt, DATE)
})
.finally(() => {
EMAILS[1].isVerified = true

Просмотреть файл

@ -89,16 +89,16 @@ describe('lib/senders/oauth_client_info:', () => {
})
return fetch('24bdbfa45cd300c5').then((res) => {
assert.deepEqual(res, OAUTH_CLIENT)
assert.equal(mockLog.trace.getCall(0).args[0].op, 'fetch.start')
assert.equal(mockLog.trace.getCall(1).args[0].op, 'fetch.usedServer')
assert.equal(mockLog.trace.getCall(0).args[0], 'fetch.start')
assert.equal(mockLog.trace.getCall(1).args[0], 'fetch.usedServer')
assert.equal(mockLog.trace.getCall(2), null)
assert.ok(mockOAuthDB.getClientInfo.calledOnce)
// second call is cached
return fetch('24bdbfa45cd300c5')
}).then((res) => {
assert.equal(mockLog.trace.getCall(2).args[0].op, 'fetch.start')
assert.equal(mockLog.trace.getCall(3).args[0].op, 'fetch.usedCache')
assert.equal(mockLog.trace.getCall(2).args[0], 'fetch.start')
assert.equal(mockLog.trace.getCall(3).args[0], 'fetch.usedCache')
assert.ok(mockOAuthDB.getClientInfo.calledOnce)
assert.deepEqual(res, OAUTH_CLIENT)
})
@ -112,13 +112,13 @@ describe('lib/senders/oauth_client_info:', () => {
})
return P.delay(15, fetch('24bdbfa45cd300c5')).then((res) => {
assert.deepEqual(res, OAUTH_CLIENT)
assert.equal(mockLog.trace.getCall(1).args[0].op, 'fetch.usedServer')
assert.equal(mockLog.trace.getCall(1).args[0], 'fetch.usedServer')
assert.ok(mockOAuthDB.getClientInfo.calledOnce)
// second call uses server, cache expired
return fetch('24bdbfa45cd300c5')
}).then((res) => {
assert.equal(mockLog.trace.getCall(3).args[0].op, 'fetch.usedServer')
assert.equal(mockLog.trace.getCall(3).args[0], 'fetch.usedServer')
assert.ok(mockOAuthDB.getClientInfo.calledTwice)
assert.deepEqual(res, OAUTH_CLIENT)
})

Просмотреть файл

@ -122,9 +122,9 @@ describe('lib/senders/sms:', () => {
it('called log.info correctly', () => {
assert.equal(log.info.callCount, 1)
const args = log.info.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.budget.ok',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.budget.ok')
assert.deepEqual(args[1], {
isBudgetOk: true,
current: 0,
limit: config.sms.minimumCreditThresholdUSD,
@ -182,9 +182,9 @@ describe('lib/senders/sms:', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.budget.error',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.budget.error')
assert.deepEqual(args[1], {
err: 'Invalid getMetricStatistics result "wibble"',
result: undefined
})
@ -207,9 +207,9 @@ describe('lib/senders/sms:', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.budget.error',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.budget.error')
assert.deepEqual(args[1], {
err: 'Cannot read property \'Maximum\' of undefined',
result: JSON.stringify(results.getMetricStatistics)
})
@ -249,9 +249,9 @@ describe('lib/senders/sms:', () => {
it('called log.trace correctly', () => {
assert.equal(log.trace.callCount, 1)
const args = log.trace.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.send',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.send')
assert.deepEqual(args[1], {
templateName: 'installFirefox',
acceptLanguage: 'en'
})
@ -260,9 +260,9 @@ describe('lib/senders/sms:', () => {
it('called log.info correctly', () => {
assert.equal(log.info.callCount, 2)
const args = log.info.args[1]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.send.success',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.send.success')
assert.deepEqual(args[1], {
templateName: 'installFirefox',
acceptLanguage: 'en',
messageId: 'foo'
@ -309,9 +309,9 @@ describe('lib/senders/sms:', () => {
it('called log.error correctly', () => {
assert.equal(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'sms.getMessage.error',
assert.lengthOf(args, 2)
assert.equal(args[0], 'sms.getMessage.error')
assert.deepEqual(args[1], {
templateName: 'wibble'
})
})

Просмотреть файл

@ -35,8 +35,8 @@ describe('lib/server', () => {
it('logs an endpoint error', (done) => {
const mockLog = {
error: (err) => {
assert.equal(err.op, 'server.EndpointError')
error: (op, err) => {
assert.equal(op, 'server.EndpointError')
assert.equal(err.message, msg)
assert.equal(err.reason, reason)
done()
@ -51,8 +51,8 @@ describe('lib/server', () => {
}
const mockLog = {
error: (err) => {
assert.equal(err.op, 'server.EndpointError')
error: (op, err) => {
assert.equal(op, 'server.EndpointError')
assert.equal(err.message, msg)
assert.equal(err.reason, reason)
assert.equal(err.method, 'PUT')
@ -391,9 +391,9 @@ describe('lib/server', () => {
it('called log.error correctly', () => {
assert.isAtLeast(log.error.callCount, 1)
const args = log.error.args[0]
assert.equal(args.length, 1)
assert.deepEqual(args[0], {
op: 'server.EndpointError',
assert.equal(args.length, 2)
assert.equal(args[0], 'server.EndpointError')
assert.deepEqual(args[1], {
message: 'request failed',
reason: 'because i said so'
})

Просмотреть файл

@ -29,11 +29,11 @@ describe('send-email-batch', () => {
it('calls log as expected', () => {
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[0][0].op, 'send.success')
assert.equal(log.info.args[1][0].op, 'send.success')
assert.equal(log.info.args[0][0], 'send.success')
assert.equal(log.info.args[1][0], 'send.success')
assert.isTrue(log.error.calledOnce)
assert.equal(log.error.args[0][0].op, 'send.error')
assert.equal(log.error.args[0][0], 'send.error')
})
it('calls the sender as expected', () => {

Просмотреть файл

@ -53,13 +53,13 @@ describe('send-email-batches', () => {
it('calls log as expected', () => {
assert.equal(log.info.callCount, 2)
assert.equal(log.info.args[0][0].op, 'send.begin')
assert.equal(log.info.args[0][0], 'send.begin')
assert.equal(log.info.args[1][0].op, 'send.complete')
assert.equal(log.info.args[1][0].count, 4)
assert.equal(log.info.args[1][0].successCount, 3)
assert.equal(log.info.args[1][0].errorCount, 1)
assert.equal(log.info.args[1][0].unsentCount, 0)
assert.equal(log.info.args[1][0], 'send.complete')
assert.equal(log.info.args[1][1].count, 4)
assert.equal(log.info.args[1][1].successCount, 3)
assert.equal(log.info.args[1][1].errorCount, 1)
assert.equal(log.info.args[1][1].unsentCount, 0)
})
it('calls sendEmailBatchSpy as expected', () => {