diff --git a/package-lock.json b/package-lock.json index 48200e4d7..fba76262e 100644 --- a/package-lock.json +++ b/package-lock.json @@ -3180,9 +3180,9 @@ } }, "@types/aws-lambda": { - "version": "8.10.27", - "resolved": "https://registry.npmjs.org/@types/aws-lambda/-/aws-lambda-8.10.27.tgz", - "integrity": "sha512-9QjcjORRtgG5KPVHWqGZ0F2Uo/ALUWQ5D7qfJEco0fEjoSbA908w05RXql7YPS72jQ1w6I+pr+8pQPqBPlYnSw==" + "version": "8.10.28", + "resolved": "https://registry.npmjs.org/@types/aws-lambda/-/aws-lambda-8.10.28.tgz", + "integrity": "sha512-MERGUHaCnVze5EausDGZQj1ZcH4YdiD7ltE0+guuZQOfrV7SipmCcQLFo6m36hostsRDjcs9UjQMRiPEdUBG9A==" }, "@types/aws-serverless-express": { "version": "3.3.1", @@ -3386,9 +3386,9 @@ } }, "@types/lodash": { - "version": "4.14.135", - "resolved": "https://registry.npmjs.org/@types/lodash/-/lodash-4.14.135.tgz", - "integrity": "sha512-Ed+tSZ9qM1oYpi5kzdsBuOzcAIn1wDW+e8TFJ50IMJMlSopGdJgKAbhHzN6h1E1OfjlGOr2JepzEWtg9NIfoNg==" + "version": "4.14.136", + "resolved": "https://registry.npmjs.org/@types/lodash/-/lodash-4.14.136.tgz", + "integrity": "sha512-0GJhzBdvsW2RUccNHOBkabI8HZVdOXmXbXhuKlDEd5Vv12P7oAVGfomGp3Ne21o5D/qu1WmthlNKFaoZJJeErA==" }, "@types/lodash.merge": { "version": "4.6.6", @@ -5476,7 +5476,8 @@ }, "ansi-regex": { "version": "2.1.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-w7M6te42DYbg5ijwRorn7yfWVN8=", "dev": true, "optional": true }, @@ -5500,7 +5501,8 @@ }, "balanced-match": { "version": "1.0.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-ibTRmasr7kneFk6gK4nORi1xt2c=", "dev": true, "optional": true }, @@ -5524,19 +5526,22 @@ }, "code-point-at": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-DQcLTQQ6W+ozovGkDi7bPZpMz3c=", "dev": true, "optional": true }, "concat-map": { "version": "0.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-2Klr13/Wjfd5OnMDajug1UBdR3s=", "dev": true, "optional": true }, "console-control-strings": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-PXz0Rk22RG6mRL9LOVB/mFEAjo4=", "dev": true, "optional": true }, @@ -5667,7 +5672,8 @@ }, "inherits": { "version": "2.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha1-Yzwsg+PaQqUC9SRmAiSA9CCCYd4=", "dev": true, "optional": true }, @@ -5707,7 +5713,8 @@ }, "minimist": { "version": "0.0.8", - "bundled": true, + "resolved": false, + "integrity": "sha1-hX/Kv8M5fSYluCKCYuhqp6ARsF0=", "dev": true, "optional": true }, @@ -5824,7 +5831,8 @@ }, "number-is-nan": { "version": "1.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-CXtgK1NCKlIsGvuHkDGDNpQaAR0=", "dev": true, "optional": true }, @@ -5934,7 +5942,8 @@ }, "safe-buffer": { "version": "5.1.2", - "bundled": true, + "resolved": false, + "integrity": "sha512-Gd2UZBJDkXlY7GbJxfsE8/nvKkUEU1G38c1siN6QP6a9PT9MmHB8GnpscSmMJSoF8LOIrt8ud/wPtojys4G6+g==", "dev": true, "optional": true }, @@ -6047,13 +6056,15 @@ }, "wrappy": { "version": "1.0.2", - "bundled": true, + "resolved": false, + "integrity": "sha1-tSQ9jz7BqjXxNkYFvA0QNuMKtp8=", "dev": true, "optional": true }, "yallist": { "version": "3.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha512-S+Zk8DEWE6oKpV+vI3qWkaK+jSbIK86pCwe2IF/xwIpQ8jEuxpw9NyaGjmp9+BoJv5FV2piqCDcoCtStppiq2A==", "dev": true, "optional": true } @@ -7708,7 +7719,8 @@ }, "ansi-regex": { "version": "2.1.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-w7M6te42DYbg5ijwRorn7yfWVN8=", "optional": true }, "aproba": { @@ -7729,12 +7741,14 @@ }, "balanced-match": { "version": "1.0.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-ibTRmasr7kneFk6gK4nORi1xt2c=", "optional": true }, "brace-expansion": { "version": "1.1.11", - "bundled": true, + "resolved": false, + "integrity": "sha512-iCuPHDFgrHX7H2vEI/5xpz07zSHB00TpugqhmYtVmMO6518mCuRMoOYFldEBl0g187ufozdaHgWKcYFb61qGiA==", "optional": true, "requires": { "balanced-match": "^1.0.0", @@ -7749,17 +7763,20 @@ }, "code-point-at": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-DQcLTQQ6W+ozovGkDi7bPZpMz3c=", "optional": true }, "concat-map": { "version": "0.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-2Klr13/Wjfd5OnMDajug1UBdR3s=", "optional": true }, "console-control-strings": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-PXz0Rk22RG6mRL9LOVB/mFEAjo4=", "optional": true }, "core-util-is": { @@ -7876,7 +7893,8 @@ }, "inherits": { "version": "2.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha1-Yzwsg+PaQqUC9SRmAiSA9CCCYd4=", "optional": true }, "ini": { @@ -7887,7 +7905,8 @@ }, "is-fullwidth-code-point": { "version": "1.0.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-754xOG8DGn8NZDr4L95QxFfvAMs=", "optional": true, "requires": { "number-is-nan": "^1.0.0" @@ -7901,7 +7920,8 @@ }, "minimatch": { "version": "3.0.4", - "bundled": true, + "resolved": false, + "integrity": "sha512-yJHVQEhyqPLUTgt9B83PXu6W3rx4MvvHvSUvToogpwoGDOUQ+yDrR0HRot+yOCdCO7u4hX3pWft6kWBBcqh0UA==", "optional": true, "requires": { "brace-expansion": "^1.1.7" @@ -7909,12 +7929,14 @@ }, "minimist": { "version": "0.0.8", - "bundled": true, + "resolved": false, + "integrity": "sha1-hX/Kv8M5fSYluCKCYuhqp6ARsF0=", "optional": true }, "minipass": { "version": "2.3.5", - "bundled": true, + "resolved": false, + "integrity": "sha512-Gi1W4k059gyRbyVUZQ4mEqLm0YIUiGYfvxhF6SIlk3ui1WVxMTGfGdQ2SInh3PDrRTVvPKgULkpJtT4RH10+VA==", "optional": true, "requires": { "safe-buffer": "^5.1.2", @@ -7932,7 +7954,8 @@ }, "mkdirp": { "version": "0.5.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-MAV0OOrGz3+MR2fzhkjWaX11yQM=", "optional": true, "requires": { "minimist": "0.0.8" @@ -8013,7 +8036,8 @@ }, "number-is-nan": { "version": "1.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-CXtgK1NCKlIsGvuHkDGDNpQaAR0=", "optional": true }, "object-assign": { @@ -8024,7 +8048,8 @@ }, "once": { "version": "1.4.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-WDsap3WWHUsROsF9nFC6753Xa9E=", "optional": true, "requires": { "wrappy": "1" @@ -8110,7 +8135,8 @@ }, "safe-buffer": { "version": "5.1.2", - "bundled": true, + "resolved": false, + "integrity": "sha512-Gd2UZBJDkXlY7GbJxfsE8/nvKkUEU1G38c1siN6QP6a9PT9MmHB8GnpscSmMJSoF8LOIrt8ud/wPtojys4G6+g==", "optional": true }, "safer-buffer": { @@ -8145,7 +8171,8 @@ }, "string-width": { "version": "1.0.2", - "bundled": true, + "resolved": false, + "integrity": "sha1-EYvfW4zcUaKn5w0hHgfisLmxB9M=", "optional": true, "requires": { "code-point-at": "^1.0.0", @@ -8164,7 +8191,8 @@ }, "strip-ansi": { "version": "3.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-ajhfuIU9lS1f8F0Oiq+UJ43GPc8=", "optional": true, "requires": { "ansi-regex": "^2.0.0" @@ -8208,12 +8236,14 @@ }, "wrappy": { "version": "1.0.2", - "bundled": true, + "resolved": false, + "integrity": "sha1-tSQ9jz7BqjXxNkYFvA0QNuMKtp8=", "optional": true }, "yallist": { "version": "3.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha512-S+Zk8DEWE6oKpV+vI3qWkaK+jSbIK86pCwe2IF/xwIpQ8jEuxpw9NyaGjmp9+BoJv5FV2piqCDcoCtStppiq2A==", "optional": true } } @@ -12287,6 +12317,21 @@ "url-value-parser": "^1.0.0" } }, + "express-request-id": { + "version": "1.4.1", + "resolved": "https://registry.npmjs.org/express-request-id/-/express-request-id-1.4.1.tgz", + "integrity": "sha512-qpxK6XhDYtdx9FvxwCHkUeZVWtkGbWR87hBAzGECfwYF/QQCPXEwwB2/9NGkOR1tT7/aLs9mma3CT0vjSzuZVw==", + "requires": { + "uuid": "^3.3.2" + }, + "dependencies": { + "uuid": { + "version": "3.3.2", + "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.3.2.tgz", + "integrity": "sha512-yXJmeNaw3DnnKAOKJE51sL/ZaYfWJRl1pK9dr19YFCu0ObS231AB1/LbqTKRAQ5kw8A90rA6fr4riOUpTZvQZA==" + } + } + }, "express-session": { "version": "1.15.6", "resolved": "https://registry.npmjs.org/express-session/-/express-session-1.15.6.tgz", @@ -16137,7 +16182,8 @@ }, "ansi-regex": { "version": "2.1.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-w7M6te42DYbg5ijwRorn7yfWVN8=", "dev": true, "optional": true }, @@ -16161,7 +16207,8 @@ }, "balanced-match": { "version": "1.0.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-ibTRmasr7kneFk6gK4nORi1xt2c=", "dev": true, "optional": true }, @@ -16185,19 +16232,22 @@ }, "code-point-at": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-DQcLTQQ6W+ozovGkDi7bPZpMz3c=", "dev": true, "optional": true }, "concat-map": { "version": "0.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-2Klr13/Wjfd5OnMDajug1UBdR3s=", "dev": true, "optional": true }, "console-control-strings": { "version": "1.1.0", - "bundled": true, + "resolved": false, + "integrity": "sha1-PXz0Rk22RG6mRL9LOVB/mFEAjo4=", "dev": true, "optional": true }, @@ -16328,7 +16378,8 @@ }, "inherits": { "version": "2.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha1-Yzwsg+PaQqUC9SRmAiSA9CCCYd4=", "dev": true, "optional": true }, @@ -16368,7 +16419,8 @@ }, "minimist": { "version": "0.0.8", - "bundled": true, + "resolved": false, + "integrity": "sha1-hX/Kv8M5fSYluCKCYuhqp6ARsF0=", "dev": true, "optional": true }, @@ -16485,7 +16537,8 @@ }, "number-is-nan": { "version": "1.0.1", - "bundled": true, + "resolved": false, + "integrity": "sha1-CXtgK1NCKlIsGvuHkDGDNpQaAR0=", "dev": true, "optional": true }, @@ -16595,7 +16648,8 @@ }, "safe-buffer": { "version": "5.1.2", - "bundled": true, + "resolved": false, + "integrity": "sha512-Gd2UZBJDkXlY7GbJxfsE8/nvKkUEU1G38c1siN6QP6a9PT9MmHB8GnpscSmMJSoF8LOIrt8ud/wPtojys4G6+g==", "dev": true, "optional": true }, @@ -16708,13 +16762,15 @@ }, "wrappy": { "version": "1.0.2", - "bundled": true, + "resolved": false, + "integrity": "sha1-tSQ9jz7BqjXxNkYFvA0QNuMKtp8=", "dev": true, "optional": true }, "yallist": { "version": "3.0.3", - "bundled": true, + "resolved": false, + "integrity": "sha512-S+Zk8DEWE6oKpV+vI3qWkaK+jSbIK86pCwe2IF/xwIpQ8jEuxpw9NyaGjmp9+BoJv5FV2piqCDcoCtStppiq2A==", "dev": true, "optional": true } @@ -19626,9 +19682,9 @@ } }, "memoize-one": { - "version": "5.0.4", - "resolved": "https://registry.npmjs.org/memoize-one/-/memoize-one-5.0.4.tgz", - "integrity": "sha512-P0z5IeAH6qHHGkJIXWw0xC2HNEgkx/9uWWBQw64FJj3/ol14VYdfVGWWr0fXfjhhv3TKVIqUq65os6O4GUNksA==" + "version": "5.0.5", + "resolved": "https://registry.npmjs.org/memoize-one/-/memoize-one-5.0.5.tgz", + "integrity": "sha512-ey6EpYv0tEaIbM/nTDOpHciXUvd+ackQrJgEzBwemhZZIWZjcyodqEcrmqDy2BKRTM3a65kKBV4WtLXJDt26SQ==" }, "memorystream": { "version": "0.3.1", @@ -20132,9 +20188,9 @@ "integrity": "sha512-bV7f+6l2QigeBBZSM/6yTNq4P2fNpSWj/0e7jQcy87A8e7o2nAfP/34/2ky5Vw4B9S446EtIhodAzkFCcR4dQg==" }, "moment-timezone": { - "version": "0.5.25", - "resolved": "https://registry.npmjs.org/moment-timezone/-/moment-timezone-0.5.25.tgz", - "integrity": "sha512-DgEaTyN/z0HFaVcVbSyVCUU6HeFdnNC3vE4c9cgu2dgMTvjBUBdBzWfasTBmAW45u5OIMeCJtU8yNjM22DHucw==", + "version": "0.5.26", + "resolved": "https://registry.npmjs.org/moment-timezone/-/moment-timezone-0.5.26.tgz", + "integrity": "sha512-sFP4cgEKTCymBBKgoxZjYzlSovC20Y6J7y3nanDc5RoBIXKlZhoYwBoZGe3flwU6A372AcRwScH8KiwV6zjy1g==", "requires": { "moment": ">= 2.9.0" } diff --git a/packages/@uppy/companion/package.json b/packages/@uppy/companion/package.json index 7c82edace..8e941ff22 100644 --- a/packages/@uppy/companion/package.json +++ b/packages/@uppy/companion/package.json @@ -41,6 +41,7 @@ "express": "4.17.1", "express-interceptor": "1.2.0", "express-prom-bundle": "3.3.0", + "express-request-id": "1.4.1", "express-session": "1.15.6", "grant-express": "4.1.2", "helmet": "3.8.2", diff --git a/packages/@uppy/companion/src/server/Uploader.js b/packages/@uppy/companion/src/server/Uploader.js index d03ee3f03..b4fd07b64 100644 --- a/packages/@uppy/companion/src/server/Uploader.js +++ b/packages/@uppy/companion/src/server/Uploader.js @@ -57,7 +57,7 @@ class Uploader { // .on('error', (err) => logger.error(`${this.shortToken} ${err}`, 'uploader.duplex.error')) // } this.writeStream = fs.createWriteStream(this.path, { mode: 0o666 }) // no executable files - .on('error', (err) => logger.error(`${this.shortToken} ${err}`, 'uploader.write.error')) + .on('error', (err) => logger.error(`${err}`, 'uploader.write.error', this.shortToken)) /** @type {number} */ this.emittedProgress = 0 this.storage = options.storage @@ -80,6 +80,17 @@ class Uploader { } } + /** + * returns a substring of the token. Used as traceId for logging + * we avoid using the entire token because this is meant to be a short term + * access token between uppy client and companion websocket + * @param {string} token the token to Shorten + * @returns {string} + */ + static shortenToken (token) { + return token.substring(0, 8) + } + /** * the number of bytes written into the streams */ @@ -128,10 +139,12 @@ class Uploader { } /** - * returns a substring of the token + * returns a substring of the token. Used as traceId for logging + * we avoid using the entire token because this is meant to be a short term + * access token between uppy client and companion websocket */ get shortToken () { - return this.token.substring(0, 8) + return Uploader.shortenToken(this.token) } /** @@ -140,7 +153,7 @@ class Uploader { */ onSocketReady (callback) { emitter().once(`connection:${this.token}`, () => callback()) - logger.debug(`${this.shortToken} waiting for connection`, 'uploader.socket.wait') + logger.debug(`waiting for connection`, 'uploader.socket.wait', this.shortToken) } cleanUp () { @@ -178,7 +191,7 @@ class Uploader { } this.writeStream.write(chunk, () => { - logger.debug(`${this.shortToken} ${this.bytesWritten} bytes`, 'uploader.download.progress') + logger.debug(`${this.bytesWritten} bytes`, 'uploader.download.progress', this.shortToken) if (protocol === PROTOCOLS.multipart || protocol === PROTOCOLS.tus) { return this.emitIllusiveProgress() } @@ -259,8 +272,9 @@ class Uploader { const illusiveBytesUploaded = (this.bytesWritten / 2) + (bytesUploaded / 2) logger.debug( - `${this.shortToken} ${bytesUploaded} ${illusiveBytesUploaded} ${bytesTotal}`, - 'uploader.illusive.progress' + `${bytesUploaded} ${illusiveBytesUploaded} ${bytesTotal}`, + 'uploader.illusive.progress', + this.shortToken ) this.emitProgress(illusiveBytesUploaded, bytesTotal) } @@ -278,8 +292,9 @@ class Uploader { const percentage = (bytesUploaded / bytesTotal * 100) const formatPercentage = percentage.toFixed(2) logger.debug( - `${this.shortToken} ${bytesUploaded} ${bytesTotal} ${formatPercentage}%`, - 'uploader.upload.progress' + `${bytesUploaded} ${bytesTotal} ${formatPercentage}%`, + 'uploader.upload.progress', + this.shortToken ) const dataToEmit = { diff --git a/packages/@uppy/companion/src/server/controllers/callback.js b/packages/@uppy/companion/src/server/controllers/callback.js index 77669c58f..c33666ab0 100644 --- a/packages/@uppy/companion/src/server/controllers/callback.js +++ b/packages/@uppy/companion/src/server/controllers/callback.js @@ -18,7 +18,7 @@ module.exports = function callback (req, res, next) { } req.uppy.providerTokens[providerName] = req.session.grant.response.access_token - logger.debug(`Generating auth token for provider ${providerName}.`) + logger.debug(`Generating auth token for provider ${providerName}.`, null, req.id) const uppyAuthToken = tokenService.generateToken(req.uppy.providerTokens, req.uppy.options.secret) return res.redirect(req.uppy.buildURL(`/${providerName}/send-token?uppyAuthToken=${uppyAuthToken}`, true)) } diff --git a/packages/@uppy/companion/src/server/controllers/get.js b/packages/@uppy/companion/src/server/controllers/get.js index f7bae3906..f26be9121 100644 --- a/packages/@uppy/companion/src/server/controllers/get.js +++ b/packages/@uppy/companion/src/server/controllers/get.js @@ -17,11 +17,11 @@ function get (req, res, next) { } if (!size) { - logger.error('unable to determine file size', 'controller.get.provider.size') + logger.error('unable to determine file size', 'controller.get.provider.size', req.id) return res.status(400).json({ error: 'unable to determine file size' }) } - logger.debug('Instantiating uploader.') + logger.debug('Instantiating uploader.', null, req.id) const uploader = new Uploader({ uppyOptions: req.uppy.options, endpoint: body.endpoint, @@ -47,10 +47,10 @@ function get (req, res, next) { // wait till the client has connected to the socket, before starting // the download, so that the client can receive all download/upload progress. - logger.debug('Waiting for socket connection before beginning remote download.') + logger.debug('Waiting for socket connection before beginning remote download.', null, req.id) // waiting for socketReady. uploader.onSocketReady(() => { - logger.debug('Socket connection received. Starting remote download.') + logger.debug('Socket connection received. Starting remote download.', null, req.id) provider.download({ id, token, query: req.query }, uploader.handleChunk.bind(uploader)) }) const response = uploader.getResponse() diff --git a/packages/@uppy/companion/src/server/controllers/url.js b/packages/@uppy/companion/src/server/controllers/url.js index db3922f87..6a74af305 100644 --- a/packages/@uppy/companion/src/server/controllers/url.js +++ b/packages/@uppy/companion/src/server/controllers/url.js @@ -19,17 +19,17 @@ module.exports = () => { * @param {object} res expressJS response object */ const meta = (req, res) => { - logger.debug('URL file import handler running') + logger.debug('URL file import handler running', null, req.id) if (!validator.isURL(req.body.url, { require_protocol: true, require_tld: !req.uppy.options.debug })) { - logger.debug('Invalid request body detected. Exiting url meta handler.') + logger.debug('Invalid request body detected. Exiting url meta handler.', null, req.id) return res.status(400).json({ error: 'Invalid request body' }) } utils.getURLMeta(req.body.url) .then((meta) => res.json(meta)) .catch((err) => { - logger.error(err, 'controller.url.meta.error') + logger.error(err, 'controller.url.meta.error', req.id) return res.status(500).json({ error: err }) }) } @@ -42,13 +42,13 @@ const meta = (req, res) => { * @param {object} res expressJS response object */ const get = (req, res) => { - logger.debug('URL file import handler running') + logger.debug('URL file import handler running', null, req.id) utils.getURLMeta(req.body.url) .then(({ size }) => { // @ts-ignore const { filePath } = req.uppy.options - logger.debug('Instantiating uploader.') + logger.debug('Instantiating uploader.', null, req.id) const uploader = new Uploader({ uppyOptions: req.uppy.options, endpoint: req.body.endpoint, @@ -68,16 +68,16 @@ const get = (req, res) => { return } - logger.debug('Waiting for socket connection before beginning remote download.') + logger.debug('Waiting for socket connection before beginning remote download.', null, req.id) uploader.onSocketReady(() => { - logger.debug('Socket connection received. Starting remote download.') - downloadURL(req.body.url, uploader.handleChunk.bind(uploader)) + logger.debug('Socket connection received. Starting remote download.', null, req.id) + downloadURL(req.body.url, uploader.handleChunk.bind(uploader), req.id) }) const response = uploader.getResponse() res.status(response.status).json(response.body) }).catch((err) => { - logger.error(err, 'controller.url.get.error') + logger.error(err, 'controller.url.get.error', req.id) res.json({ err }) }) } @@ -88,8 +88,9 @@ const get = (req, res) => { * * @param {string} url * @param {typeof Function} onDataChunk + * @param {string=} traceId */ -const downloadURL = (url, onDataChunk) => { +const downloadURL = (url, onDataChunk, traceId) => { const opts = { uri: url, method: 'GET', @@ -99,5 +100,5 @@ const downloadURL = (url, onDataChunk) => { request(opts) .on('data', onDataChunk) .on('end', () => onDataChunk(null)) - .on('error', (err) => logger.error(err, 'controller.url.download.error')) + .on('error', (err) => logger.error(err, 'controller.url.download.error', traceId)) } diff --git a/packages/@uppy/companion/src/server/logger.js b/packages/@uppy/companion/src/server/logger.js index f2bb4c12c..05c217e5c 100644 --- a/packages/@uppy/companion/src/server/logger.js +++ b/packages/@uppy/companion/src/server/logger.js @@ -4,39 +4,43 @@ const chalk = require('chalk') * INFO level log * @param {string} msg the message to log * @param {string=} tag a unique tag to easily search for this message + * @param {string=} traceId a unique id to easily trace logs tied to a request */ -exports.info = (msg, tag) => { - log(msg, tag, 'info') +exports.info = (msg, tag, traceId) => { + log(msg, tag, 'info', traceId) } /** * WARN level log * @param {string} msg the message to log * @param {string=} tag a unique tag to easily search for this message + * @param {string=} traceId a unique id to easily trace logs tied to a request */ -exports.warn = (msg, tag) => { +exports.warn = (msg, tag, traceId) => { // @ts-ignore - log(msg, tag, 'warn', chalk.bold.yellow) + log(msg, tag, 'warn', traceId, chalk.bold.yellow) } /** * ERROR level log * @param {string | Error} msg the message to log * @param {string=} tag a unique tag to easily search for this message + * @param {string=} traceId a unique id to easily trace logs tied to a request */ -exports.error = (msg, tag) => { +exports.error = (msg, tag, traceId) => { // @ts-ignore - log(msg, tag, 'error', chalk.bold.red) + log(msg, tag, 'error', traceId, chalk.bold.red) } /** * DEBUG level log * @param {string} msg the message to log * @param {string=} tag a unique tag to easily search for this message + * @param {string=} traceId a unique id to easily trace logs tied to a request */ -exports.debug = (msg, tag) => { +exports.debug = (msg, tag, traceId) => { if (process.env.NODE_ENV !== 'production') { - log(msg, tag, 'debug') + log(msg, tag, 'debug', traceId) } } @@ -46,11 +50,15 @@ exports.debug = (msg, tag) => { * @param {string} tag a unique tag to easily search for this message * @param {string} level error | info | debug * @param {function=} color function to display the log in appropriate color + * @param {string=} id a unique id to easily trace logs tied to a request */ -const log = (msg, tag, level, color) => { +const log = (msg, tag, level, id, color) => { const time = new Date().toISOString() + tag = tag || '' + id = id || '' + const whitespace = tag && id ? ' ' : '' color = color || ((message) => message) // exclude msg from template string so values such as error objects // can be well formatted - console.log(color(`companion: ${time} [${level}] ${tag || ''}`), color(msg)) + console.log(color(`companion: ${time} [${level}] ${id}${whitespace}${tag}`), color(msg)) } diff --git a/packages/@uppy/companion/src/server/middlewares.js b/packages/@uppy/companion/src/server/middlewares.js index a98fda04d..dfa8c2057 100644 --- a/packages/@uppy/companion/src/server/middlewares.js +++ b/packages/@uppy/companion/src/server/middlewares.js @@ -3,12 +3,12 @@ const logger = require('./logger') exports.hasSessionAndProvider = (req, res, next) => { if (!req.session || !req.body) { - logger.debug('No session/body attached to req object. Exiting dispatcher.') + logger.debug('No session/body attached to req object. Exiting dispatcher.', null, req.id) return res.sendStatus(400) } if (!req.uppy.provider) { - logger.debug('No provider/provider-handler found. Exiting dispatcher.') + logger.debug('No provider/provider-handler found. Exiting dispatcher.', null, req.id) return res.sendStatus(400) } diff --git a/packages/@uppy/companion/src/server/provider/index.js b/packages/@uppy/companion/src/server/provider/index.js index c5b2b696b..91996c478 100644 --- a/packages/@uppy/companion/src/server/provider/index.js +++ b/packages/@uppy/companion/src/server/provider/index.js @@ -78,7 +78,7 @@ module.exports.getProviderMiddleware = (providers) => { if (providers[providerName] && validOptions(req.uppy.options)) { req.uppy.provider = new providers[providerName]({ providerName, config }) } else { - logger.warn('invalid provider options detected. Provider will not be loaded', 'provider.middleware.invalid') + logger.warn('invalid provider options detected. Provider will not be loaded', 'provider.middleware.invalid', req.id) } next() } diff --git a/packages/@uppy/companion/src/standalone/index.js b/packages/@uppy/companion/src/standalone/index.js index 746a2196d..2deed03c3 100644 --- a/packages/@uppy/companion/src/standalone/index.js +++ b/packages/@uppy/companion/src/standalone/index.js @@ -7,6 +7,7 @@ const bodyParser = require('body-parser') // @ts-ignore const promBundle = require('express-prom-bundle') const session = require('express-session') +const addRequestId = require('express-request-id')() const helper = require('./helper') // @ts-ignore const { version } = require('../../package.json') @@ -29,6 +30,7 @@ if (app.get('env') !== 'test') { clearInterval(promInterval) } +app.use(addRequestId) // log server requests. app.use(morgan('combined')) morgan.token('url', (req, res) => { diff --git a/packages/@uppy/companion/src/uppy.js b/packages/@uppy/companion/src/uppy.js index 5a0003263..cea4352a1 100644 --- a/packages/@uppy/companion/src/uppy.js +++ b/packages/@uppy/companion/src/uppy.js @@ -17,6 +17,7 @@ const interceptor = require('express-interceptor') const logger = require('./server/logger') const { STORAGE_PREFIX } = require('./server/Uploader') const middlewares = require('./server/middlewares') +const { shortenToken } = require('./server/Uploader') const providers = providerManager.getDefaultProviders() const defaultOptions = { @@ -141,7 +142,7 @@ module.exports.socket = (server) => { */ function sendProgress (data) { ws.send(jsonStringify(data), (err) => { - if (err) logger.error(err, 'socket.progress.error') + if (err) logger.error(err, 'socket.progress.error', shortenToken(token)) }) } @@ -149,7 +150,7 @@ module.exports.socket = (server) => { // if we have any already stored progress data on the upload. if (redisClient) { redisClient.get(`${STORAGE_PREFIX}:${token}`, (err, data) => { - if (err) logger.error(err, 'socket.redis.error') + if (err) logger.error(err, 'socket.redis.error', shortenToken(token)) if (data) { const dataObj = JSON.parse(data.toString()) if (dataObj.action) sendProgress(dataObj) @@ -185,11 +186,13 @@ const interceptGrantErrorResponse = interceptor((req, res) => { intercept: (body, send) => { const unwantedBody = 'error=Grant%3A%20missing%20session%20or%20misconfigured%20provider' if (body === unwantedBody) { - logger.error(`grant.js responded with error: ${body}`, 'grant.oauth.error') + logger.error(`grant.js responded with error: ${body}`, 'grant.oauth.error', req.id) res.set('Content-Type', 'text/plain') + const reqHint = req.id ? `Request ID: ${req.id}` : '' send([ 'Companion was unable to complete the OAuth process :(', - 'Error: User session is missing or the Provider was misconfigured' + 'Error: User session is missing or the Provider was misconfigured', + reqHint ].join('\n')) } else { send(body)