diff --git a/NEWS.md b/NEWS.md index 25008b8f..7ed40872 100644 --- a/NEWS.md +++ b/NEWS.md @@ -3,6 +3,8 @@ ## 4.4.1 Released 2017-mm-dd +Announcements: + - Logging all errors ## 4.4.0 Released 2017-12-12 diff --git a/config/environments/development.js.example b/config/environments/development.js.example index 91cf2a39..55cda5ba 100644 --- a/config/environments/development.js.example +++ b/config/environments/development.js.example @@ -55,7 +55,7 @@ var config = { ,socket_timeout: 600000 ,enable_cors: true ,cache_enabled: false - ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler])' + ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])' // If log_filename is given logs will be written // there, in append mode. Otherwise stdout is used (default). // Log file will be re-opened on receiving the HUP signal diff --git a/config/environments/production.js.example b/config/environments/production.js.example index 7d7a00cb..3904d46e 100644 --- a/config/environments/production.js.example +++ b/config/environments/production.js.example @@ -55,7 +55,7 @@ var config = { ,socket_timeout: 600000 ,enable_cors: true ,cache_enabled: true - ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler])' + ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])' // If log_filename is given logs will be written // there, in append mode. Otherwise stdout is used (default). // Log file will be re-opened on receiving the HUP signal diff --git a/config/environments/staging.js.example b/config/environments/staging.js.example index 3d1098fb..15031991 100644 --- a/config/environments/staging.js.example +++ b/config/environments/staging.js.example @@ -55,7 +55,7 @@ var config = { ,socket_timeout: 600000 ,enable_cors: true ,cache_enabled: true - ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms (:res[X-Tiler-Profiler]) -> :res[Content-Type]' + ,log_format: ':req[X-Real-IP] :method :req[Host]:url :status :response-time ms (:res[X-Tiler-Profiler]) -> :res[Content-Type] (:res[X-Tiler-Errors])' // If log_filename is given logs will be written // there, in append mode. Otherwise stdout is used (default). // Log file will be re-opened on receiving the HUP signal diff --git a/config/environments/test.js.example b/config/environments/test.js.example index ea788a22..43ebf844 100644 --- a/config/environments/test.js.example +++ b/config/environments/test.js.example @@ -54,7 +54,7 @@ var config = { ,socket_timeout: 600000 ,enable_cors: true ,cache_enabled: false - ,log_format: '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler])' + ,log_format: '[:date] :req[X-Real-IP] :method :req[Host]:url :status :response-time ms -> :res[Content-Type] (:res[X-Tiler-Profiler]) (:res[X-Tiler-Errors])' // If log_filename is given logs will be written // there, in append mode. Otherwise stdout is used (default). // Log file will be re-opened on receiving the HUP signal diff --git a/lib/cartodb/middleware/error-middleware.js b/lib/cartodb/middleware/error-middleware.js index 80457b9c..f3f2eb36 100644 --- a/lib/cartodb/middleware/error-middleware.js +++ b/lib/cartodb/middleware/error-middleware.js @@ -18,7 +18,8 @@ module.exports = function errorMiddleware (/* options */) { if (err.message === 'Tile does not exist' && res.locals.format === 'mvt') { statusCode = 204; } - + + setErrorHeader(allErrors, statusCode, res); debug('[%s ERROR] -- %d: %s, %s', label, statusCode, err, err.stack); // If a callback was requested, force status to 200 @@ -160,3 +161,31 @@ function errorMessageWithContext(err) { return error; } + +function setErrorHeader(errors, statusCode, res) { + let errorsCopy = errors.slice(0); + const mainError = errorsCopy.shift(); + + let errorsLog = { + mainError: { + statusCode: statusCode || 200, + message: mainError.message, + name: mainError.name, + label: mainError.label, + type: mainError.type, + subtype: mainError.subtype + } + }; + + errorsLog.moreErrors = errorsCopy.map(error => { + return { + message: error.message, + name: error.name, + label: error.label, + type: error.type, + subtype: error.subtype + }; + }); + + res.set('X-Tiler-Errors', JSON.stringify(errorsLog)); +} diff --git a/test/acceptance/error-middleware.js b/test/acceptance/error-middleware.js new file mode 100644 index 00000000..3ad22774 --- /dev/null +++ b/test/acceptance/error-middleware.js @@ -0,0 +1,40 @@ +const assert = require('../support/assert'); +const TestClient = require('../support/test-client'); + +describe('error middleware', function () { + it('should returns a errors header', function (done) { + const mapConfig = { + version: '1.6.0', + layers: [{ + type: 'mapnik', + options: {} + }] + }; + + const errorHeader = { + mainError: { + statusCode: 400, + message: "Missing cartocss for layer 0 options", + name: "Error", + label: "ANONYMOUS LAYERGROUP", + type: "layer", + }, + moreErrors: [] + }; + + this.testClient = new TestClient(mapConfig, 1234); + + const expectedResponse = { + status: 400, + headers: { + 'Content-Type': 'application/json; charset=utf-8', + 'X-Tiler-Errors': JSON.stringify(errorHeader) + } + }; + + this.testClient.getLayergroup(expectedResponse, (err) => { + assert.ifError(err); + done(); + }); + }); +}); diff --git a/test/unit/cartodb/base_controller.js b/test/unit/cartodb/base_controller.js deleted file mode 100644 index 9bf21ccd..00000000 --- a/test/unit/cartodb/base_controller.js +++ /dev/null @@ -1,23 +0,0 @@ -require('../../support/test_helper.js'); - -var assert = require('assert'); -var errorMiddleware = require('../../../lib/cartodb/middleware/error-middleware'); - -describe('error-middleware', function() { - - it('different formats for postgis plugin error returns 400 as status code', function() { - - var expectedStatusCode = 400; - assert.equal( - errorMiddleware.findStatusCode("Postgis Plugin: ERROR: column \"missing\" does not exist\n"), - expectedStatusCode, - "Error status code for single line does not match" - ); - - assert.equal( - errorMiddleware.findStatusCode("Postgis Plugin: PSQL error:\nERROR: column \"missing\" does not exist\n"), - expectedStatusCode, - "Error status code for multiline/PSQL does not match" - ); - }); -}); diff --git a/test/unit/cartodb/error-middleware.test.js b/test/unit/cartodb/error-middleware.test.js new file mode 100644 index 00000000..4e235c4a --- /dev/null +++ b/test/unit/cartodb/error-middleware.test.js @@ -0,0 +1,125 @@ +require('../../support/test_helper.js'); + +var assert = require('assert'); +var errorMiddleware = require('../../../lib/cartodb/middleware/error-middleware'); + +describe('error-middleware', function() { + + it('different formats for postgis plugin error returns 400 as status code', function() { + + var expectedStatusCode = 400; + assert.equal( + errorMiddleware.findStatusCode("Postgis Plugin: ERROR: column \"missing\" does not exist\n"), + expectedStatusCode, + "Error status code for single line does not match" + ); + + assert.equal( + errorMiddleware.findStatusCode("Postgis Plugin: PSQL error:\nERROR: column \"missing\" does not exist\n"), + expectedStatusCode, + "Error status code for multiline/PSQL does not match" + ); + }); + + it('should return a header with errors', function (done) { + const error = new Error('error test'); + error.label = 'test label'; + error.type = 'test type'; + error.subtype = 'test subtype'; + + const errors = [error, error]; + + const req = {}; + const res = { + headers: {}, + set (key, value) { + this.headers[key] = value; + }, + statusCode: 0, + status (status) { + this.statusCode = status; + }, + json () {}, + send () {} + }; + + const errorHeader = { + mainError: { + statusCode: 400, + message: error.message, + name: error.name, + label: error.label, + type: error.type, + subtype: error.subtype, + }, + moreErrors: [{ + message: error.message, + name: error.name, + label: error.label, + type: error.type, + subtype: error.subtype + }] + }; + + const errorFn = errorMiddleware(); + errorFn(errors, req, res); + + assert.deepEqual(res.headers, { + 'X-Tiler-Errors': JSON.stringify(errorHeader) + }); + + done(); + }); + + it('JSONP should return a header with error status code', function (done) { + const error = new Error('error test'); + error.label = 'test label'; + error.type = 'test type'; + error.subtype = 'test subtype'; + + const errors = [error, error]; + + const req = { + query: { callback: true } + }; + const res = { + headers: {}, + set (key, value) { + this.headers[key] = value; + }, + statusCode: 0, + status (status) { + this.statusCode = status; + }, + jsonp () {}, + send () {} + }; + + const errorHeader = { + mainError: { + statusCode: 400, + message: error.message, + name: error.name, + label: error.label, + type: error.type, + subtype: error.subtype, + }, + moreErrors: [{ + message: error.message, + name: error.name, + label: error.label, + type: error.type, + subtype: error.subtype + }] + }; + + const errorFn = errorMiddleware(); + errorFn(errors, req, res); + + assert.deepEqual(res.headers, { + 'X-Tiler-Errors': JSON.stringify(errorHeader) + }); + + done(); + }); +});