Merge branch 'master' into express-4.x

2016-09-30 17:37:30 +02:00 · 2016-09-30 17:37:30 +02:00 · bf1a67780d
commit bf1a67780d
parent 0e03bcd1d3 d7762c9f73
14 changed files with 266 additions and 21 deletions
--- a/NEWS.md
+++ b/NEWS.md
@ -1,7 +1,17 @@
-1.35.1 - 2016-mm-dd
+1.36.1 - 2016-mm-dd
 -------------------


+1.36.0 - 2016-09-30
+-------------------
+
+New features:
+ * Log queries from batch fallback jobs.
+
+Enhancements:
+ * assert.response following callback(err, obj) pattern.
+
+
 1.35.0 - 2016-09-15
 -------------------

--- a/app.js
+++ b/app.js
@ -100,6 +100,10 @@ process.on('SIGHUP', function() {
        global.logger = global.log4js.getLogger();
        console.log('Log files reloaded');
    });
+
+    if (server.batch && server.batch.logger) {
+        server.batch.logger.reopenFileStreams();
+    }
 });

 process.on('SIGTERM', function () {
--- a/app/server.js
+++ b/app/server.js
@ -203,7 +203,7 @@ function App() {
    var isBatchProcess = process.argv.indexOf('--no-batch') === -1;

    if (global.settings.environment !== 'test' && isBatchProcess) {
-        app.batch = batchFactory(metadataBackend, redisConfig, statsd_client);
+        app.batch = batchFactory(metadataBackend, redisConfig, statsd_client, global.settings.batch_log_filename);
        app.batch.start();
    }

--- a/batch/batch-logger.js
+++ b/batch/batch-logger.js
@ -0,0 +1,25 @@
+'use strict';
+
+var bunyan = require('bunyan');
+var fs = require('fs');
+
+function BatchLogger (path) {
+    this.path = path;
+    this.logger = bunyan.createLogger({
+        name: 'batch-queries',
+        streams: [{
+            level: 'info',
+            stream: path ? fs.createWriteStream(path, { flags: 'a', encoding: 'utf8' }) :  process.stdout
+        }]
+    });
+}
+
+module.exports = BatchLogger;
+
+BatchLogger.prototype.log = function (job) {
+    return job.log(this.logger);
+};
+
+BatchLogger.prototype.reopenFileStreams = function () {
+    this.logger.reopenFileStreams();
+};
--- a/batch/batch.js
+++ b/batch/batch.js
@ -7,12 +7,13 @@ var forever = require('./util/forever');
 var queue = require('queue-async');
 var jobStatus = require('./job_status');

-function Batch(jobSubscriber, jobQueuePool, jobRunner, jobService) {
+function Batch(jobSubscriber, jobQueuePool, jobRunner, jobService, logger) {
    EventEmitter.call(this);
    this.jobSubscriber = jobSubscriber;
    this.jobQueuePool = jobQueuePool;
    this.jobRunner = jobRunner;
    this.jobService = jobService;
+    this.logger = logger;
 }
 util.inherits(Batch, EventEmitter);

@ -90,6 +91,8 @@ Batch.prototype._consumeJobs = function (host, queue, callback) {
                debug('Job %s %s in %s', job_id, job.data.status, host);
            }

+            self.logger.log(job);
+
            self.emit('job:' + job.data.status, job_id);

            callback();
--- a/batch/index.js
+++ b/batch/index.js
@ -1,6 +1,5 @@
 'use strict';

-
 var RedisPool = require('redis-mpool');
 var _ = require('underscore');
 var JobRunner = require('./job_runner');
@ -14,9 +13,10 @@ var JobPublisher = require('./job_publisher');
 var JobQueue = require('./job_queue');
 var JobBackend = require('./job_backend');
 var JobService = require('./job_service');
+var BatchLogger = require('./batch-logger');
 var Batch = require('./batch');

-module.exports = function batchFactory (metadataBackend, redisConfig, statsdClient) {
+module.exports = function batchFactory (metadataBackend, redisConfig, statsdClient, loggerPath) {
    var redisPoolSubscriber = new RedisPool(_.extend(redisConfig, { name: 'batch-subscriber'}));
    var redisPoolPublisher = new RedisPool(_.extend(redisConfig, { name: 'batch-publisher'}));
    var queueSeeker = new QueueSeeker(metadataBackend);
@ -30,6 +30,7 @@ module.exports = function batchFactory (metadataBackend, redisConfig, statsdClie
    var jobCanceller = new JobCanceller(userDatabaseMetadataService);
    var jobService = new JobService(jobBackend, jobCanceller);
    var jobRunner = new JobRunner(jobService, jobQueue, queryRunner, statsdClient);
+    var logger = new BatchLogger(loggerPath);

-    return new Batch(jobSubscriber, jobQueuePool, jobRunner, jobService);
+    return new Batch(jobSubscriber, jobQueuePool, jobRunner, jobService, logger);
 };
--- a/batch/models/job_base.js
+++ b/batch/models/job_base.js
@ -111,3 +111,7 @@ JobBase.prototype.serialize = function () {

    return data;
 };
+
+JobBase.prototype.log = function(/*logger*/) {
+    return false;
+};
--- a/batch/models/job_fallback.js
+++ b/batch/models/job_fallback.js
@ -7,6 +7,9 @@ var QueryFallback = require('./query/query_fallback');
 var MainFallback = require('./query/main_fallback');
 var QueryFactory = require('./query/query_factory');

+var JobUtils = require('./job_state_machine');
+var jobUtils = new JobUtils();
+
 function JobFallback(jobDefinition) {
    JobBase.call(this, jobDefinition);

@ -206,3 +209,68 @@ JobFallback.prototype.getLastFinishedStatus = function () {
        return this.isFinalStatus(status) ? status : lastFinished;
    }.bind(this), jobStatus.DONE);
 };
+
+JobFallback.prototype.log = function(logger) {
+    if (!isFinished(this)) {
+        return false;
+    }
+
+    var queries = this.data.query.query;
+
+    for (var i = 0; i < queries.length; i++) {
+        var query = queries[i];
+
+        var output = {
+            time: query.started_at,
+            endtime: query.ended_at,
+            username: this.data.user,
+            job: this.data.job_id,
+            elapsed: elapsedTime(query.started_at, query.ended_at)
+        };
+
+        var queryId = query.id;
+
+        if (queryId) {
+            output.query_id = queryId;
+
+            var node = parseQueryId(queryId);
+            if (node) {
+                output.analysis = node.analysisId;
+                output.node = node.nodeId;
+                output.type = node.nodeType;
+            }
+        }
+
+        logger.info(output);
+    }
+
+    return true;
+};
+
+function isFinished (job) {
+    return jobUtils.isFinalStatus(job.data.status) &&
+        (!job.data.fallback_status || jobUtils.isFinalStatus(job.data.fallback_status));
+}
+
+function parseQueryId (queryId) {
+    var data = queryId.split(':');
+
+    if (data.length === 3) {
+        return {
+            analysisId: data[0],
+            nodeId: data[1],
+            nodeType: data[2]
+        };
+    }
+    return null;
+}
+
+function elapsedTime (started_at, ended_at) {
+    if (!started_at || !ended_at) {
+        return;
+    }
+
+    var start = new Date(started_at);
+    var end = new Date(ended_at);
+    return end.getTime() - start.getTime();
+}
--- a/config/environments/development.js.example
+++ b/config/environments/development.js.example
@ -30,6 +30,7 @@ module.exports.db_host      = 'localhost';
 module.exports.db_port      = '5432';
 module.exports.db_batch_port      = '5432';
 module.exports.finished_jobs_ttl_in_seconds = 2 * 3600; // 2 hours
+module.exports.batch_log_filename = 'logs/batch-queries.log';
 // Max database connections in the pool
 // Subsequent connections will wait for a free slot.
 // NOTE: not used by OGR-mediated accesses
--- a/config/environments/production.js.example
+++ b/config/environments/production.js.example
@ -31,6 +31,7 @@ module.exports.db_host      = 'localhost';
 module.exports.db_port      = '6432';
 module.exports.db_batch_port      = '5432';
 module.exports.finished_jobs_ttl_in_seconds = 2 * 3600; // 2 hours
+module.exports.batch_log_filename = 'logs/batch-queries.log';
 // Max database connections in the pool
 // Subsequent connections will wait for a free slot.i
 // NOTE: not used by OGR-mediated accesses
--- a/config/environments/staging.js.example
+++ b/config/environments/staging.js.example
@ -31,6 +31,7 @@ module.exports.db_host      = 'localhost';
 module.exports.db_port      = '6432';
 module.exports.db_batch_port      = '5432';
 module.exports.finished_jobs_ttl_in_seconds = 2 * 3600; // 2 hours
+module.exports.batch_log_filename = 'logs/batch-queries.log';
 // Max database connections in the pool
 // Subsequent connections will wait for a free slot.
 // NOTE: not used by OGR-mediated accesses
--- a/config/environments/test.js.example
+++ b/config/environments/test.js.example
@ -28,6 +28,7 @@ module.exports.db_host      = 'localhost';
 module.exports.db_port      = '5432';
 module.exports.db_batch_port      = '5432';
 module.exports.finished_jobs_ttl_in_seconds = 2 * 3600; // 2 hours
+module.exports.batch_log_filename = 'logs/batch-queries.log';
 // Max database connections in the pool
 // Subsequent connections will wait for a free slot.
 // NOTE: not used by OGR-mediated accesses
--- a/npm-shrinkwrap.json
+++ b/npm-shrinkwrap.json
@ -1,6 +1,6 @@
 {
  "name": "cartodb_sql_api",
-  "version": "1.35.1",
+  "version": "1.36.1",
  "dependencies": {
    "body-parser": {
      "version": "1.14.2",
@ -90,7 +90,7 @@
            },
            "mime-types": {
              "version": "2.1.12",
-              "from": "mime-types@>=2.1.2 <2.2.0",
+              "from": "mime-types@>=2.1.11 <2.2.0",
              "resolved": "https://registry.npmjs.org/mime-types/-/mime-types-2.1.12.tgz",
              "dependencies": {
                "mime-db": {
@ -104,6 +104,131 @@
        }
      }
    },
+    "bunyan": {
+      "version": "1.8.1",
+      "from": "bunyan@1.8.1",
+      "resolved": "https://registry.npmjs.org/bunyan/-/bunyan-1.8.1.tgz",
+      "dependencies": {
+        "dtrace-provider": {
+          "version": "0.6.0",
+          "from": "dtrace-provider@>=0.6.0 <0.7.0",
+          "resolved": "https://registry.npmjs.org/dtrace-provider/-/dtrace-provider-0.6.0.tgz",
+          "dependencies": {
+            "nan": {
+              "version": "2.4.0",
+              "from": "nan@>=2.0.8 <3.0.0",
+              "resolved": "https://registry.npmjs.org/nan/-/nan-2.4.0.tgz"
+            }
+          }
+        },
+        "mv": {
+          "version": "2.1.1",
+          "from": "mv@>=2.0.0 <3.0.0",
+          "resolved": "https://registry.npmjs.org/mv/-/mv-2.1.1.tgz",
+          "dependencies": {
+            "mkdirp": {
+              "version": "0.5.1",
+              "from": "mkdirp@>=0.5.1 <0.6.0",
+              "resolved": "https://registry.npmjs.org/mkdirp/-/mkdirp-0.5.1.tgz",
+              "dependencies": {
+                "minimist": {
+                  "version": "0.0.8",
+                  "from": "minimist@0.0.8",
+                  "resolved": "https://registry.npmjs.org/minimist/-/minimist-0.0.8.tgz"
+                }
+              }
+            },
+            "ncp": {
+              "version": "2.0.0",
+              "from": "ncp@>=2.0.0 <2.1.0",
+              "resolved": "https://registry.npmjs.org/ncp/-/ncp-2.0.0.tgz"
+            },
+            "rimraf": {
+              "version": "2.4.5",
+              "from": "rimraf@>=2.4.0 <2.5.0",
+              "resolved": "https://registry.npmjs.org/rimraf/-/rimraf-2.4.5.tgz",
+              "dependencies": {
+                "glob": {
+                  "version": "6.0.4",
+                  "from": "glob@>=6.0.1 <7.0.0",
+                  "resolved": "https://registry.npmjs.org/glob/-/glob-6.0.4.tgz",
+                  "dependencies": {
+                    "inflight": {
+                      "version": "1.0.5",
+                      "from": "inflight@>=1.0.4 <2.0.0",
+                      "resolved": "https://registry.npmjs.org/inflight/-/inflight-1.0.5.tgz",
+                      "dependencies": {
+                        "wrappy": {
+                          "version": "1.0.2",
+                          "from": "wrappy@>=1.0.0 <2.0.0",
+                          "resolved": "https://registry.npmjs.org/wrappy/-/wrappy-1.0.2.tgz"
+                        }
+                      }
+                    },
+                    "inherits": {
+                      "version": "2.0.3",
+                      "from": "inherits@>=2.0.0 <3.0.0",
+                      "resolved": "https://registry.npmjs.org/inherits/-/inherits-2.0.3.tgz"
+                    },
+                    "minimatch": {
+                      "version": "3.0.3",
+                      "from": "minimatch@>=2.0.0 <3.0.0||>=3.0.0 <4.0.0",
+                      "resolved": "https://registry.npmjs.org/minimatch/-/minimatch-3.0.3.tgz",
+                      "dependencies": {
+                        "brace-expansion": {
+                          "version": "1.1.6",
+                          "from": "brace-expansion@>=1.0.0 <2.0.0",
+                          "resolved": "https://registry.npmjs.org/brace-expansion/-/brace-expansion-1.1.6.tgz",
+                          "dependencies": {
+                            "balanced-match": {
+                              "version": "0.4.2",
+                              "from": "balanced-match@>=0.4.1 <0.5.0",
+                              "resolved": "https://registry.npmjs.org/balanced-match/-/balanced-match-0.4.2.tgz"
+                            },
+                            "concat-map": {
+                              "version": "0.0.1",
+                              "from": "concat-map@0.0.1",
+                              "resolved": "https://registry.npmjs.org/concat-map/-/concat-map-0.0.1.tgz"
+                            }
+                          }
+                        }
+                      }
+                    },
+                    "once": {
+                      "version": "1.4.0",
+                      "from": "once@>=1.3.0 <2.0.0",
+                      "resolved": "https://registry.npmjs.org/once/-/once-1.4.0.tgz",
+                      "dependencies": {
+                        "wrappy": {
+                          "version": "1.0.2",
+                          "from": "wrappy@>=1.0.0 <2.0.0",
+                          "resolved": "https://registry.npmjs.org/wrappy/-/wrappy-1.0.2.tgz"
+                        }
+                      }
+                    },
+                    "path-is-absolute": {
+                      "version": "1.0.1",
+                      "from": "path-is-absolute@>=1.0.0 <2.0.0",
+                      "resolved": "https://registry.npmjs.org/path-is-absolute/-/path-is-absolute-1.0.1.tgz"
+                    }
+                  }
+                }
+              }
+            }
+          }
+        },
+        "safe-json-stringify": {
+          "version": "1.0.3",
+          "from": "safe-json-stringify@>=1.0.0 <2.0.0",
+          "resolved": "https://registry.npmjs.org/safe-json-stringify/-/safe-json-stringify-1.0.3.tgz"
+        },
+        "moment": {
+          "version": "2.15.1",
+          "from": "moment@>=2.10.6 <3.0.0",
+          "resolved": "https://registry.npmjs.org/moment/-/moment-2.15.1.tgz"
+        }
+      }
+    },
    "cartodb-psql": {
      "version": "0.6.1",
      "from": "cartodb-psql@>=0.6.0 <0.7.0",
@ -584,7 +709,7 @@
          "dependencies": {
            "strip-ansi": {
              "version": "3.0.1",
-              "from": "strip-ansi@>=3.0.0 <4.0.0",
+              "from": "strip-ansi@>=3.0.1 <4.0.0",
              "resolved": "https://registry.npmjs.org/strip-ansi/-/strip-ansi-3.0.1.tgz",
              "dependencies": {
                "ansi-regex": {
@ -675,9 +800,9 @@
                  "resolved": "https://registry.npmjs.org/load-json-file/-/load-json-file-1.1.0.tgz",
                  "dependencies": {
                    "graceful-fs": {
-                      "version": "4.1.6",
+                      "version": "4.1.9",
                      "from": "graceful-fs@>=4.1.2 <5.0.0",
-                      "resolved": "https://registry.npmjs.org/graceful-fs/-/graceful-fs-4.1.6.tgz"
+                      "resolved": "https://registry.npmjs.org/graceful-fs/-/graceful-fs-4.1.9.tgz"
                    },
                    "parse-json": {
                      "version": "2.2.0",
@ -788,9 +913,9 @@
                  "resolved": "https://registry.npmjs.org/path-type/-/path-type-1.1.0.tgz",
                  "dependencies": {
                    "graceful-fs": {
-                      "version": "4.1.6",
+                      "version": "4.1.9",
                      "from": "graceful-fs@>=4.1.2 <5.0.0",
-                      "resolved": "https://registry.npmjs.org/graceful-fs/-/graceful-fs-4.1.6.tgz"
+                      "resolved": "https://registry.npmjs.org/graceful-fs/-/graceful-fs-4.1.9.tgz"
                    },
                    "pify": {
                      "version": "2.3.0",
@ -836,14 +961,14 @@
          "resolved": "https://registry.npmjs.org/string-width/-/string-width-1.0.2.tgz",
          "dependencies": {
            "code-point-at": {
-              "version": "1.0.0",
+              "version": "1.0.1",
              "from": "code-point-at@>=1.0.0 <2.0.0",
-              "resolved": "https://registry.npmjs.org/code-point-at/-/code-point-at-1.0.0.tgz",
+              "resolved": "https://registry.npmjs.org/code-point-at/-/code-point-at-1.0.1.tgz",
              "dependencies": {
                "number-is-nan": {
-                  "version": "1.0.0",
+                  "version": "1.0.1",
                  "from": "number-is-nan@>=1.0.0 <2.0.0",
-                  "resolved": "https://registry.npmjs.org/number-is-nan/-/number-is-nan-1.0.0.tgz"
+                  "resolved": "https://registry.npmjs.org/number-is-nan/-/number-is-nan-1.0.1.tgz"
                }
              }
            },
@ -853,15 +978,15 @@
              "resolved": "https://registry.npmjs.org/is-fullwidth-code-point/-/is-fullwidth-code-point-1.0.0.tgz",
              "dependencies": {
                "number-is-nan": {
-                  "version": "1.0.0",
+                  "version": "1.0.1",
                  "from": "number-is-nan@>=1.0.0 <2.0.0",
-                  "resolved": "https://registry.npmjs.org/number-is-nan/-/number-is-nan-1.0.0.tgz"
+                  "resolved": "https://registry.npmjs.org/number-is-nan/-/number-is-nan-1.0.1.tgz"
                }
              }
            },
            "strip-ansi": {
              "version": "3.0.1",
-              "from": "strip-ansi@>=3.0.0 <4.0.0",
+              "from": "strip-ansi@>=3.0.1 <4.0.0",
              "resolved": "https://registry.npmjs.org/strip-ansi/-/strip-ansi-3.0.1.tgz",
              "dependencies": {
                "ansi-regex": {
--- a/package.json
+++ b/package.json
@ -5,7 +5,7 @@
  "keywords": [
    "cartodb"
  ],
-  "version": "1.35.1",
+  "version": "1.36.1",
  "repository": {
    "type": "git",
    "url": "git://github.com/CartoDB/CartoDB-SQL-API.git"
@ -18,6 +18,7 @@
  ],
  "dependencies": {
    "body-parser": "~1.14.2",
+    "bunyan": "1.8.1",
    "cartodb-psql": "~0.6.0",
    "cartodb-query-tables": "0.2.0",
    "cartodb-redis": "0.13.1",