From dce872fac8166f8102d197ef86bafb67395f1797 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Fri, 8 Jul 2016 17:13:30 -0700 Subject: [PATCH 01/24] Adds bunyan for json logging on every package! - Bunyan logs json output, and added a stream to send our logs to cloudwatch - Replaces /all/ instances of console.log. Turned eslint rule back on, so we don't use console.log ever again. - Added npm scripts to view pretty logs --- .eslintrc | 1 - README.md | 4 +- package.json | 8 ++- packages/nylas-api/app.js | 6 +- packages/nylas-api/decorators/connections.js | 3 + packages/nylas-api/routes/auth.js | 4 +- packages/nylas-api/routes/files.js | 17 +++--- packages/nylas-api/routes/messages.js | 9 +-- packages/nylas-api/routes/ping.js | 4 +- packages/nylas-core/imap-connection.js | 19 ++++-- packages/nylas-core/index.js | 1 + packages/nylas-core/logger.js | 52 ++++++++++++++++ packages/nylas-core/models/account/file.js | 4 +- packages/nylas-core/models/account/message.js | 4 +- packages/nylas-core/package.json | 1 + packages/nylas-core/pubsub-connector.js | 4 +- packages/nylas-core/scheduler-utils.js | 8 ++- packages/nylas-dashboard/app.js | 5 +- packages/nylas-message-processor/app.js | 29 ++++----- .../processors/parsing.js | 4 +- .../processors/threading.js | 11 +++- .../spec/threading-spec.js | 1 - packages/nylas-sync/app.js | 9 +-- ...-category-list.js => fetch-folder-list.js} | 3 +- ...ategory.js => fetch-messages-in-folder.js} | 60 +++++++++++++------ packages/nylas-sync/sync-process-manager.js | 18 +++--- packages/nylas-sync/sync-worker.js | 28 +++++---- pm2-dev.yml | 10 ++-- 28 files changed, 216 insertions(+), 111 deletions(-) create mode 100644 packages/nylas-core/logger.js rename packages/nylas-sync/imap/{fetch-category-list.js => fetch-folder-list.js} (97%) rename packages/nylas-sync/imap/{fetch-messages-in-category.js => fetch-messages-in-folder.js} (84%) diff --git a/.eslintrc b/.eslintrc index 1128872ff..d712529ce 100644 --- a/.eslintrc +++ b/.eslintrc @@ -17,7 +17,6 @@ "object-curly-spacing": "off", "max-len": "off", "new-cap": ["error", {"capIsNew": false}], - "no-console": "off", "no-constant-condition": "off", "no-loop-func": "off", "no-shadow": "error", diff --git a/README.md b/README.md index 83e953c62..76f21b673 100644 --- a/README.md +++ b/README.md @@ -28,7 +28,9 @@ # Developing Locally: ``` -npm start +npm run start +npm run logs +npm run stop ``` We use [pm2](http://pm2.keymetrics.io/) to launch a variety of processes diff --git a/package.json b/package.json index c73ac7f1a..411c58799 100644 --- a/package.json +++ b/package.json @@ -5,6 +5,8 @@ "main": "", "dependencies": { "bluebird": "3.x.x", + "bunyan": "^1.8.1", + "bunyan-cloudwatch": "^2.0.0", "lerna": "2.0.0-beta.23", "mysql": "^2.11.1", "newrelic": "^1.28.1", @@ -25,8 +27,10 @@ "sqlite3": "https://github.com/bengotow/node-sqlite3/archive/bengotow/usleep-v3.1.4.tar.gz" }, "scripts": { - "start": "./node_modules/pm2/bin/pm2 start ./pm2-dev.yml --no-daemon", - "postinstall": "node_modules/.bin/lerna bootstrap" + "start": "pm2 start ./pm2-dev.yml", + "logs": "pm2 logs --raw | bunyan -o short", + "stop": "pm2 delete all", + "postinstall": "lerna bootstrap" }, "repository": { "type": "git", diff --git a/packages/nylas-api/app.js b/packages/nylas-api/app.js index bca30c9af..d6fab7358 100644 --- a/packages/nylas-api/app.js +++ b/packages/nylas-api/app.js @@ -7,8 +7,10 @@ const Vision = require('vision'); const Package = require('./package'); const fs = require('fs'); const path = require('path'); +const {DatabaseConnector, SchedulerUtils, Logger} = require(`nylas-core`); global.Promise = require('bluebird'); +global.Logger = Logger.createLogger('nylas-k2-api') const server = new Hapi.Server({ connections: { @@ -33,8 +35,6 @@ const plugins = [Inert, Vision, HapiBasicAuth, HapiBoom, { let sharedDb = null; const validate = (request, username, password, callback) => { - const {DatabaseConnector, SchedulerUtils} = require(`nylas-core`); - let getSharedDb = null; if (sharedDb) { getSharedDb = Promise.resolve(sharedDb) @@ -88,6 +88,6 @@ server.register(plugins, (err) => { server.start((startErr) => { if (startErr) { throw startErr; } - console.log('API running at:', server.info.uri); + global.Logger.info({url: server.info.uri}, 'API running'); }); }); diff --git a/packages/nylas-api/decorators/connections.js b/packages/nylas-api/decorators/connections.js index 2003696cf..f0fe1d437 100644 --- a/packages/nylas-api/decorators/connections.js +++ b/packages/nylas-api/decorators/connections.js @@ -7,4 +7,7 @@ module.exports = (server) => { const account = this.auth.credentials; return DatabaseConnector.forAccount(account.id); }); + server.decorate('request', 'logger', (request) => { + return global.Logger.forAccount(request.auth.credentials) + }, {apply: true}); } diff --git a/packages/nylas-api/routes/auth.js b/packages/nylas-api/routes/auth.js index fd14f4fc5..65c776927 100644 --- a/packages/nylas-api/routes/auth.js +++ b/packages/nylas-api/routes/auth.js @@ -97,7 +97,7 @@ module.exports = (server) => { const {settings, email, provider, name} = request.payload; if (provider === 'imap') { - connectionChecks.push(IMAPConnection.connect(dbStub, settings)) + connectionChecks.push(IMAPConnection.connect({db: dbStub, settings})) } Promise.all(connectionChecks).then(() => { @@ -188,7 +188,7 @@ module.exports = (server) => { } Promise.all([ - IMAPConnection.connect({}, Object.assign({}, settings, credentials)), + IMAPConnection.connect({db: {}, settings: Object.assign({}, settings, credentials)}), ]) .then(() => buildAccountWith({ diff --git a/packages/nylas-api/routes/files.js b/packages/nylas-api/routes/files.js index e22975daf..46f7ee980 100644 --- a/packages/nylas-api/routes/files.js +++ b/packages/nylas-api/routes/files.js @@ -73,9 +73,7 @@ module.exports = (server) => { }, handler: (request, reply) => { request.getAccountDatabase().then(({File}) => { - const {headers: {accept}} = request const {params: {id}} = request - const account = request.auth.credentials File.findOne({where: {id}}).then((file) => { if (!file) { @@ -83,9 +81,9 @@ module.exports = (server) => { } return reply(Serialization.jsonStringify(file)); }) - .catch((error) => { - console.log('Error fetching file: ', error) - reply(error) + .catch((err) => { + request.logger.error(err, 'Error fetching file') + reply(err) }) }) }, @@ -107,7 +105,6 @@ module.exports = (server) => { handler: (request, reply) => { request.getAccountDatabase() .then((db) => { - const {headers: {accept}} = request const {params: {id}} = request const account = request.auth.credentials @@ -116,12 +113,12 @@ module.exports = (server) => { if (!file) { return reply.notFound(`File ${id} not found`) } - return file.fetch({account, db}) + return file.fetch({account, db, logger: request.logger}) .then((stream) => reply(stream)) }) - .catch((error) => { - console.log('Error fetching file: ', error) - reply(error) + .catch((err) => { + request.logger.error(err, 'Error downloading file') + reply(err) }) }) }, diff --git a/packages/nylas-api/routes/messages.js b/packages/nylas-api/routes/messages.js index c5efda964..474f773fe 100644 --- a/packages/nylas-api/routes/messages.js +++ b/packages/nylas-api/routes/messages.js @@ -123,15 +123,16 @@ module.exports = (server) => { return reply.notFound(`Message ${id} not found`) } if (accept === 'message/rfc822') { - return message.fetchRaw({account, db}).then((rawMessage) => + return message.fetchRaw({account, db, logger: request.logger}) + .then((rawMessage) => reply(rawMessage) ) } return reply(Serialization.jsonStringify(message)); }) - .catch((error) => { - console.log('Error fetching message: ', error) - reply(error) + .catch((err) => { + request.logger.error(err, 'Error fetching message') + reply(err) }) }) }, diff --git a/packages/nylas-api/routes/ping.js b/packages/nylas-api/routes/ping.js index a2c9e82e4..0e7072f78 100644 --- a/packages/nylas-api/routes/ping.js +++ b/packages/nylas-api/routes/ping.js @@ -6,8 +6,8 @@ module.exports = (server) => { auth: false, }, handler: (request, reply) => { - console.log("---> Ping!") - reply("pong") + request.logger.info('----> Pong!') + reply("Pong") }, }); }; diff --git a/packages/nylas-core/imap-connection.js b/packages/nylas-core/imap-connection.js index ac1eedb73..05e703b49 100644 --- a/packages/nylas-core/imap-connection.js +++ b/packages/nylas-core/imap-connection.js @@ -176,8 +176,9 @@ class IMAPConnection extends EventEmitter { return new IMAPConnection(...args).connect() } - constructor(db, settings) { + constructor({db, settings, logger = console} = {}) { super(); + this._logger = logger; this._db = db; this._queue = []; this._currentOperation = null; @@ -231,13 +232,13 @@ class IMAPConnection extends EventEmitter { this._imap = Promise.promisifyAll(new Imap(settings)); this._imap.once('end', () => { - console.log('Underlying IMAP Connection ended'); + this._logger.info('Underlying IMAP Connection ended'); this._connectPromise = null; this._imap = null; }); this._imap.on('alert', (msg) => { - console.log(`IMAP SERVER SAYS: ${msg}`) + this._logger.info({imap_server_msg: msg}, `IMAP server message`) }) // Emitted when new mail arrives in the currently open mailbox. @@ -346,14 +347,20 @@ class IMAPConnection extends EventEmitter { result.then(() => { this._currentOperation = null; - console.log(`Finished task: ${operation.description()}`) + this._logger.info({ + operation_type: operation.constructor.name, + operation_description: operation.description(), + }, `Finished sync operation`) resolve(); this.processNextOperation(); }) .catch((err) => { this._currentOperation = null; - console.log(`Task errored: ${operation.description()}`) - console.error(err) + this._logger.error({ + err, + operation_type: operation.constructor.name, + operation_description: operation.description(), + }, `Sync operation errored`) reject(err); }) } diff --git a/packages/nylas-core/index.js b/packages/nylas-core/index.js index d8ac0b59a..3282ce9a3 100644 --- a/packages/nylas-core/index.js +++ b/packages/nylas-core/index.js @@ -11,4 +11,5 @@ module.exports = { SyncPolicy: require('./sync-policy'), SchedulerUtils: require('./scheduler-utils'), MessageTypes: require('./message-types'), + Logger: require('./logger'), } diff --git a/packages/nylas-core/logger.js b/packages/nylas-core/logger.js new file mode 100644 index 000000000..aaa885fb4 --- /dev/null +++ b/packages/nylas-core/logger.js @@ -0,0 +1,52 @@ +const bunyan = require('bunyan') +const createCWStream = require('bunyan-cloudwatch') +const NODE_ENV = process.env.NODE_ENV || 'unknown' + + +function getLogStreams(name, env) { + const stdoutStream = { + stream: process.stdout, + level: 'info', + } + if (env === 'development') { + return [stdoutStream] + } + + const cloudwatchStream = { + stream: createCWStream({ + logGroup: `k2-${env}`, + logStream: `${name}-${env}`, + cloudWatchLogsOptions: { + region: 'us-east-1', + }, + }), + type: 'raw', + } + return [stdoutStream, cloudwatchStream] +} + +function createLogger(name, env = NODE_ENV) { + const childLogs = new Map() + const logger = bunyan.createLogger({ + name, + serializers: bunyan.stdSerializers, + streams: getLogStreams(name, env), + }) + + return Object.assign(logger, { + forAccount(account = {}) { + if (!childLogs.has(account.id)) { + const childLog = logger.child({ + account_id: account.id, + account_email: account.emailAddress, + }) + childLogs.set(account.id, childLog) + } + return childLogs.get(account.id) + }, + }) +} + +module.exports = { + createLogger, +} diff --git a/packages/nylas-core/models/account/file.js b/packages/nylas-core/models/account/file.js index 5043318e8..655e8b13d 100644 --- a/packages/nylas-core/models/account/file.js +++ b/packages/nylas-core/models/account/file.js @@ -15,11 +15,11 @@ module.exports = (sequelize, Sequelize) => { }, }, instanceMethods: { - fetch: function fetch({account, db}) { + fetch: function fetch({account, db, logger}) { const settings = Object.assign({}, account.connectionSettings, account.decryptedCredentials()) return Promise.props({ message: this.getMessage(), - connection: IMAPConnection.connect(db, settings), + connection: IMAPConnection.connect({db, settings, logger}), }) .then(({message, connection}) => { return message.getFolder() diff --git a/packages/nylas-core/models/account/message.js b/packages/nylas-core/models/account/message.js index 80bf1b5b5..e5fffdacc 100644 --- a/packages/nylas-core/models/account/message.js +++ b/packages/nylas-core/models/account/message.js @@ -69,11 +69,11 @@ module.exports = (sequelize, Sequelize) => { ) }, - fetchRaw: function fetchRaw({account, db}) { + fetchRaw: function fetchRaw({account, db, logger}) { const settings = Object.assign({}, account.connectionSettings, account.decryptedCredentials()) return Promise.props({ folder: this.getFolder(), - connection: IMAPConnection.connect(db, settings), + connection: IMAPConnection.connect({db, settings, logger}), }) .then(({folder, connection}) => { return connection.openBox(folder.name) diff --git a/packages/nylas-core/package.json b/packages/nylas-core/package.json index fa5d9cc27..3c151ff87 100644 --- a/packages/nylas-core/package.json +++ b/packages/nylas-core/package.json @@ -4,6 +4,7 @@ "description": "Core shared packages", "main": "index.js", "dependencies": { + "bunyan": "^1.8.1", "imap": "0.8.x", "xoauth2": "1.x.x" }, diff --git a/packages/nylas-core/pubsub-connector.js b/packages/nylas-core/pubsub-connector.js index 76df1df5d..36121688a 100644 --- a/packages/nylas-core/pubsub-connector.js +++ b/packages/nylas-core/pubsub-connector.js @@ -1,9 +1,11 @@ const Rx = require('rx') const redis = require("redis"); +const log = global.Logger || console Promise.promisifyAll(redis.RedisClient.prototype); Promise.promisifyAll(redis.Multi.prototype); + class PubsubConnector { constructor() { this._broadcastClient = null; @@ -13,7 +15,7 @@ class PubsubConnector { buildClient() { const client = redis.createClient(process.env.REDIS_URL || null); - client.on("error", console.error); + client.on("error", log.error); return client; } diff --git a/packages/nylas-core/scheduler-utils.js b/packages/nylas-core/scheduler-utils.js index 55f8a4959..9b719f0ba 100644 --- a/packages/nylas-core/scheduler-utils.js +++ b/packages/nylas-core/scheduler-utils.js @@ -22,7 +22,9 @@ const forEachAccountList = (forEachCallback) => { } const assignPolicy = (accountId, policy) => { - console.log(`Changing policy for ${accountId} to ${JSON.stringify(policy)}`) + const log = global.Logger || console + log.info({policy, account_id: accountId}, `Changing single policy`) + const DatabaseConnector = require('./database-connector'); return DatabaseConnector.forShared().then(({Account}) => { Account.find({where: {id: accountId}}).then((account) => { @@ -33,7 +35,9 @@ const assignPolicy = (accountId, policy) => { } const assignPolicyToAcounts = (accountIds, policy) => { - console.log(`Changing policy for ${accountIds} to ${JSON.stringify(policy)}`) + const log = global.Logger || console + log.info({policy, account_ids: accountIds}, `Changing multiple policies`) + const DatabaseConnector = require('./database-connector'); return DatabaseConnector.forShared().then(({Account}) => { Account.findAll({where: {id: {$or: accountIds}}}).then((accounts) => { diff --git a/packages/nylas-dashboard/app.js b/packages/nylas-dashboard/app.js index 2ee772b4a..dbd02d606 100644 --- a/packages/nylas-dashboard/app.js +++ b/packages/nylas-dashboard/app.js @@ -1,11 +1,12 @@ const Hapi = require('hapi'); const HapiWebSocket = require('hapi-plugin-websocket'); const Inert = require('inert'); -const {DatabaseConnector, PubsubConnector, SchedulerUtils} = require(`nylas-core`); +const {DatabaseConnector, PubsubConnector, SchedulerUtils, Logger} = require(`nylas-core`); const fs = require('fs'); const path = require('path'); global.Promise = require('bluebird'); +global.Logger = Logger.createLogger('nylas-k2-dashboard') const server = new Hapi.Server(); server.connection({ port: process.env.PORT }); @@ -98,6 +99,6 @@ server.register([HapiWebSocket, Inert], () => { server.start((startErr) => { if (startErr) { throw startErr; } - console.log('Dashboard running at:', server.info.uri); + global.Logger.info({uri: server.info.uri}, 'Dashboard running'); }); }); diff --git a/packages/nylas-message-processor/app.js b/packages/nylas-message-processor/app.js index 458a074e3..4ad7aee14 100644 --- a/packages/nylas-message-processor/app.js +++ b/packages/nylas-message-processor/app.js @@ -1,7 +1,8 @@ -const {PubsubConnector, DatabaseConnector} = require(`nylas-core`) +const {PubsubConnector, DatabaseConnector, Logger} = require(`nylas-core`) const {processors} = require('./processors') global.Promise = require('bluebird'); +global.Logger = Logger.createLogger('nylas-k2-message-processor') // List of the attributes of Message that the processor should be allowed to change. // The message may move between folders, get starred, etc. while it's being @@ -11,15 +12,13 @@ const MessageProcessorVersion = 1; const redis = PubsubConnector.buildClient(); -function runPipeline({db, accountId, message}) { - console.log(`Processing message ${message.id}`) +function runPipeline({db, accountId, message, logger}) { + logger.info(`MessageProcessor: Processing message`) return processors.reduce((prevPromise, processor) => ( prevPromise.then((prevMessage) => { - const processed = processor({message: prevMessage, accountId, db}); - if (!(processed instanceof Promise)) { - throw new Error(`processor ${processor} did not return a promise.`) - } - return processed.then((nextMessage) => { + const processed = processor({message: prevMessage, accountId, db, logger}); + return Promise.resolve(processed) + .then((nextMessage) => { if (!nextMessage.body) { throw new Error("processor did not resolve with a valid message object.") } @@ -46,26 +45,28 @@ function dequeueJob() { try { json = JSON.parse(item[1]); } catch (error) { - console.error(`MessageProcessor Failed: Found invalid JSON item in queue: ${item}`) + global.Logger.error({item}, `MessageProcessor: Found invalid JSON item in queue`) return dequeueJob(); } const {messageId, accountId} = json; + const logger = global.Logger.forAccount({id: accountId}).child({message_id: messageId}) - DatabaseConnector.forAccount(accountId).then((db) => - db.Message.find({ + DatabaseConnector.forAccount(accountId).then((db) => { + return db.Message.find({ where: {id: messageId}, include: [{model: db.Folder}, {model: db.Label}], }).then((message) => { if (!message) { return Promise.reject(new Error(`Message not found (${messageId}). Maybe account was deleted?`)) } - return runPipeline({db, accountId, message}).then((processedMessage) => + return runPipeline({db, accountId, message, logger}).then((processedMessage) => saveMessage(processedMessage) ).catch((err) => - console.error(`MessageProcessor Failed: ${err} ${err.stack}`) + logger.error(err, `MessageProcessor: Failed`) ) }) - ).finally(() => { + }) + .finally(() => { dequeueJob() }); diff --git a/packages/nylas-message-processor/processors/parsing.js b/packages/nylas-message-processor/processors/parsing.js index 6763437e0..a144199ab 100644 --- a/packages/nylas-message-processor/processors/parsing.js +++ b/packages/nylas-message-processor/processors/parsing.js @@ -11,7 +11,7 @@ function Contact({name, address} = {}) { const extractContacts = (values) => (values || []).map(v => Contact(mimelib.parseAddresses(v).pop())) -function processMessage({message}) { +function processMessage({message, logger}) { if (message.snippet) { // trim and clean snippet which is alreay present (from message plaintext) message.snippet = message.snippet.replace(/[\n\r]/g, ' ').replace(/\s\s+/g, ' ') @@ -24,7 +24,7 @@ function processMessage({message}) { // TODO: Fanciness message.snippet = message.body.substr(0, Math.min(message.body.length, SNIPPET_SIZE)); } else { - console.log("Received message has no body or snippet.") + logger.info("MessageProcessor: Parsing - Received message has no body or snippet.") } message.to = extractContacts(message.headers.to); diff --git a/packages/nylas-message-processor/processors/threading.js b/packages/nylas-message-processor/processors/threading.js index 57e896ec2..2f9c847fd 100644 --- a/packages/nylas-message-processor/processors/threading.js +++ b/packages/nylas-message-processor/processors/threading.js @@ -9,11 +9,14 @@ class ThreadingProcessor { // conversation. Put it back soonish. // const messageEmails = _.uniq([].concat(message.to, message.cc, message.from).map(p => p.email)); - // console.log(`Found ${threads.length} candidate threads for message with subject: ${message.subject}`) + // this.logger.info({ + // num_candidate_threads: threads.length, + // message_subject: message.subject, + // }, `Found candidate threads for message`) // // for (const thread of threads) { // const threadEmails = _.uniq([].concat(thread.participants).map(p => p.email)); - // console.log(`Intersection: ${_.intersection(threadEmails, messageEmails).join(',')}`) + // this.logger.info(`Intersection: ${_.intersection(threadEmails, messageEmails).join(',')}`) // // if (_.intersection(threadEmails, messageEmails) >= threadEmails.length * 0.9) { // return thread; @@ -66,7 +69,7 @@ class ThreadingProcessor { }) } - processMessage({db, message}) { + processMessage({db, message, logger}) { if (!(message.labels instanceof Array)) { throw new Error("Threading processMessage expects labels to be an inflated array."); } @@ -74,6 +77,8 @@ class ThreadingProcessor { throw new Error("Threading processMessage expects folder value to be present."); } + this.logger = logger + const {Folder, Label} = db; let findOrCreateThread = null; if (message.headers['x-gm-thrid']) { diff --git a/packages/nylas-message-processor/spec/threading-spec.js b/packages/nylas-message-processor/spec/threading-spec.js index b1df5d815..5e0aaa3ba 100644 --- a/packages/nylas-message-processor/spec/threading-spec.js +++ b/packages/nylas-message-processor/spec/threading-spec.js @@ -43,7 +43,6 @@ it('adds the message to the thread', (done) => { }, create: (message) => { message.setThread = (thread) => { - console.log("setting") message.thread = thread.id } return Promise.resolve(message) diff --git a/packages/nylas-sync/app.js b/packages/nylas-sync/app.js index 5d7319245..af70a66cb 100644 --- a/packages/nylas-sync/app.js +++ b/packages/nylas-sync/app.js @@ -1,16 +1,17 @@ global.Promise = require('bluebird'); - -const {DatabaseConnector} = require(`nylas-core`) +const {DatabaseConnector, Logger} = require(`nylas-core`) const SyncProcessManager = require('./sync-process-manager'); +global.Logger = Logger.createLogger('nylas-k2-sync') + const manager = new SyncProcessManager(); DatabaseConnector.forShared().then((db) => { const {Account} = db; Account.findAll().then((accounts) => { if (accounts.length === 0) { - console.log(`Couldn't find any accounts to sync. Run this CURL command to auth one!`) - console.log(`curl -X POST -H "Content-Type: application/json" -d '{"email":"inboxapptest2@fastmail.fm", "name":"Ben Gotow", "provider":"imap", "settings":{"imap_username":"inboxapptest1@fastmail.fm","imap_host":"mail.messagingengine.com","imap_port":993,"smtp_host":"mail.messagingengine.com","smtp_port":0,"smtp_username":"inboxapptest1@fastmail.fm", "smtp_password":"trar2e","imap_password":"trar2e","ssl_required":true}}' "http://localhost:5100/auth?client_id=123"`) + global.Logger.info(`Couldn't find any accounts to sync. Run this CURL command to auth one!`) + global.Logger.info(`curl -X POST -H "Content-Type: application/json" -d '{"email":"inboxapptest2@fastmail.fm", "name":"Ben Gotow", "provider":"imap", "settings":{"imap_username":"inboxapptest1@fastmail.fm","imap_host":"mail.messagingengine.com","imap_port":993,"smtp_host":"mail.messagingengine.com","smtp_port":0,"smtp_username":"inboxapptest1@fastmail.fm", "smtp_password":"trar2e","imap_password":"trar2e","ssl_required":true}}' "http://localhost:5100/auth?client_id=123"`) } manager.ensureAccountIDsInRedis(accounts.map(a => a.id)).then(() => { manager.start(); diff --git a/packages/nylas-sync/imap/fetch-category-list.js b/packages/nylas-sync/imap/fetch-folder-list.js similarity index 97% rename from packages/nylas-sync/imap/fetch-category-list.js rename to packages/nylas-sync/imap/fetch-folder-list.js index b82f33876..d5c5a0000 100644 --- a/packages/nylas-sync/imap/fetch-category-list.js +++ b/packages/nylas-sync/imap/fetch-folder-list.js @@ -3,8 +3,9 @@ const {Provider} = require('nylas-core'); const GMAIL_FOLDERS = ['[Gmail]/All Mail', '[Gmail]/Trash', '[Gmail]/Spam']; class FetchFolderList { - constructor(provider) { + constructor(provider, logger = console) { this._provider = provider; + this._logger = logger; } description() { diff --git a/packages/nylas-sync/imap/fetch-messages-in-category.js b/packages/nylas-sync/imap/fetch-messages-in-folder.js similarity index 84% rename from packages/nylas-sync/imap/fetch-messages-in-category.js rename to packages/nylas-sync/imap/fetch-messages-in-folder.js index 554f09e71..0bf994f61 100644 --- a/packages/nylas-sync/imap/fetch-messages-in-category.js +++ b/packages/nylas-sync/imap/fetch-messages-in-folder.js @@ -11,12 +11,13 @@ const FETCH_MESSAGES_FIRST_COUNT = 100; const FETCH_MESSAGES_COUNT = 200; class FetchMessagesInFolder { - constructor(category, options) { + constructor(category, options, logger = console) { this._imap = null this._box = null this._db = null this._category = category; this._options = options; + this._logger = logger; if (!this._category) { throw new Error("FetchMessagesInFolder requires a category") } @@ -86,9 +87,13 @@ class FetchMessagesInFolder { } }) - console.log(` --- found ${flagChangeMessages.length || 'no'} flag changes`) + this._logger.info({ + flag_changes: flagChangeMessages.length, + }, `FetchMessagesInFolder: found flag changes`) if (createdUIDs.length > 0) { - console.log(` --- found ${createdUIDs.length} new messages. These will not be processed because we assume that they will be assigned uid = uidnext, and will be picked up in the next sync when we discover unseen messages.`) + this._logger.info({ + new_messages: createdUIDs.length, + }, `FetchMessagesInFolder: found new messages. These will not be processed because we assume that they will be assigned uid = uidnext, and will be picked up in the next sync when we discover unseen messages.`) } if (flagChangeMessages.length === 0) { @@ -111,7 +116,9 @@ class FetchMessagesInFolder { .filter(msg => !remoteUIDAttributes[msg.folderImapUID]) .map(msg => msg.folderImapUID) - console.log(` --- found ${removedUIDs.length} messages no longer in the folder`) + this._logger.info({ + removed_messages: removedUIDs.length, + }, `FetchMessagesInFolder: found messages no longer in the folder`) if (removedUIDs.length === 0) { return Promise.resolve(); @@ -148,7 +155,9 @@ class FetchMessagesInFolder { } if (desired.length === 0) { - console.warn(`Could not find good part. Options are: ${available.join(', ')}`) + this._logger.warn({ + available_options: available.join(', '), + }, `FetchMessagesInFolder: Could not find good part`) } return desired; @@ -173,7 +182,10 @@ class FetchMessagesInFolder { const uids = uidsByPart[key]; const desiredParts = JSON.parse(key); const bodies = ['HEADER'].concat(desiredParts.map(p => p.id)); - console.log(`Fetching parts ${key} for ${uids.length} messages`) + this._logger.info({ + key, + num_messages: uids.length, + }`FetchMessagesInFolder: Fetching parts for messages`) // note: the order of UIDs in the array doesn't matter, Gmail always // returns them in ascending (oldest => newest) order. @@ -258,11 +270,17 @@ class FetchMessagesInFolder { ) .then((message) => { if (created) { - console.log(`Created message ID: ${message.id}, UID: ${attributes.uid}`) + this._logger.info({ + message_id: message.id, + uid: attributes.uid, + }, `FetchMessagesInFolder: Created message`) this._createFilesFromStruct({message, struct: attributes.struct}) PubsubConnector.queueProcessMessage({accountId, messageId: message.id}); } else { - console.log(`Updated message ID: ${message.id}, UID: ${attributes.uid}`) + this._logger.info({ + message_id: message.id, + uid: attributes.uid, + }, `FetchMessagesInFolder: Updated message`) } }) @@ -291,7 +309,9 @@ class FetchMessagesInFolder { const desiredRanges = []; - console.log(` - Fetching messages. Currently have range: ${savedSyncState.fetchedmin}:${savedSyncState.fetchedmax}`) + this._logger.info({ + range: `${savedSyncState.fetchedmin}:${savedSyncState.fetchedmax}`, + }, `FetchMessagesInFolder: Fetching messages.`) // Todo: In the future, this is where logic should go that limits // sync based on number of messages / age of messages. @@ -303,18 +323,20 @@ class FetchMessagesInFolder { if (savedSyncState.fetchedmax < boxUidnext) { desiredRanges.push({min: savedSyncState.fetchedmax, max: boxUidnext}) } else { - console.log(" --- fetchedmax == uidnext, nothing more recent to fetch.") + this._logger.info('FetchMessagesInFolder: fetchedmax == uidnext, nothing more recent to fetch.') } if (savedSyncState.fetchedmin > 1) { const lowerbound = Math.max(1, savedSyncState.fetchedmin - FETCH_MESSAGES_COUNT); desiredRanges.push({min: lowerbound, max: savedSyncState.fetchedmin}) } else { - console.log(" --- fetchedmin == 1, nothing older to fetch.") + this._logger.info("FetchMessagesInFolder: fetchedmin == 1, nothing older to fetch.") } } return Promise.each(desiredRanges, ({min, max}) => { - console.log(` --- fetching range: ${min}:${max}`); + this._logger.info({ + range: `${min}:${max}`, + }, `FetchMessagesInFolder: Fetching range`); return this._fetchMessagesAndQueueForProcessing(`${min}:${max}`).then(() => { const {fetchedmin, fetchedmax} = this._category.syncState; @@ -326,7 +348,7 @@ class FetchMessagesInFolder { }); }) }).then(() => { - console.log(` - Fetching messages finished`); + this._logger.info(`FetchMessagesInFolder: Fetching messages finished`); }); } @@ -350,15 +372,15 @@ class FetchMessagesInFolder { let shallowFetch = null; if (this._imap.serverSupports(Capabilities.Condstore)) { - console.log(` - Shallow attribute scan (using CONDSTORE)`) + this._logger.info(`FetchMessagesInFolder: Shallow attribute scan (using CONDSTORE)`) if (nextHighestmodseq === highestmodseq) { - console.log(" --- highestmodseq matches, nothing more to fetch") + this._logger.info('FetchMessagesInFolder: highestmodseq matches, nothing more to fetch') return Promise.resolve(); } shallowFetch = this._box.fetchUIDAttributes(`1:*`, {changedsince: highestmodseq}); } else { const range = `${this._getLowerBoundUID(SHALLOW_SCAN_UID_COUNT)}:*`; - console.log(` - Shallow attribute scan (using range: ${range})`) + this._logger.info({range}, `FetchMessagesInFolder: Shallow attribute scan`) shallowFetch = this._box.fetchUIDAttributes(range); } @@ -372,7 +394,7 @@ class FetchMessagesInFolder { this._updateMessageAttributes(remoteUIDAttributes, localMessageAttributes) )) .then(() => { - console.log(` - finished fetching changes to messages`); + this._logger.info(`FetchMessagesInFolder: finished fetching changes to messages`); return this.updateFolderSyncState({ highestmodseq: nextHighestmodseq, timeShallowScan: Date.now(), @@ -386,7 +408,7 @@ class FetchMessagesInFolder { const {fetchedmin, fetchedmax} = this._category.syncState; const range = `${fetchedmin}:${fetchedmax}`; - console.log(` - Deep attribute scan: fetching attributes in range: ${range}`) + this._logger.info({range}, `FetchMessagesInFolder: Deep attribute scan: fetching attributes in range`) return this._box.fetchUIDAttributes(range) .then((remoteUIDAttributes) => { @@ -401,7 +423,7 @@ class FetchMessagesInFolder { }) )) .then(() => { - console.log(` - Deep scan finished.`); + this._logger.info(`FetchMessagesInFolder: Deep scan finished.`); return this.updateFolderSyncState({ highestmodseq: this._box.highestmodseq, timeDeepScan: Date.now(), diff --git a/packages/nylas-sync/sync-process-manager.js b/packages/nylas-sync/sync-process-manager.js index 513bd1664..d9cab0829 100644 --- a/packages/nylas-sync/sync-process-manager.js +++ b/packages/nylas-sync/sync-process-manager.js @@ -43,7 +43,7 @@ class SyncProcessManager { } start() { - console.log(`ProcessManager: Starting with ID ${IDENTITY}`) + global.Logger.info(`ProcessManager: Starting with ID ${IDENTITY}`) this.unassignAccountsAssignedTo(IDENTITY).then(() => { this.unassignAccountsMissingHeartbeats(); @@ -63,12 +63,12 @@ class SyncProcessManager { client.setAsync(key, Date.now()).then(() => client.expireAsync(key, HEARTBEAT_EXPIRES) ).then(() => - console.log("ProcessManager: 💘") + global.Logger.info("ProcessManager: 💘") ) } onSigInt() { - console.log(`ProcessManager: Exiting...`) + global.Logger.info(`ProcessManager: Exiting...`) this._exiting = true; this.unassignAccountsAssignedTo(IDENTITY).then(() => @@ -85,7 +85,7 @@ class SyncProcessManager { let unseenIds = [].concat(accountIds); - console.log("ProcessManager: Starting scan for accountIds in database that are not present in Redis.") + global.Logger.info("ProcessManager: Starting scan for accountIds in database that are not present in Redis.") return forEachAccountList((foundProcessIdentity, foundIds) => { unseenIds = unseenIds.filter((a) => !foundIds.includes(`${a}`)) @@ -94,7 +94,7 @@ class SyncProcessManager { if (unseenIds.length === 0) { return; } - console.log(`ProcessManager: Adding account IDs ${unseenIds.join(',')} to ${ACCOUNTS_UNCLAIMED}.`) + global.Logger.info(`ProcessManager: Adding account IDs ${unseenIds.join(',')} to ${ACCOUNTS_UNCLAIMED}.`) unseenIds.map((id) => client.lpushAsync(ACCOUNTS_UNCLAIMED, id)); }); } @@ -102,7 +102,7 @@ class SyncProcessManager { unassignAccountsMissingHeartbeats() { const client = PubsubConnector.broadcastClient(); - console.log("ProcessManager: Starting unassignment for processes missing heartbeats.") + global.Logger.info("ProcessManager: Starting unassignment for processes missing heartbeats.") Promise.each(client.keysAsync(`${ACCOUNTS_CLAIMED_PREFIX}*`), (key) => { const id = key.replace(ACCOUNTS_CLAIMED_PREFIX, ''); @@ -125,12 +125,12 @@ class SyncProcessManager { ) return unassignOne(0).then((returned) => { - console.log(`ProcessManager: Returned ${returned} accounts assigned to ${identity}.`) + global.Logger.info(`ProcessManager: Returned ${returned} accounts assigned to ${identity}.`) }); } update() { - console.log(`ProcessManager: Searching for an unclaimed account to sync.`) + global.Logger.info(`ProcessManager: Searching for an unclaimed account to sync.`) this.acceptUnclaimedAccount().finally(() => { if (this._exiting) { @@ -170,7 +170,7 @@ class SyncProcessManager { if (this._exiting || this._workers[account.id]) { return; } - console.log(`ProcessManager: Starting worker for Account ${accountId}`) + global.Logger.info(`ProcessManager: Starting worker for Account ${accountId}`) this._workers[account.id] = new SyncWorker(account, db, () => { this.removeWorkerForAccountId(accountId) }); diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index 6ebb34b8d..d0788ca78 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -11,8 +11,8 @@ const { const {CLAIM_DURATION} = SchedulerUtils; -const FetchFolderList = require('./imap/fetch-category-list') -const FetchMessagesInFolder = require('./imap/fetch-messages-in-category') +const FetchFolderList = require('./imap/fetch-folder-list') +const FetchMessagesInFolder = require('./imap/fetch-messages-in-folder') const SyncbackTaskFactory = require('./syncback-task-factory') @@ -24,6 +24,7 @@ class SyncWorker { this._startTime = Date.now(); this._lastSyncTime = null; this._onExpired = onExpired; + this._logger = global.Logger.forAccount(account) this._syncTimer = null; this._expirationTimer = null; @@ -100,7 +101,7 @@ class SyncWorker { return Promise.reject(new Error("ensureConnection: There are no IMAP connection credentials for this account.")) } - const conn = new IMAPConnection(this._db, Object.assign({}, settings, credentials)); + const conn = new IMAPConnection({db: this._db, settings: Object.assign({}, settings, credentials), logger: this._logger}); conn.on('mail', () => { this._onConnectionIdleUpdate(); }) @@ -145,7 +146,7 @@ class SyncWorker { ) return Promise.all(categoriesToSync.map((cat) => - this._conn.runOperation(new FetchMessagesInFolder(cat, folderSyncOptions)) + this._conn.runOperation(new FetchMessagesInFolder(cat, folderSyncOptions, this._logger)) )) }); } @@ -155,10 +156,10 @@ class SyncWorker { this._syncTimer = null; if (!process.env.SYNC_AFTER_ERRORS && this._account.errored()) { - console.log(`SyncWorker: Account ${this._account.emailAddress} (${this._account.id}) is in error state - Skipping sync`) + this._logger.info(`SyncWorker: Account is in error state - Skipping sync`) return } - console.log(`SyncWorker: Account ${this._account.emailAddress} (${this._account.id}) sync started (${reason})`) + this._logger.info({reason}, `SyncWorker: Account sync started`) this.ensureConnection() .then(() => this._account.update({syncError: null})) @@ -174,7 +175,7 @@ class SyncWorker { } onSyncError(error) { - console.error(`SyncWorker: Error while syncing account ${this._account.emailAddress} (${this._account.id})`, error) + this._logger.error(error, `SyncWorker: Error while syncing account`) this.closeConnection() if (error.source.includes('socket') || error.source.includes('timeout')) { @@ -203,16 +204,16 @@ class SyncWorker { this._account.lastSyncCompletions = lastSyncCompletions this._account.save() - console.log('Syncworker: Completed sync cycle') + this._logger.info('Syncworker: Completed sync cycle') if (afterSync === 'idle') { return this._getIdleFolder() .then((idleFolder) => this._conn.openBox(idleFolder.name)) - .then(() => console.log('SyncWorker: - Idling on inbox category')) + .then(() => this._logger.info('SyncWorker: - Idling on inbox category')) } if (afterSync === 'close') { - console.log('SyncWorker: - Closing connection'); + this._logger.info('SyncWorker: - Closing connection'); this.closeConnection() return Promise.resolve() } @@ -226,7 +227,7 @@ class SyncWorker { scheduleNextSync() { if (Date.now() - this._startTime > CLAIM_DURATION) { - console.log("SyncWorker: - Has held account for more than CLAIM_DURATION, returning to pool."); + this._logger.info("SyncWorker: - Has held account for more than CLAIM_DURATION, returning to pool."); this.cleanup(); this._onExpired(); return; @@ -238,7 +239,10 @@ class SyncWorker { if (interval) { const target = this._lastSyncTime + interval; - console.log(`SyncWorker: Account ${active ? 'active' : 'inactive'}. Next sync scheduled for ${new Date(target).toLocaleString()}`); + this._logger.info({ + is_active: active, + next_sync: new Date(target).toLocaleString(), + }, `SyncWorker: Next sync scheduled`); this._syncTimer = setTimeout(() => { this.syncNow({reason: 'Scheduled'}); }, target - Date.now()); diff --git a/pm2-dev.yml b/pm2-dev.yml index 313be4c0d..a88d4e8c2 100644 --- a/pm2-dev.yml +++ b/pm2-dev.yml @@ -12,25 +12,23 @@ apps: GMAIL_CLIENT_ID : "271342407743-nibas08fua1itr1utq9qjladbkv3esdm.apps.googleusercontent.com" GMAIL_CLIENT_SECRET : "WhmxErj-ei6vJXLocNhBbfBF" GMAIL_REDIRECT_URL : "http://localhost:5100/auth/gmail/oauthcallback" - - + NODE_ENV: 'development' - script : packages/nylas-sync/app.js name : sync env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" DB_ENCRYPTION_PASSWORD : "d6F3Efeq" - - + NODE_ENV: 'development' - script : packages/nylas-dashboard/app.js name : dashboard env : PORT: 5101 DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" DB_ENCRYPTION_PASSWORD : "d6F3Efeq" - - + NODE_ENV: 'development' - script : packages/nylas-message-processor/app.js name : processor env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" DB_ENCRYPTION_PASSWORD : "d6F3Efeq" + NODE_ENV: 'development' From 93189b0f22f49d897d55b20858d41da8e4727e62 Mon Sep 17 00:00:00 2001 From: Ben Gotow Date: Mon, 11 Jul 2016 10:56:08 -0700 Subject: [PATCH 02/24] Try adding newrelic logging --- packages/nylas-api/app.js | 2 ++ packages/nylas-api/newrelic.js | 24 ++++++++++++++++++++++++ packages/nylas-sync/app.js | 1 + packages/nylas-sync/newrelic.js | 24 ++++++++++++++++++++++++ 4 files changed, 51 insertions(+) create mode 100644 packages/nylas-api/newrelic.js create mode 100644 packages/nylas-sync/newrelic.js diff --git a/packages/nylas-api/app.js b/packages/nylas-api/app.js index bca30c9af..8fab0cd2e 100644 --- a/packages/nylas-api/app.js +++ b/packages/nylas-api/app.js @@ -1,3 +1,5 @@ +require('newrelic'); + const Hapi = require('hapi'); const HapiSwagger = require('hapi-swagger'); const HapiBoom = require('hapi-boom-decorators') diff --git a/packages/nylas-api/newrelic.js b/packages/nylas-api/newrelic.js new file mode 100644 index 000000000..00882097e --- /dev/null +++ b/packages/nylas-api/newrelic.js @@ -0,0 +1,24 @@ +/** + * New Relic agent configuration. + * + * See lib/config.defaults.js in the agent distribution for a more complete + * description of configuration variables and their potential values. + */ +exports.config = { + /** + * Array of application names. + */ + app_name: ['Nylas K2 API'], + /** + * Your New Relic license key. + */ + license_key: 'e232d6ccc786bd87aa72b86782439710162e3739', + logging: { + /** + * Level at which to log. 'trace' is most useful to New Relic when diagnosing + * issues with the agent, 'info' and higher will impose the least overhead on + * production applications. + */ + level: 'info', + }, +} diff --git a/packages/nylas-sync/app.js b/packages/nylas-sync/app.js index 5d7319245..227e7a365 100644 --- a/packages/nylas-sync/app.js +++ b/packages/nylas-sync/app.js @@ -1,3 +1,4 @@ +require('newrelic'); global.Promise = require('bluebird'); const {DatabaseConnector} = require(`nylas-core`) diff --git a/packages/nylas-sync/newrelic.js b/packages/nylas-sync/newrelic.js new file mode 100644 index 000000000..a85120e87 --- /dev/null +++ b/packages/nylas-sync/newrelic.js @@ -0,0 +1,24 @@ +/** + * New Relic agent configuration. + * + * See lib/config.defaults.js in the agent distribution for a more complete + * description of configuration variables and their potential values. + */ +exports.config = { + /** + * Array of application names. + */ + app_name: ['Nylas K2 Sync'], + /** + * Your New Relic license key. + */ + license_key: 'e232d6ccc786bd87aa72b86782439710162e3739', + logging: { + /** + * Level at which to log. 'trace' is most useful to New Relic when diagnosing + * issues with the agent, 'info' and higher will impose the least overhead on + * production applications. + */ + level: 'info', + }, +} From 600245ebcb930f8b0e161b285c933f33e8b18e13 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Fri, 8 Jul 2016 18:48:52 -0700 Subject: [PATCH 03/24] Fix cloudwatch config --- packages/nylas-core/logger.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/nylas-core/logger.js b/packages/nylas-core/logger.js index aaa885fb4..da3bba76f 100644 --- a/packages/nylas-core/logger.js +++ b/packages/nylas-core/logger.js @@ -14,8 +14,8 @@ function getLogStreams(name, env) { const cloudwatchStream = { stream: createCWStream({ - logGroup: `k2-${env}`, - logStream: `${name}-${env}`, + logGroupName: `k2-${env}`, + logStreamName: `${name}-${env}`, cloudWatchLogsOptions: { region: 'us-east-1', }, From f648016c621463357a7fffb89299ca83ea1eb530 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 11:27:35 -0700 Subject: [PATCH 04/24] Lock logger versions --- package.json | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/package.json b/package.json index 411c58799..c7d2fea4f 100644 --- a/package.json +++ b/package.json @@ -5,8 +5,8 @@ "main": "", "dependencies": { "bluebird": "3.x.x", - "bunyan": "^1.8.1", - "bunyan-cloudwatch": "^2.0.0", + "bunyan": "1.8.0", + "bunyan-cloudwatch": "2.0.0", "lerna": "2.0.0-beta.23", "mysql": "^2.11.1", "newrelic": "^1.28.1", From ff334e169cebb9c1f8ef11ef366b5ab19c3a00cc Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 11:43:51 -0700 Subject: [PATCH 05/24] Make npm start log output logs too --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index c7d2fea4f..807c2d4b6 100644 --- a/package.json +++ b/package.json @@ -27,7 +27,7 @@ "sqlite3": "https://github.com/bengotow/node-sqlite3/archive/bengotow/usleep-v3.1.4.tar.gz" }, "scripts": { - "start": "pm2 start ./pm2-dev.yml", + "start": "pm2 start ./pm2-dev.yml; pm2 logs --raw | bunyan -o short", "logs": "pm2 logs --raw | bunyan -o short", "stop": "pm2 delete all", "postinstall": "lerna bootstrap" From 98c17c9780f2e9c8627014c6462c0cf000f6ea6f Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 11:47:42 -0700 Subject: [PATCH 06/24] Fix api logger decorator --- packages/nylas-api/decorators/connections.js | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/nylas-api/decorators/connections.js b/packages/nylas-api/decorators/connections.js index f0fe1d437..161e9beb6 100644 --- a/packages/nylas-api/decorators/connections.js +++ b/packages/nylas-api/decorators/connections.js @@ -8,6 +8,9 @@ module.exports = (server) => { return DatabaseConnector.forAccount(account.id); }); server.decorate('request', 'logger', (request) => { - return global.Logger.forAccount(request.auth.credentials) + if (request.auth.credentials) { + return global.Logger.forAccount(request.auth.credentials) + } + return global.Logger }, {apply: true}); } From c0d7902f9fb4b40549d794a28146439fd52cd728 Mon Sep 17 00:00:00 2001 From: Evan Morikawa Date: Mon, 11 Jul 2016 11:48:54 -0700 Subject: [PATCH 07/24] Add npm run restart --- package.json | 1 + 1 file changed, 1 insertion(+) diff --git a/package.json b/package.json index 807c2d4b6..a94202966 100644 --- a/package.json +++ b/package.json @@ -30,6 +30,7 @@ "start": "pm2 start ./pm2-dev.yml; pm2 logs --raw | bunyan -o short", "logs": "pm2 logs --raw | bunyan -o short", "stop": "pm2 delete all", + "restart": "npm run stop && npm run start", "postinstall": "lerna bootstrap" }, "repository": { From 84815ce2fa884d6ebc3992003429dec38c5b0b17 Mon Sep 17 00:00:00 2001 From: Evan Morikawa Date: Mon, 11 Jul 2016 12:00:20 -0700 Subject: [PATCH 08/24] Add file watching to restart server --- .gitignore | 1 + package.json | 3 +-- pm2-dev.yml | 4 ++++ 3 files changed, 6 insertions(+), 2 deletions(-) diff --git a/.gitignore b/.gitignore index ce1018e2e..e5ddc09e2 100644 --- a/.gitignore +++ b/.gitignore @@ -4,6 +4,7 @@ dump.rdb *npm-debug.log storage/ lerna-debug.log +newrelic_agent.log # Elastic Beanstalk Files .elasticbeanstalk/* diff --git a/package.json b/package.json index a94202966..7a33802a6 100644 --- a/package.json +++ b/package.json @@ -27,10 +27,9 @@ "sqlite3": "https://github.com/bengotow/node-sqlite3/archive/bengotow/usleep-v3.1.4.tar.gz" }, "scripts": { - "start": "pm2 start ./pm2-dev.yml; pm2 logs --raw | bunyan -o short", + "start": "pm2 start ./pm2-dev.yml --watch; pm2 logs --raw | bunyan -o short", "logs": "pm2 logs --raw | bunyan -o short", "stop": "pm2 delete all", - "restart": "npm run stop && npm run start", "postinstall": "lerna bootstrap" }, "repository": { diff --git a/pm2-dev.yml b/pm2-dev.yml index a88d4e8c2..4f60094fd 100644 --- a/pm2-dev.yml +++ b/pm2-dev.yml @@ -4,6 +4,7 @@ apps: - script : packages/nylas-api/app.js + watch : true name : api env : PORT: 5100 @@ -14,12 +15,14 @@ apps: GMAIL_REDIRECT_URL : "http://localhost:5100/auth/gmail/oauthcallback" NODE_ENV: 'development' - script : packages/nylas-sync/app.js + watch : true name : sync env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" DB_ENCRYPTION_PASSWORD : "d6F3Efeq" NODE_ENV: 'development' - script : packages/nylas-dashboard/app.js + watch : true name : dashboard env : PORT: 5101 @@ -27,6 +30,7 @@ apps: DB_ENCRYPTION_PASSWORD : "d6F3Efeq" NODE_ENV: 'development' - script : packages/nylas-message-processor/app.js + watch : true name : processor env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" From 1c4434c136902fa30be0ac30fc0565c5e7834b47 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 12:12:17 -0700 Subject: [PATCH 09/24] Re-emit error events on bunyan log streams --- packages/nylas-core/logger.js | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/nylas-core/logger.js b/packages/nylas-core/logger.js index da3bba76f..40c73ad31 100644 --- a/packages/nylas-core/logger.js +++ b/packages/nylas-core/logger.js @@ -21,6 +21,7 @@ function getLogStreams(name, env) { }, }), type: 'raw', + reemitErrorEvents: true, } return [stdoutStream, cloudwatchStream] } From 877a6bf6122da17aeff5c56b45e1ef470ad37106 Mon Sep 17 00:00:00 2001 From: Halla Moore Date: Mon, 11 Jul 2016 12:55:34 -0700 Subject: [PATCH 10/24] Add SyncbackRequest details to dashboard --- packages/nylas-dashboard/public/css/app.css | 78 +++++++- .../public/images/dropdown.png | Bin 0 -> 333 bytes packages/nylas-dashboard/public/index.html | 2 + packages/nylas-dashboard/public/js/app.jsx | 2 + .../nylas-dashboard/public/js/dropdown.jsx | 71 ++++++++ .../public/js/set-all-sync-policies.jsx | 23 ++- .../nylas-dashboard/public/js/sync-policy.jsx | 2 +- .../public/js/syncback-request-details.jsx | 171 ++++++++++++++++++ .../routes/syncback-requests.js | 81 +++++++++ 9 files changed, 419 insertions(+), 11 deletions(-) create mode 100644 packages/nylas-dashboard/public/images/dropdown.png create mode 100644 packages/nylas-dashboard/public/js/dropdown.jsx create mode 100644 packages/nylas-dashboard/public/js/syncback-request-details.jsx create mode 100644 packages/nylas-dashboard/routes/syncback-requests.js diff --git a/packages/nylas-dashboard/public/css/app.css b/packages/nylas-dashboard/public/css/app.css index ceb513342..436426196 100644 --- a/packages/nylas-dashboard/public/css/app.css +++ b/packages/nylas-dashboard/public/css/app.css @@ -59,10 +59,14 @@ pre { .action-link { display: inline-block; - margin: 5px; color: rgba(16, 83, 161, 0.88); text-decoration: underline; cursor: pointer; + margin: 5px 0; +} + +.action-link.cancel { + margin-left: 5px; } .sync-policy textarea { @@ -76,6 +80,7 @@ pre { width: 50%; margin: auto; padding: 20px; + overflow: auto; } .modal-bg { @@ -88,6 +93,15 @@ pre { padding-top: 10%; } +.modal-close { + position: relative; + float: right; + top: -10px; + cursor: pointer; + font-size: 14px; + font-weight: bold; +} + .sync-graph { margin-top: 3px; } @@ -97,3 +111,65 @@ pre { margin-top: 5px; margin-bottom: 1px; } + +#syncback-request-details { + font-size: 15px; + color: black; +} + +#syncback-request-details .counts { + margin: 10px; +} + +#syncback-request-details span { + margin: 10px; +} + +#syncback-request-details table { + width: 100%; +} + +#syncback-request-details tr:nth-child(even) { + background-color: #F1F1F1; +} + +#syncback-request-details tr:not(:first-child):hover { + background-color: #C9C9C9; +} + +#syncback-request-details td, #syncback-request-details th { + text-align: center; + padding: 10px 5px; +} + +.dropdown-arrow { + margin: 0 5px; + height: 7px; + vertical-align: middle; +} + +.dropdown-options { + border: solid black 1px; + position: absolute; + background-color: white; + text-align: left; +} + +.dropdown-option { + padding: 0px 2px; +} + +.dropdown-option:hover { + background-color: rgb(114, 163, 255); +} + +.dropdown-selected { + display: inline; +} + +.dropdown-wrapper { + display: inline; + cursor: pointer; + position: absolute; + font-weight: normal; +} diff --git a/packages/nylas-dashboard/public/images/dropdown.png b/packages/nylas-dashboard/public/images/dropdown.png new file mode 100644 index 0000000000000000000000000000000000000000..a49a693f9ec1b6d0e552d4fe2f3e0dc748f7cbdc GIT binary patch literal 333 zcmV-T0kZyyP)Px$2T4RhR45f=U;u)E@HkKZh`2x?lM%!x1_XsC8u>>gT7lFu28PG^|7T>}0M$5s z!-|F3K=ywqA1mb_o>0Na_`e+_`Jdr`G}C`323{nUnE?^;Q-OS(EEG&;n)oL`<2ai z^X55UnL&yO8HC$_S>HhVQT!en8p`&EnQJvLRQ*7bAOK{a04lP8@IWNvK8On-27pBn zk`NX)gAi&k4FJi3y@ODM(`!H_*bTsH2uKh!jBpzOQjZcQAOU0m^4c$EPQQO&Iks)y fj0gi{H6S(s8clzSk0>{000000NkvXXu0mjf*8_nP literal 0 HcmV?d00001 diff --git a/packages/nylas-dashboard/public/index.html b/packages/nylas-dashboard/public/index.html index 89227c3d8..a1c31b217 100644 --- a/packages/nylas-dashboard/public/index.html +++ b/packages/nylas-dashboard/public/index.html @@ -7,6 +7,8 @@ + + diff --git a/packages/nylas-dashboard/public/js/app.jsx b/packages/nylas-dashboard/public/js/app.jsx index 5f740093b..660df19e8 100644 --- a/packages/nylas-dashboard/public/js/app.jsx +++ b/packages/nylas-dashboard/public/js/app.jsx @@ -6,6 +6,7 @@ const { SetAllSyncPolicies, AccountFilter, SyncGraph, + SyncbackRequestDetails, } = window; class Account extends React.Component { @@ -51,6 +52,7 @@ class Account extends React.Component {

{account.email_address} {active ? '🌕' : '🌑'}

{assignment} + selectedOnClick.call(this)}> + {this.state.selected} + dropdown arrow +
+ ); + + // All options, not shown if dropdown is closed + let options = []; + let optionsWrapper = ; + if (!this.state.closed) { + for (const opt of this.props.options) { + options.push( +
this.selectAndClose.call(this, opt)}> {opt}
+ ); + } + optionsWrapper = ( +
+ {options} +
+ ) + } + + return ( +
this.close.call(this)}> + {selected} + {optionsWrapper} +
+ ); + } + +} + +Dropdown.propTypes = { + options: React.PropTypes.arrayOf(React.PropTypes.string), + defaultOption: React.PropTypes.string, + onSelect: React.PropTypes.func, +} + +window.Dropdown = Dropdown; diff --git a/packages/nylas-dashboard/public/js/set-all-sync-policies.jsx b/packages/nylas-dashboard/public/js/set-all-sync-policies.jsx index f9346c1e6..06bfe2e26 100644 --- a/packages/nylas-dashboard/public/js/set-all-sync-policies.jsx +++ b/packages/nylas-dashboard/public/js/set-all-sync-policies.jsx @@ -38,15 +38,20 @@ class SetAllSyncPolicies extends React.Component { render() { if (this.state.editMode) { return ( -
-
-
Sync Policy
- - - this.cancel.call(this)}> Cancel +
+ this.edit.call(this)}> + Set sync policies for currently displayed accounts + +
+
+
Sync Policy
+ + + this.cancel.call(this)}> Cancel +
) diff --git a/packages/nylas-dashboard/public/js/sync-policy.jsx b/packages/nylas-dashboard/public/js/sync-policy.jsx index bfbee8ffb..5efe9655b 100644 --- a/packages/nylas-dashboard/public/js/sync-policy.jsx +++ b/packages/nylas-dashboard/public/js/sync-policy.jsx @@ -43,7 +43,7 @@ class SyncPolicy extends React.Component { {this.props.stringifiedSyncPolicy} - this.cancel.call(this)}> Cancel + this.cancel.call(this)}> Cancel
) diff --git a/packages/nylas-dashboard/public/js/syncback-request-details.jsx b/packages/nylas-dashboard/public/js/syncback-request-details.jsx new file mode 100644 index 000000000..1aecdb220 --- /dev/null +++ b/packages/nylas-dashboard/public/js/syncback-request-details.jsx @@ -0,0 +1,171 @@ +const React = window.React; +const Dropdown = window.Dropdown; + +class SyncbackRequestDetails extends React.Component { + constructor(props) { + super(props); + this.state = { + open: false, + accountId: props.accountId, + syncbackRequests: null, + counts: null, + statusFilter: 'all', + }; + } + + getDetails() { + const req = new XMLHttpRequest(); + const url = `${window.location.protocol}/syncback-requests/${this.state.accountId}`; + req.open("GET", url, true); + req.onreadystatechange = () => { + if (req.readyState === XMLHttpRequest.DONE) { + if (req.status === 200) { + this.setState({syncbackRequests: req.responseText}); + } else { + console.error(req.responseText); + } + } + } + req.send(); + } + + getCounts() { + const since = Date.now() - 1000 * 60 * 60; // one hour ago + const req = new XMLHttpRequest(); + const url = `${window.location.protocol}/syncback-requests/${this.state.accountId}/counts?since=${since}`; + req.open("GET", url, true); + req.onreadystatechange = () => { + if (req.readyState === XMLHttpRequest.DONE) { + if (req.status === 200) { + this.setState({counts: JSON.parse(req.responseText)}); + } else { + console.error(req.responseText); + } + } + } + req.send(); + } + + setStatusFilter(statusFilter) { + this.setState({statusFilter: statusFilter}); + } + + open() { + this.getDetails(); + this.getCounts(); + this.setState({open: true}); + } + + close() { + this.setState({open: false}); + } + + render() { + if (this.state.open) { + let counts = Of requests created in the last hour: ... + if (this.state.counts) { + const total = this.state.counts.new + this.state.counts.failed + + this.state.counts.succeeded; + if (total === 0) { + counts = "No requests made in the last hour"; + } else { + counts = ( +
+ Of requests created in the last hour: + + {this.state.counts.failed / total * 100}% failed + + + {this.state.counts.succeeded / total * 100}% succeeded + + + {/* .new was throwing off my syntax higlighting, so ignoring linter*/} + {this.state.counts['new'] / total * 100}% are still new + +
+ ) + } + } + + let details = "Loading..." + if (this.state.syncbackRequests) { + let reqs = JSON.parse(this.state.syncbackRequests); + if (this.state.statusFilter !== 'all') { + reqs = reqs.filter((req) => req.status === this.state.statusFilter); + } + let rows = []; + if (reqs.length === 0) { + rows.push(No results--); + } + for (let i = reqs.length - 1; i >= 0; i--) { + const req = reqs[i]; + const date = new Date(req.createdAt); + rows.push( + {req.status} + {req.type} + {date.toLocaleTimeString()}, {date.toLocaleDateString()} + ) + } + details = ( + + + + + + + + {rows} + +
+ Status:  + this.setStatusFilter.call(this, status)} + /> + Type Created At
+ ); + } + + return ( +
+ Syncback Request Details +
+
+
this.close.call(this)}> + X +
+
+ {counts} + {details} +
+
+
+
+ ); + } + // else, the modal isn't open + return ( +
+ this.open.call(this)}> + Syncback Request Details + +
+ ); + } +} + +SyncbackRequestDetails.propTypes = { + accountId: React.PropTypes.number, +} + +window.SyncbackRequestDetails = SyncbackRequestDetails; diff --git a/packages/nylas-dashboard/routes/syncback-requests.js b/packages/nylas-dashboard/routes/syncback-requests.js new file mode 100644 index 000000000..267f1086a --- /dev/null +++ b/packages/nylas-dashboard/routes/syncback-requests.js @@ -0,0 +1,81 @@ +const Joi = require('joi'); +const {DatabaseConnector} = require(`nylas-core`); + +module.exports = (server) => { + server.route({ + method: 'GET', + path: '/syncback-requests/{account_id}', + config: { + description: 'Get the SyncbackRequests for an account', + notes: 'Notes go here', + tags: ['syncback-requests'], + validate: { + params: { + account_id: Joi.number().integer(), + }, + }, + response: { + schema: Joi.string(), + }, + }, + handler: (request, reply) => { + DatabaseConnector.forAccount(request.params.account_id).then((db) => { + const {SyncbackRequest} = db; + SyncbackRequest.findAll().then((syncbackRequests) => { + reply(JSON.stringify(syncbackRequests)) + }); + }); + }, + }); + + server.route({ + method: 'GET', + path: '/syncback-requests/{account_id}/counts', + config: { + description: 'Get stats on the statuses of SyncbackRequests', + notes: 'Notes go here', + tags: ['syncback-requests'], + validate: { + params: { + account_id: Joi.number().integer(), + }, + query: { + since: Joi.date().timestamp(), + }, + }, + response: { + schema: Joi.string(), + }, + }, + handler: (request, reply) => { + DatabaseConnector.forAccount(request.params.account_id).then((db) => { + const {SyncbackRequest} = db; + + const counts = { + 'new': null, + 'succeeded': null, + 'failed': null, + } + + const where = {}; + if (request.query.since) { + where.createdAt = {gt: request.query.since}; + } + + const countPromises = []; + for (const status of Object.keys(counts)) { + where.status = status.toUpperCase(); + countPromises.push( + SyncbackRequest.count({where: where}).then((count) => { + counts[status] = count; + }) + ); + } + + Promise.all(countPromises).then(() => { + reply(JSON.stringify(counts)); + }) + }); + }, + }); +}; From 8a63ace9e3f618a8e6873d1a86772e5eb330fc88 Mon Sep 17 00:00:00 2001 From: Halla Moore Date: Mon, 11 Jul 2016 13:27:44 -0700 Subject: [PATCH 11/24] Change config to watch just the 'packages' directory --- pm2-dev.yml | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/pm2-dev.yml b/pm2-dev.yml index 4f60094fd..b8efea594 100644 --- a/pm2-dev.yml +++ b/pm2-dev.yml @@ -4,7 +4,7 @@ apps: - script : packages/nylas-api/app.js - watch : true + watch : ["packages"] name : api env : PORT: 5100 @@ -15,14 +15,14 @@ apps: GMAIL_REDIRECT_URL : "http://localhost:5100/auth/gmail/oauthcallback" NODE_ENV: 'development' - script : packages/nylas-sync/app.js - watch : true + watch : ["packages"] name : sync env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" DB_ENCRYPTION_PASSWORD : "d6F3Efeq" NODE_ENV: 'development' - script : packages/nylas-dashboard/app.js - watch : true + watch : ["packages"] name : dashboard env : PORT: 5101 @@ -30,7 +30,7 @@ apps: DB_ENCRYPTION_PASSWORD : "d6F3Efeq" NODE_ENV: 'development' - script : packages/nylas-message-processor/app.js - watch : true + watch : ["packages"] name : processor env : DB_ENCRYPTION_ALGORITHM : "aes-256-ctr" From 6ff596b5a7df2e52f444bff7cbee503668ff26cc Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 13:46:50 -0700 Subject: [PATCH 12/24] Properly log uncaight errors in sync worker --- packages/nylas-sync/sync-worker.js | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index d0788ca78..2c11a5137 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -56,7 +56,8 @@ class SyncWorker { case MessageTypes.SYNCBACK_REQUESTED: this.syncNow({reason: 'Syncback Action Queued'}); break; default: - throw new Error(`Invalid message: ${msg}`) + const err = new Error(`Invalid message`) + this._logger.error({message: msg, err}, 'Invalid message') } } @@ -218,7 +219,9 @@ class SyncWorker { return Promise.resolve() } - throw new Error(`SyncWorker.onSyncDidComplete: Unknown afterSync behavior: ${afterSync}. Closing connection`) + this._logger.warn({after_sync: afterSync}, `SyncWorker.onSyncDidComplete: Unknown afterSync behavior`) + this.closeConnection() + return Promise.resolve() } isWaitingForNextSync() { From b7301f5dc5e72c36ea6460ca6e21a174fe23e641 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 14:10:30 -0700 Subject: [PATCH 13/24] Fix more error handling in sync worker --- packages/nylas-sync/sync-worker.js | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index 2c11a5137..0b7d760d4 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -56,8 +56,7 @@ class SyncWorker { case MessageTypes.SYNCBACK_REQUESTED: this.syncNow({reason: 'Syncback Action Queued'}); break; default: - const err = new Error(`Invalid message`) - this._logger.error({message: msg, err}, 'Invalid message') + this._logger.error({message: msg}, 'SyncWorker: Invalid message') } } @@ -65,10 +64,14 @@ class SyncWorker { if (!this.isWaitingForNextSync()) { return; } - this._getAccount().then((account) => { + this._getAccount() + .then((account) => { this._account = account; this.syncNow({reason: 'Account Modification'}); - }); + }) + .catch((err) => { + this._logger.error(err, 'SyncWorker: Error getting account for update') + }) } _onConnectionIdleUpdate() { @@ -210,18 +213,17 @@ class SyncWorker { if (afterSync === 'idle') { return this._getIdleFolder() .then((idleFolder) => this._conn.openBox(idleFolder.name)) - .then(() => this._logger.info('SyncWorker: - Idling on inbox category')) + .then(() => this._logger.info('SyncWorker: Idling on inbox category')) } if (afterSync === 'close') { - this._logger.info('SyncWorker: - Closing connection'); + this._logger.info('SyncWorker: Closing connection'); this.closeConnection() return Promise.resolve() } - this._logger.warn({after_sync: afterSync}, `SyncWorker.onSyncDidComplete: Unknown afterSync behavior`) - this.closeConnection() - return Promise.resolve() + this._logger.error({after_sync: afterSync}, `SyncWorker.onSyncDidComplete: Unknown afterSync behavior`) + throw new Error('SyncWorker.onSyncDidComplete: Unknown afterSync behavior') } isWaitingForNextSync() { From 1360599ffc921fb15a186cf585bbc4c13e1f1c69 Mon Sep 17 00:00:00 2001 From: Evan Morikawa Date: Mon, 11 Jul 2016 14:23:20 -0700 Subject: [PATCH 14/24] Fix deafult test account email address --- packages/nylas-api/routes/auth.js | 1 + packages/nylas-sync/app.js | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/packages/nylas-api/routes/auth.js b/packages/nylas-api/routes/auth.js index 65c776927..d0cb6949e 100644 --- a/packages/nylas-api/routes/auth.js +++ b/packages/nylas-api/routes/auth.js @@ -76,6 +76,7 @@ module.exports = (server) => { validate: { query: { client_id: Joi.string().required(), + n1_id: Joi.string(), }, payload: { email: Joi.string().email().required(), diff --git a/packages/nylas-sync/app.js b/packages/nylas-sync/app.js index d0effc28f..14ae4c177 100644 --- a/packages/nylas-sync/app.js +++ b/packages/nylas-sync/app.js @@ -12,7 +12,7 @@ DatabaseConnector.forShared().then((db) => { Account.findAll().then((accounts) => { if (accounts.length === 0) { global.Logger.info(`Couldn't find any accounts to sync. Run this CURL command to auth one!`) - global.Logger.info(`curl -X POST -H "Content-Type: application/json" -d '{"email":"inboxapptest2@fastmail.fm", "name":"Ben Gotow", "provider":"imap", "settings":{"imap_username":"inboxapptest1@fastmail.fm","imap_host":"mail.messagingengine.com","imap_port":993,"smtp_host":"mail.messagingengine.com","smtp_port":0,"smtp_username":"inboxapptest1@fastmail.fm", "smtp_password":"trar2e","imap_password":"trar2e","ssl_required":true}}' "http://localhost:5100/auth?client_id=123"`) + global.Logger.info(`curl -X POST -H "Content-Type: application/json" -d '{"email":"inboxapptest1@fastmail.fm", "name":"Ben Gotow", "provider":"imap", "settings":{"imap_username":"inboxapptest1@fastmail.fm","imap_host":"mail.messagingengine.com","imap_port":993,"smtp_host":"mail.messagingengine.com","smtp_port":0,"smtp_username":"inboxapptest1@fastmail.fm", "smtp_password":"trar2e","imap_password":"trar2e","ssl_required":true}}' "http://localhost:5100/auth?client_id=123"`) } manager.ensureAccountIDsInRedis(accounts.map(a => a.id)).then(() => { manager.start(); From 0860f3027c87e2514fcbe4f947554f14542df158 Mon Sep 17 00:00:00 2001 From: Halla Moore Date: Mon, 11 Jul 2016 14:12:03 -0700 Subject: [PATCH 15/24] Fix two small errors --- packages/nylas-sync/imap/fetch-messages-in-folder.js | 2 +- packages/nylas-sync/sync-worker.js | 3 +++ 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/nylas-sync/imap/fetch-messages-in-folder.js b/packages/nylas-sync/imap/fetch-messages-in-folder.js index 0bf994f61..038dde66d 100644 --- a/packages/nylas-sync/imap/fetch-messages-in-folder.js +++ b/packages/nylas-sync/imap/fetch-messages-in-folder.js @@ -185,7 +185,7 @@ class FetchMessagesInFolder { this._logger.info({ key, num_messages: uids.length, - }`FetchMessagesInFolder: Fetching parts for messages`) + }, `FetchMessagesInFolder: Fetching parts for messages`) // note: the order of UIDs in the array doesn't matter, Gmail always // returns them in ascending (oldest => newest) order. diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index 0b7d760d4..7fb2efca1 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -55,6 +55,9 @@ class SyncWorker { this._onAccountUpdated(); break; case MessageTypes.SYNCBACK_REQUESTED: this.syncNow({reason: 'Syncback Action Queued'}); break; + case MessageTypes.ACCOUNT_CREATED: + // No other processing currently required for account creation + break; default: this._logger.error({message: msg}, 'SyncWorker: Invalid message') } From 04ab0d9034f8e0cc38e1093a964d7c353ba6263f Mon Sep 17 00:00:00 2001 From: Halla Moore Date: Mon, 11 Jul 2016 14:16:39 -0700 Subject: [PATCH 16/24] Change firstSyncCompletedAt to firstSyncCompletion, now explicitly 14 bytes. --- packages/nylas-api/serialization.js | 2 +- packages/nylas-core/models/shared/account.js | 4 ++-- packages/nylas-dashboard/public/js/app.jsx | 4 ++-- packages/nylas-sync/sync-worker.js | 4 ++-- 4 files changed, 7 insertions(+), 7 deletions(-) diff --git a/packages/nylas-api/serialization.js b/packages/nylas-api/serialization.js index 5d6a1c07c..3b0fa5f3b 100644 --- a/packages/nylas-api/serialization.js +++ b/packages/nylas-api/serialization.js @@ -22,7 +22,7 @@ function jsonSchema(modelName) { // connection_settings: Joi.object(), // sync_policy: Joi.object(), // sync_error: Joi.object().allow(null), - // first_sync_completed_at: Joi.number().allow(null), + // first_sync_completion: Joi.number().allow(null), // last_sync_completions: Joi.array(), // }) } diff --git a/packages/nylas-core/models/shared/account.js b/packages/nylas-core/models/shared/account.js index e5b203666..9a61101a9 100644 --- a/packages/nylas-core/models/shared/account.js +++ b/packages/nylas-core/models/shared/account.js @@ -12,7 +12,7 @@ module.exports = (sequelize, Sequelize) => { connectionCredentials: Sequelize.TEXT, syncPolicy: JSONType('syncPolicy'), syncError: JSONType('syncError', {defaultValue: null}), - firstSyncCompletedAt: Sequelize.INTEGER, + firstSyncCompletion: Sequelize.INTEGER(14), lastSyncCompletions: JSONARRAYType('lastSyncCompletions'), }, { classMethods: { @@ -31,7 +31,7 @@ module.exports = (sequelize, Sequelize) => { connection_settings: this.connectionSettings, sync_policy: this.syncPolicy, sync_error: this.syncError, - first_sync_completed_at: this.firstSyncCompletedAt, + first_sync_completion: this.firstSyncCompletion, last_sync_completions: this.lastSyncCompletions, created_at: this.createdAt, } diff --git a/packages/nylas-dashboard/public/js/app.jsx b/packages/nylas-dashboard/public/js/app.jsx index 660df19e8..bed514410 100644 --- a/packages/nylas-dashboard/public/js/app.jsx +++ b/packages/nylas-dashboard/public/js/app.jsx @@ -44,8 +44,8 @@ class Account extends React.Component { const timeSinceLastSync = (Date.now() - newestSync) / 1000; let firstSyncDuration = "Incomplete"; - if (account.first_sync_completed_at) { - firstSyncDuration = (new Date(account.first_sync_completed_at) - new Date(account.created_at)) / 1000; + if (account.first_sync_completion) { + firstSyncDuration = (new Date(account.first_sync_completion) - new Date(account.created_at)) / 1000; } return ( diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index 7fb2efca1..1dfb377b9 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -197,8 +197,8 @@ class SyncWorker { onSyncDidComplete() { const {afterSync} = this._account.syncPolicy; - if (!this._account.firstSyncCompletedAt) { - this._account.firstSyncCompletedAt = Date.now() + if (!this._account.firstSyncCompletion) { + this._account.firstSyncCompletion = Date.now() } const now = Date.now(); From bc10ff453e57c9375ba6c50a1909456fb156de6a Mon Sep 17 00:00:00 2001 From: Halla Moore Date: Mon, 11 Jul 2016 15:06:36 -0700 Subject: [PATCH 17/24] Change stop script to use pm2 stop command instead of delete --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 7a33802a6..d41b6612e 100644 --- a/package.json +++ b/package.json @@ -29,7 +29,7 @@ "scripts": { "start": "pm2 start ./pm2-dev.yml --watch; pm2 logs --raw | bunyan -o short", "logs": "pm2 logs --raw | bunyan -o short", - "stop": "pm2 delete all", + "stop": "pm2 stop all", "postinstall": "lerna bootstrap" }, "repository": { From 960dbdeb8f995d209e4cde7e6ce0be446e44633b Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 15:40:03 -0700 Subject: [PATCH 18/24] Update logger for sync process manager - Log identity data always --- packages/nylas-sync/sync-process-manager.js | 28 +++++++++++++-------- 1 file changed, 18 insertions(+), 10 deletions(-) diff --git a/packages/nylas-sync/sync-process-manager.js b/packages/nylas-sync/sync-process-manager.js index d9cab0829..560bc1fad 100644 --- a/packages/nylas-sync/sync-process-manager.js +++ b/packages/nylas-sync/sync-process-manager.js @@ -40,10 +40,11 @@ class SyncProcessManager { this._workers = {}; this._listenForSyncsClient = null; this._exiting = false; + this._logger = global.Logger.child({identity: IDENTITY}) } start() { - global.Logger.info(`ProcessManager: Starting with ID ${IDENTITY}`) + this._logger.info(`ProcessManager: Starting with ID`) this.unassignAccountsAssignedTo(IDENTITY).then(() => { this.unassignAccountsMissingHeartbeats(); @@ -63,12 +64,12 @@ class SyncProcessManager { client.setAsync(key, Date.now()).then(() => client.expireAsync(key, HEARTBEAT_EXPIRES) ).then(() => - global.Logger.info("ProcessManager: 💘") + this._logger.info("ProcessManager: 💘") ) } onSigInt() { - global.Logger.info(`ProcessManager: Exiting...`) + this._logger.info(`ProcessManager: Exiting...`) this._exiting = true; this.unassignAccountsAssignedTo(IDENTITY).then(() => @@ -85,7 +86,7 @@ class SyncProcessManager { let unseenIds = [].concat(accountIds); - global.Logger.info("ProcessManager: Starting scan for accountIds in database that are not present in Redis.") + this._logger.info("ProcessManager: Starting scan for accountIds in database that are not present in Redis.") return forEachAccountList((foundProcessIdentity, foundIds) => { unseenIds = unseenIds.filter((a) => !foundIds.includes(`${a}`)) @@ -94,7 +95,10 @@ class SyncProcessManager { if (unseenIds.length === 0) { return; } - global.Logger.info(`ProcessManager: Adding account IDs ${unseenIds.join(',')} to ${ACCOUNTS_UNCLAIMED}.`) + this._logger.info({ + unseen_ids: unseenIds.join(', '), + channel: ACCOUNTS_UNCLAIMED, + }, `ProcessManager: Adding unseen account IDs to ACCOUNTS_UNCLAIMED channel.`) unseenIds.map((id) => client.lpushAsync(ACCOUNTS_UNCLAIMED, id)); }); } @@ -102,7 +106,7 @@ class SyncProcessManager { unassignAccountsMissingHeartbeats() { const client = PubsubConnector.broadcastClient(); - global.Logger.info("ProcessManager: Starting unassignment for processes missing heartbeats.") + this._logger.info("ProcessManager: Starting unassignment for processes missing heartbeats.") Promise.each(client.keysAsync(`${ACCOUNTS_CLAIMED_PREFIX}*`), (key) => { const id = key.replace(ACCOUNTS_CLAIMED_PREFIX, ''); @@ -125,12 +129,15 @@ class SyncProcessManager { ) return unassignOne(0).then((returned) => { - global.Logger.info(`ProcessManager: Returned ${returned} accounts assigned to ${identity}.`) + this._logger.info({ + returned, + assigned_to: identity, + }, `ProcessManager: Returned accounts`) }); } update() { - global.Logger.info(`ProcessManager: Searching for an unclaimed account to sync.`) + this._logger.info(`ProcessManager: Searching for an unclaimed account to sync.`) this.acceptUnclaimedAccount().finally(() => { if (this._exiting) { @@ -170,7 +177,7 @@ class SyncProcessManager { if (this._exiting || this._workers[account.id]) { return; } - global.Logger.info(`ProcessManager: Starting worker for Account ${accountId}`) + this._logger.info({account_id: accountId}, `ProcessManager: Starting worker for Account`) this._workers[account.id] = new SyncWorker(account, db, () => { this.removeWorkerForAccountId(accountId) }); @@ -187,7 +194,8 @@ class SyncProcessManager { if (didRemove) { PubsubConnector.broadcastClient().rpushAsync(dst, accountId) } else { - throw new Error("Wanted to return item to pool, but didn't have claim on it.") + this._logger.error("Wanted to return item to pool, but didn't have claim on it.") + return } this._workers[accountId] = null; }); From d4cd2510db76c5d9dcfc17cf5755d0c93852c1a5 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 15:46:52 -0700 Subject: [PATCH 19/24] Fix pm2 run scripts --- package.json | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/package.json b/package.json index d41b6612e..f95dacb81 100644 --- a/package.json +++ b/package.json @@ -27,9 +27,9 @@ "sqlite3": "https://github.com/bengotow/node-sqlite3/archive/bengotow/usleep-v3.1.4.tar.gz" }, "scripts": { - "start": "pm2 start ./pm2-dev.yml --watch; pm2 logs --raw | bunyan -o short", + "start": "pm2 kill && pm2 start ./pm2-dev.yml --watch && pm2 logs --raw | bunyan -o short", "logs": "pm2 logs --raw | bunyan -o short", - "stop": "pm2 stop all", + "stop": "pm2 kill", "postinstall": "lerna bootstrap" }, "repository": { From 3c63268eecfb39890d2b64b873cdb84c8e646797 Mon Sep 17 00:00:00 2001 From: Ben Gotow Date: Mon, 11 Jul 2016 16:01:18 -0700 Subject: [PATCH 20/24] Return a new token for existing account instead of duplicating accounts --- packages/nylas-api/routes/auth.js | 57 ++++++++++++++-------- packages/nylas-core/imap-connection.js | 7 ++- packages/nylas-dashboard/public/js/app.jsx | 2 + packages/nylas-sync/sync-worker.js | 7 ++- 4 files changed, 49 insertions(+), 24 deletions(-) diff --git a/packages/nylas-api/routes/auth.js b/packages/nylas-api/routes/auth.js index d0cb6949e..5cd1e2fb4 100644 --- a/packages/nylas-api/routes/auth.js +++ b/packages/nylas-api/routes/auth.js @@ -43,24 +43,33 @@ const buildAccountWith = ({name, email, provider, settings, credentials}) => { return DatabaseConnector.forShared().then((db) => { const {AccountToken, Account} = db; - const account = Account.build({ - name: name, - provider: provider, - emailAddress: email, - connectionSettings: settings, - syncPolicy: SyncPolicy.defaultPolicy(), - lastSyncCompletions: [], - }) - account.setCredentials(credentials); + return Account.find({ + where: { + emailAddress: email, + connectionSettings: JSON.stringify(settings), + }, + }).then((existing) => { + const account = existing || Account.build({ + name: name, + provider: provider, + emailAddress: email, + connectionSettings: settings, + syncPolicy: SyncPolicy.defaultPolicy(), + lastSyncCompletions: [], + }) - return account.save().then((saved) => - AccountToken.create({accountId: saved.id}).then((token) => - DatabaseConnector.prepareAccountDatabase(saved.id).thenReturn({ - account: saved, - token: token, - }) - ) - ); + // always update with the latest credentials + account.setCredentials(credentials); + + return account.save().then((saved) => + AccountToken.create({accountId: saved.id}).then((token) => + DatabaseConnector.prepareAccountDatabase(saved.id).thenReturn({ + account: saved, + token: token, + }) + ) + ); + }); }); } @@ -76,7 +85,6 @@ module.exports = (server) => { validate: { query: { client_id: Joi.string().required(), - n1_id: Joi.string(), }, payload: { email: Joi.string().email().required(), @@ -98,7 +106,11 @@ module.exports = (server) => { const {settings, email, provider, name} = request.payload; if (provider === 'imap') { - connectionChecks.push(IMAPConnection.connect({db: dbStub, settings})) + connectionChecks.push(IMAPConnection.connect({ + logger: request.logger, + settings: settings, + db: dbStub, + })); } Promise.all(connectionChecks).then(() => { @@ -187,9 +199,12 @@ module.exports = (server) => { client_id: GMAIL_CLIENT_ID, client_secret: GMAIL_CLIENT_SECRET, } - Promise.all([ - IMAPConnection.connect({db: {}, settings: Object.assign({}, settings, credentials)}), + IMAPConnection.connect({ + logger: request.logger, + settings: Object.assign({}, settings, credentials), + db: {}, + }), ]) .then(() => buildAccountWith({ diff --git a/packages/nylas-core/imap-connection.js b/packages/nylas-core/imap-connection.js index 05e703b49..d833a7936 100644 --- a/packages/nylas-core/imap-connection.js +++ b/packages/nylas-core/imap-connection.js @@ -156,8 +156,6 @@ class IMAPBox { } return this._imap.closeBoxAsync(expunge) } - - } @@ -178,6 +176,11 @@ class IMAPConnection extends EventEmitter { constructor({db, settings, logger = console} = {}) { super(); + + if (!(settings instanceof Object)) { + throw new Error("IMAPConnection: Must be instantiated with `settings`") + } + this._logger = logger; this._db = db; this._queue = []; diff --git a/packages/nylas-dashboard/public/js/app.jsx b/packages/nylas-dashboard/public/js/app.jsx index bed514410..ecf7a1f7d 100644 --- a/packages/nylas-dashboard/public/js/app.jsx +++ b/packages/nylas-dashboard/public/js/app.jsx @@ -1,4 +1,6 @@ /* eslint react/react-in-jsx-scope: 0*/ +/* eslint no-console: 0*/ + const React = window.React; const ReactDOM = window.ReactDOM; const { diff --git a/packages/nylas-sync/sync-worker.js b/packages/nylas-sync/sync-worker.js index 1dfb377b9..7178e59cf 100644 --- a/packages/nylas-sync/sync-worker.js +++ b/packages/nylas-sync/sync-worker.js @@ -108,7 +108,12 @@ class SyncWorker { return Promise.reject(new Error("ensureConnection: There are no IMAP connection credentials for this account.")) } - const conn = new IMAPConnection({db: this._db, settings: Object.assign({}, settings, credentials), logger: this._logger}); + const conn = new IMAPConnection({ + db: this._db, + settings: Object.assign({}, settings, credentials), + logger: this._logger, + }); + conn.on('mail', () => { this._onConnectionIdleUpdate(); }) From 8e0cd92bad7fe719178586ae7064deb99a3d965b Mon Sep 17 00:00:00 2001 From: Ben Gotow Date: Mon, 11 Jul 2016 16:02:53 -0700 Subject: [PATCH 21/24] Require a logger when instantiating a connection --- packages/nylas-core/imap-connection.js | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/nylas-core/imap-connection.js b/packages/nylas-core/imap-connection.js index d833a7936..c692f11bf 100644 --- a/packages/nylas-core/imap-connection.js +++ b/packages/nylas-core/imap-connection.js @@ -174,12 +174,15 @@ class IMAPConnection extends EventEmitter { return new IMAPConnection(...args).connect() } - constructor({db, settings, logger = console} = {}) { + constructor({db, settings, logger} = {}) { super(); if (!(settings instanceof Object)) { throw new Error("IMAPConnection: Must be instantiated with `settings`") } + if (!logger) { + throw new Error("IMAPConnection: Must be instantiated with `logger`") + } this._logger = logger; this._db = db; From 2dc31cb576cdf2dd6dbae0f23b494e2978a0bc10 Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 15:50:55 -0700 Subject: [PATCH 22/24] Add number of syncing accounts to sync process manager heartbeat --- packages/nylas-sync/sync-process-manager.js | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/packages/nylas-sync/sync-process-manager.js b/packages/nylas-sync/sync-process-manager.js index 560bc1fad..8d4042895 100644 --- a/packages/nylas-sync/sync-process-manager.js +++ b/packages/nylas-sync/sync-process-manager.js @@ -64,7 +64,9 @@ class SyncProcessManager { client.setAsync(key, Date.now()).then(() => client.expireAsync(key, HEARTBEAT_EXPIRES) ).then(() => - this._logger.info("ProcessManager: 💘") + this._logger.info({ + accounts_syncing_count: Object.keys(this._workers).length, + }, "ProcessManager: 💘") ) } From ae51646de62dc2a46ddbc2b1544f2531100b7b0f Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 16:33:56 -0700 Subject: [PATCH 23/24] Comment out new relic for now --- packages/nylas-api/app.js | 2 +- packages/nylas-sync/app.js | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/nylas-api/app.js b/packages/nylas-api/app.js index fbc8aedfa..dc9b08e08 100644 --- a/packages/nylas-api/app.js +++ b/packages/nylas-api/app.js @@ -1,4 +1,4 @@ -require('newrelic'); +// require('newrelic'); const Hapi = require('hapi'); const HapiSwagger = require('hapi-swagger'); diff --git a/packages/nylas-sync/app.js b/packages/nylas-sync/app.js index 14ae4c177..ac81a02f1 100644 --- a/packages/nylas-sync/app.js +++ b/packages/nylas-sync/app.js @@ -1,4 +1,4 @@ -require('newrelic'); +// require('newrelic'); global.Promise = require('bluebird'); const {DatabaseConnector, Logger} = require(`nylas-core`) const SyncProcessManager = require('./sync-process-manager'); From f8b8dfb87f381380f78055064b54624a724b4adb Mon Sep 17 00:00:00 2001 From: Juan Tejada Date: Mon, 11 Jul 2016 16:40:48 -0700 Subject: [PATCH 24/24] Revert to running pm2 in no-daemon mode in dev - Add a stream for pretty logging in dev mode --- package.json | 4 ++-- packages/nylas-core/logger.js | 16 ++++++++++++---- 2 files changed, 14 insertions(+), 6 deletions(-) diff --git a/package.json b/package.json index f95dacb81..625d7d2a7 100644 --- a/package.json +++ b/package.json @@ -18,6 +18,7 @@ }, "devDependencies": { "babel-eslint": "6.x", + "bunyan-prettystream": "^0.1.3", "eslint": "2.x", "eslint-config-airbnb": "8.x", "eslint-plugin-import": "1.x", @@ -27,8 +28,7 @@ "sqlite3": "https://github.com/bengotow/node-sqlite3/archive/bengotow/usleep-v3.1.4.tar.gz" }, "scripts": { - "start": "pm2 kill && pm2 start ./pm2-dev.yml --watch && pm2 logs --raw | bunyan -o short", - "logs": "pm2 logs --raw | bunyan -o short", + "start": "pm2 start ./pm2-dev.yml --no-daemon", "stop": "pm2 kill", "postinstall": "lerna bootstrap" }, diff --git a/packages/nylas-core/logger.js b/packages/nylas-core/logger.js index 40c73ad31..1bdcb9002 100644 --- a/packages/nylas-core/logger.js +++ b/packages/nylas-core/logger.js @@ -1,17 +1,25 @@ const bunyan = require('bunyan') const createCWStream = require('bunyan-cloudwatch') +const PrettyStream = require('bunyan-prettystream'); const NODE_ENV = process.env.NODE_ENV || 'unknown' function getLogStreams(name, env) { + if (env === 'development') { + const prettyStdOut = new PrettyStream(); + prettyStdOut.pipe(process.stdout); + const stdoutStream = { + type: 'raw', + level: 'debug', + stream: prettyStdOut, + } + return [stdoutStream] + } + const stdoutStream = { stream: process.stdout, level: 'info', } - if (env === 'development') { - return [stdoutStream] - } - const cloudwatchStream = { stream: createCWStream({ logGroupName: `k2-${env}`,