diff --git a/lib/handlers/on-copy.js b/lib/handlers/on-copy.js index d4d21f2..896b345 100644 --- a/lib/handlers/on-copy.js +++ b/lib/handlers/on-copy.js @@ -77,11 +77,12 @@ module.exports = (server, messageHandler) => (mailbox, update, session, callback if (r && r.value) { server.loggelf({ - short_message: '[QUOTA CHANGE]', + short_message: '[QUOTA CHANGE] Quota usage increased', + _mail_action: 'quota', _user: mailboxData.user, _inc: -copiedStorage, _copied_messages: copiedMessages, - _storageUsed: r.value.storageUsed, + _storage_used: r.value.storageUsed, _session: session && session.id }); } diff --git a/lib/message-handler.js b/lib/message-handler.js index 8c53edf..5a0064e 100644 --- a/lib/message-handler.js +++ b/lib/message-handler.js @@ -234,6 +234,7 @@ class MessageHandler { // join lines .replace(/\s+/g, ' ') .trim(); + if (messageData.intro.length > 128) { let intro = messageData.intro.substr(0, 128); let lastSp = intro.lastIndexOf(' '); @@ -286,10 +287,11 @@ class MessageHandler { if (r && r.value) { this.loggelf({ - short_message: '[QUOTA CHANGE]', + short_message: '[QUOTA CHANGE] Quota usage increased', + _mail_action: 'quota', _user: mailboxData.user, _inc: size, - _storageUsed: r.value.storageUsed, + _storage_used: r.value.storageUsed, _session: options.session && options.session.id }); } @@ -315,10 +317,11 @@ class MessageHandler { if (r && r.value) { this.loggelf({ - short_message: '[QUOTA CHANGE]', + short_message: '[QUOTA CHANGE] Quota usage decreased', + _mail_action: 'quota', _user: mailboxData.user, _inc: -size, - _storageUsed: r.value.storageUsed, + _storage_used: r.value.storageUsed, _session: options.session && options.session.id, _rollback: 'yes', _error: err.message, @@ -466,10 +469,11 @@ class MessageHandler { if (r && r.value) { this.loggelf({ - short_message: '[QUOTA CHANGE]', + short_message: '[QUOTA CHANGE] Quota usage ' + (Number(inc.storageUsed) || 0 < 0 ? 'decreased' : 'increased'), + _mail_action: 'quota', _user: user, _inc: inc.storageUsed, - _storageUsed: r.value.storageUsed, + _storage_used: r.value.storageUsed, _session: options.session && options.session.id }); } diff --git a/lib/tasks/quota.js b/lib/tasks/quota.js index df0dc94..38ed3a2 100644 --- a/lib/tasks/quota.js +++ b/lib/tasks/quota.js @@ -59,7 +59,7 @@ module.exports = (taskData, options, callback) => { return setImmediate(processNext); } - db.users.collection('users').updateOne( + db.users.collection('users').findOneAndUpdate( { _id: userData._id }, @@ -68,11 +68,30 @@ module.exports = (taskData, options, callback) => { storageUsed: Number(storageUsed) || 0 } }, + { + returnOriginal: true, + projection: { + storageUsed: true + } + }, (err, r) => { if (err) { log.error('Tasks', 'task=quota id=%s user=%s error=%s', taskData._id, userData._id, err.message); return setTimeout(processNext, 5000); } + + if (r && r.value) { + options.loggelf({ + short_message: '[QUOTA CHANGE] Quota usage recalculated', + _mail_action: 'quota', + _user: userData._id, + _set: Number(storageUsed) || 0, + _previous_storage_used: r.value.storageUsed, + _storage_used: Number(storageUsed) || 0, + _session: 'task.quota.' + taskData._id + }); + } + log.info( 'Tasks', 'task=quota id=%s user=%s stored=%s calculated=%s updated=%s', @@ -80,7 +99,7 @@ module.exports = (taskData, options, callback) => { userData._id, userData.storageUsed, storageUsed, - r.modifiedCount ? 'yes' : 'no' + r.lastErrorObject && r.lastErrorObject.updatedExisting ? 'yes' : 'no' ); return setImmediate(processNext); } diff --git a/tasks.js b/tasks.js index 6a0a275..f0603a8 100644 --- a/tasks.js +++ b/tasks.js @@ -9,6 +9,8 @@ const yaml = require('js-yaml'); const fs = require('fs'); const MessageHandler = require('./lib/message-handler'); const setupIndexes = yaml.safeLoad(fs.readFileSync(__dirname + '/indexes.yaml', 'utf8')); +const Gelf = require('gelf'); +const os = require('os'); const taskRestore = require('./lib/tasks/restore'); const taskUserDelete = require('./lib/tasks/user-delete'); @@ -18,12 +20,52 @@ let messageHandler; let gcTimeout; let taskTimeout; let gcLock; +let loggelf; module.exports.start = callback => { if (!config.tasks.enabled) { return setImmediate(() => callback(null, false)); } + const component = config.log.gelf.component || 'wildduck'; + const hostname = config.log.gelf.hostname || os.hostname(); + const gelf = + config.log.gelf && config.log.gelf.enabled + ? new Gelf(config.log.gelf.options) + : { + // placeholder + emit: () => false + }; + + loggelf = message => { + if (typeof message === 'string') { + message = { + short_message: message + }; + } + + message = message || {}; + + if (!message.short_message || message.short_message.indexOf(component.toUpperCase()) !== 0) { + message.short_message = component.toUpperCase() + ' ' + (message.short_message || ''); + } + + message.facility = component; // facility is deprecated but set by the driver if not provided + message.host = hostname; + message.timestamp = Date.now() / 1000; + message._component = component; + Object.keys(message).forEach(key => { + if (!message[key]) { + delete message[key]; + } + }); + try { + gelf.emit('gelf.log', message); + } catch (err) { + log.error('Gelf', err); + } + }; + gcLock = new RedFour({ redis: db.redis, namespace: 'wildduck' @@ -454,7 +496,8 @@ function processTask(taskData, callback) { return taskRestore( taskData, { - messageHandler + messageHandler, + loggelf }, err => { if (err) { @@ -465,7 +508,7 @@ function processTask(taskData, callback) { } ); case 'user-delete': - return taskUserDelete(taskData, {}, err => { + return taskUserDelete(taskData, { loggelf }, err => { if (err) { return callback(err); } @@ -473,7 +516,7 @@ function processTask(taskData, callback) { callback(null, true); }); case 'quota': - return taskQuota(taskData, {}, err => { + return taskQuota(taskData, { loggelf }, err => { if (err) { return callback(err); }