Add distributed tracing (#1342)

* Add X-Request-ID libs header

* Use X-Request-ID in identity

* Use X-Request-ID in content node

* Add additional log

creator-node/src/logging.js

@@ -47,7 +47,8 @@ function getRequestLoggingContext (req, requestID) {
 }
 
 function loggingMiddleware (req, res, next) {
-  const requestID = shortid.generate()
+  const providedRequestID = req.header('X-Request-ID')
+  const requestID = providedRequestID || shortid.generate()
   res.set('CN-Request-ID', requestID)
 
   req.logContext = getRequestLoggingContext(req, requestID)

identity-service/src/logging.js

@@ -21,7 +21,9 @@ function requestNotExcludedFromLogging (url) {
 }
 
 function loggingMiddleware (req, res, next) {
-  const requestID = shortid.generate()
+  const providedRequestID = req.header('X-Request-ID')
+  const requestID = providedRequestID || shortid.generate()
+
   const urlParts = req.url.split('?')
   req.startTime = process.hrtime()
   req.logger = logger.child({

libs/src/services/creatorNode/index.js

@@ -1,5 +1,6 @@
 const axios = require('axios')
 const FormData = require('form-data')
+const uuid = require('../../utils/uuid')
 
 const SchemaValidator = require('../schemaValidator')
 
@@ -567,6 +568,9 @@ class CreatorNode {
       axiosRequestObj.headers['User-Id'] = user.user_id
     }
 
+    const requestId = uuid()
+    axiosRequestObj.headers['X-Request-ID'] = requestId
+
     axiosRequestObj.baseURL = this.creatorNodeEndpoint
 
     // Axios throws for non-200 responses
@@ -615,7 +619,7 @@ class CreatorNode {
         }
       }
 
-      _handleErrorHelper(e, axiosRequestObj.url)
+      _handleErrorHelper(e, axiosRequestObj.url, requestId)
     }
   }
 
@@ -642,6 +646,9 @@ class CreatorNode {
     }
     headers['X-Session-ID'] = this.authToken
 
+    const requestId = uuid()
+    headers['X-Request-ID'] = requestId
+
     let total
     const url = this.creatorNodeEndpoint + route
     try {
@@ -666,6 +673,7 @@ class CreatorNode {
           // Add a 10% inherit processing time for the file upload.
           onUploadProgress: (progressEvent) => {
             if (!total) total = progressEvent.total
+            console.info(`Upload in progress: ${progressEvent.loaded} / ${total}`)
             onProgress(progressEvent.loaded, total)
           }
         }
@@ -676,26 +684,29 @@ class CreatorNode {
       onProgress(total, total)
       return resp.data
     } catch (e) {
-      _handleErrorHelper(e, url)
+      _handleErrorHelper(e, url, requestId)
     }
   }
 }
 
-function _handleErrorHelper (e, requestUrl) {
+function _handleErrorHelper (e, requestUrl, requestId = null) {
   if (e.response && e.response.data && e.response.data.error) {
     const cnRequestID = e.response.headers['cn-request-id']
-    const errMessage = `Server returned error: [${e.response.status.toString()}] [${e.response.data.error}] for request: [${cnRequestID}]`
+    // cnRequestID will be the same as requestId if it receives the X-Request-ID header
+    const errMessage = `Server returned error: [${e.response.status.toString()}] [${e.response.data.error}] for request: [${cnRequestID}, ${requestId}]`
 
     console.error(errMessage)
     throw new Error(errMessage)
   } else if (!e.response) {
     // delete headers, may contain tokens
     if (e.config && e.config.headers) delete e.config.headers
 
-    const errorMsg = `Network error while making request to ${requestUrl}:\nStringified Error:${JSON.stringify(e)}\n`
+    const errorMsg = `Network error while making request ${requestId} to ${requestUrl}:\nStringified Error:${JSON.stringify(e)}\n`
     console.error(errorMsg, e)
     throw new Error(`${errorMsg}${e}`)
   } else {
+    const errorMsg = `Unknown error while making request ${requestId} to ${requestUrl}:\nStringified Error:${JSON.stringify(e)}\n`
+    console.error(errorMsg, e)
     throw e
   }
 }

libs/src/services/identity/index.js

@@ -1,4 +1,5 @@
 const axios = require('axios')
+const uuid = require('../../utils/uuid')
 
 const Requests = require('./requests')
 
@@ -286,14 +287,20 @@ class IdentityService {
   async _makeRequest (axiosRequestObj) {
     axiosRequestObj.baseURL = this.identityServiceEndpoint
 
+    const requestId = uuid()
+    axiosRequestObj.headers = {
+      ...(axiosRequestObj.headers || {}),
+      'X-Request-ID': requestId
+    }
+
     // Axios throws for non-200 responses
     try {
       const resp = await axios(axiosRequestObj)
       return resp.data
     } catch (e) {
       if (e.response && e.response.data && e.response.data.error) {
         console.error(
-          `Server returned error: [${e.response.status.toString()}] ${e.response.data.error}`
+          `Server returned error for requestId ${requestId}: [${e.response.status.toString()}] ${e.response.data.error}`
         )
       }
       throw e

libs/src/utils/uuid.js

@@ -0,0 +1,16 @@
+const uuid = () => {
+  // https://stackoverflow.com/questions/105034/create-guid-uuid-in-javascript/873856#873856
+  const s = []
+  const hexDigits = '0123456789abcdef'
+  for (let i = 0; i < 36; i++) {
+    s[i] = hexDigits.substr(Math.floor(Math.random() * 0x10), 1)
+  }
+  s[14] = '4' // bits 12-15 of the time_hi_and_version field to 0010
+  s[19] = hexDigits.substr((s[19] & 0x3) | 0x8, 1) // bits 6-7 of the clock_seq_hi_and_reserved to 01
+  s[8] = s[13] = s[18] = s[23] = '-'
+
+  const uuid = s.join('')
+  return uuid
+}
+
+module.exports = uuid