companion: add traceID to follow logs through

This commit is contained in:
Ifedapo Olarewaju 2019-06-30 10:02:17 +01:00
parent 49e57c2e7d
commit cf18689c10
11 changed files with 181 additions and 95 deletions

162
package-lock.json generated
View file

@ -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"
}

View file

@ -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",

View file

@ -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 = {

View file

@ -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))
}

View file

@ -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()

View file

@ -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))
}

View file

@ -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))
}

View file

@ -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)
}

View file

@ -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()
}

View file

@ -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) => {

View file

@ -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)