Add request ID in log

.ci/scripts/run-test-arm.sh

@@ -2,7 +2,11 @@
 
 set -ex
 
-NODE_VERSION=$NODE_12_VERSION
+if [ -z "$NODE_VERSION" ];
+then
+  echo "Missing NODE_VERSION, use default NODE_12_VERSION"
+  NODE_VERSION=$NODE_12_VERSION
+fi
 
 echo "Testing Kuzzle against node v$NODE_VERSION"
 

.ci/scripts/run-test.sh

@@ -2,7 +2,11 @@
 
 set -ex
 
-NODE_VERSION=$NODE_12_VERSION
+if [ -z "$NODE_VERSION" ];
+then
+  echo "Missing NODE_VERSION, use default NODE_12_VERSION"
+  NODE_VERSION=$NODE_12_VERSION
+fi
 
 echo "Testing Kuzzle against node v$NODE_VERSION"
 n $NODE_VERSION

.travis.yml

@@ -61,15 +61,27 @@ jobs:
     # Unit Tests & Linters
     # ---------------------------------------
     - stage: Unit Tests & Linters
-      name: Unit Tests & ESLint
+      name: Node 12.16.3 - Unit Tests & ESLint
       os: linux
       sudo: required
       language: node_js
-
       cache: npm
+      node_js: 12.16.3
+      install:
+        - npm ci --silent
+      script:
+        - npm run --silent test:lint
+        - npm run test:unit:coverage
+      after_script:
+        - npm run codecov
 
-      node_js: 12
-
+    - stage: Unit Tests & Linters
+      name: Node 12.18.1 - Unit Tests & ESLint
+      os: linux
+      sudo: required
+      language: node_js
+      cache: npm
+      node_js: 12.18.1
       install:
         - npm ci --silent
       script:
@@ -116,13 +128,29 @@ jobs:
     # ---------------------------------------
     # Integration tests
     # ---------------------------------------
+    - <<: *integration-tests
+      stage: Integration tests
+      name: Node.js 12.16.3 - Functional tests legacy
+      env:
+        - KUZZLE_FUNCTIONAL_TESTS=test:functional:legacy
+        - NODE_VERSION=12.16.3
+        - *integration-tests-env
+
     - <<: *integration-tests
       stage: Integration tests
       name: Node.js 12 - Functional tests legacy
       env:
         - KUZZLE_FUNCTIONAL_TESTS=test:functional:legacy
         - *integration-tests-env
 
+    - <<: *integration-tests
+      stage: Integration tests
+      name: Node.js 12.16.3 - Functional tests sdk
+      env:
+        - KUZZLE_FUNCTIONAL_TESTS=test:functional:sdk
+        - NODE_VERSION=12.16.3
+        - *integration-tests-env
+
     - <<: *integration-tests
       stage: Integration tests
       name: Node.js 12 - Functional tests sdk

lib/api/funnel.js

@@ -21,9 +21,11 @@
 
 'use strict';
 
-const debug = require('../util/debug')('kuzzle:funnel');
 const Bluebird = require('bluebird');
 const Deque = require('denque');
+const { errors: { KuzzleError } } = require('kuzzle-common-objects');
+
+const AdminController = require('./controller/admin');
 const AuthController = require('./controller/auth');
 const BulkController = require('./controller/bulk');
 const CollectionController = require('./controller/collection');
@@ -33,14 +35,13 @@ const MemoryStorageController = require('./controller/memoryStorage');
 const RealtimeController = require('./controller/realtime');
 const SecurityController = require('./controller/security');
 const ServerController = require('./controller/server');
-const AdminController = require('./controller/admin');
-const kerror = require('../kerror');
-const { errors: { KuzzleError } } = require('kuzzle-common-objects');
 const documentEventAliases = require('../config/documentEventAliases');
 const DocumentExtractor = require('./documentExtractor');
 const sdkCompatibility = require('../config/sdkCompatibility');
 const RateLimiter = require('./rateLimiter');
+const kerror = require('../kerror');
 
+const debug = require('../util/debug')('kuzzle:funnel');
 const processError = kerror.wrap('api', 'process');
 
 /**
@@ -265,33 +266,37 @@ class Funnel {
 
     let _request;
 
-    this.checkRights(request)
-      .then(modifiedRequest => {
-        _request = modifiedRequest;
-        return this.rateLimiter.isAllowed(_request);
-      })
-      .then(allowed => {
-        if (!allowed) {
-          throw processError.get('too_many_requests');
-        }
+    this.kuzzle.asyncStore.run(() => {
+      this.kuzzle.asyncStore.set('REQUEST', request);
+
+      this.checkRights(request)
+        .then(modifiedRequest => {
+          _request = modifiedRequest;
+          return this.rateLimiter.isAllowed(_request);
+        })
+        .then(allowed => {
+          if (!allowed) {
+            throw processError.get('too_many_requests');
+          }
 
-        return this.processRequest(_request);
-      })
-      .then(processResult => {
-        debug('Request %s successfully executed. Result: %a',
-          request.id,
-          processResult);
-
-        callback(null, processResult);
-
-        // disables a bluebird warning in dev. mode triggered when
-        // a promise is created and not returned
-        return null;
-      })
-      .catch(err => {
-        debug('Error processing request %s: %a', request.id, err);
-        return this._executeError(err, request, true, callback);
-      });
+          return this.processRequest(_request);
+        })
+        .then(processResult => {
+          debug('Request %s successfully executed. Result: %a',
+            request.id,
+            processResult);
+
+          callback(null, processResult);
+
+          // disables a bluebird warning in dev. mode triggered when
+          // a promise is created and not returned
+          return null;
+        })
+        .catch(err => {
+          debug('Error processing request %s: %a', request.id, err);
+          return this._executeError(err, request, true, callback);
+        });
+    });
 
     return 0;
   }

lib/kuzzle/kuzzle.js

@@ -48,6 +48,7 @@ const signal = require('./signal');
 const vault = require('./vault');
 const shutdown = require('./shutdown');
 const DumpGenerator = require('./dumpGenerator');
+const AsyncStore = require('../util/asyncStore');
 
 /**
  * @class Kuzzle
@@ -112,6 +113,9 @@ class Kuzzle extends KuzzleEventEmitter {
 
     // Vault component (will be initialized after bootstrap)
     this.vault = null;
+
+    // AsyncLocalStorage wrapper
+    this.asyncStore = new AsyncStore();
   }
 
   /**

lib/kuzzle/log.js

@@ -22,13 +22,13 @@
 'use strict';
 
 class Logger {
-  constructor(eventEmitter) {
-    this.eventEmitter = eventEmitter;
+  constructor(kuzzle) {
+    this.kuzzle = kuzzle;
     this.logMethods = ['info', 'warn', 'error', 'silly', 'debug', 'verbose'];
 
     this._useConsole();
 
-    this.eventEmitter.once('kuzzle:start', this._useLogger.bind(this));
+    this.kuzzle.once('core:kuzzleStart', this._useLogger.bind(this));
   }
 
   _useConsole() {
@@ -42,7 +42,16 @@ class Logger {
   _useLogger() {
     // when kuzzle has started, use the event to dispatch logs
     for (const method of this.logMethods) {
-      this[method] = (...args) => this.eventEmitter.emit(`log:${method}`, args);
+      this[method] = message => {
+        if (this.kuzzle.asyncStore.exists() && this.kuzzle.asyncStore.has('REQUEST')) {
+          const request = this.kuzzle.asyncStore.get('REQUEST');
+
+          this.kuzzle.emit(`log:${method}`, `[${request.id}] ${message}`);
+        }
+        else {
+          this.kuzzle.emit(`log:${method}`, message);
+        }
+      };
     }
   }
 }

lib/util/asyncStore.js

@@ -0,0 +1,114 @@
+/*
+ * Kuzzle, a backend software, self-hostable and ready to use
+ * to power modern apps
+ *
+ * Copyright 2015-2020 Kuzzle
+ * mailto: support AT kuzzle.io
+ * website: http://kuzzle.io
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+'use strict';
+
+const assert = require('assert');
+const { AsyncLocalStorage } = require('async_hooks');
+
+class AsyncStore {
+  constructor () {
+    this._asyncLocalStorage = new AsyncLocalStorage();
+  }
+
+  /**
+   * Run the provided method with an async store context
+   *
+   * @param {Function} callback
+   */
+  run (callback) {
+    this._asyncLocalStorage.run(new Map(), callback);
+  }
+
+  /**
+   * Returns true if an async store exists
+   * for the current asynchronous context
+   */
+  exists () {
+    return Boolean(this._asyncLocalStorage.getStore());
+  }
+
+  /**
+   * Sets a value in the current async store
+   *
+   * @param {String} key
+   * @param {any} value
+   */
+  set (key, value) {
+    return this._getStore().set(key, value);
+  }
+
+  /**
+   * Gets a value from the current async store
+   *
+   * @param {String} key
+   *
+   * @returns {any} value
+   */
+  get (key) {
+    return this._getStore().get(key);
+  }
+
+  /**
+   * Checks if a value exists in the current async store
+   *
+   * @param {String} key
+   *
+   * @returns {Boolean}
+   */
+  has (key) {
+    return this._getStore().has(key);
+  }
+
+  _getStore () {
+    const store = this._asyncLocalStorage.getStore();
+
+    assert(Boolean(store), 'Associated AsyncStore is not set');
+
+    return store;
+  }
+}
+
+
+class AsyncStoreStub {
+  constructor () {}
+
+  run (callback) {
+    callback();
+  }
+
+  exists () {
+    return false;
+  }
+
+  set () {}
+
+  get () {}
+
+  has () {}
+}
+
+if (process.version >= 'v12.18.1') {
+  module.exports = AsyncStore;
+}
+else {
+  module.exports = AsyncStoreStub;
+}

test/api/funnel/execute.test.js

@@ -146,6 +146,22 @@ describe('funnelController.execute', () => {
         }
       });
     });
+
+    it('should run the request in asyncStore.run context and set the request in async storage', done => {
+      funnel.execute(request, (err, res) => {
+        try {
+          should(err).be.null();
+          should(res).be.instanceOf(Request);
+          should(kuzzle.asyncStore.run).be.calledOnce();
+          should(kuzzle.asyncStore.set).be.calledWith('REQUEST', request);
+
+          done();
+        }
+        catch (error) {
+          done(error);
+        }
+      });
+    });
   });
 
   describe('#core:overload hook', () => {

test/mocks/kuzzle.mock.js

@@ -309,6 +309,11 @@ class KuzzleMock extends Kuzzle {
 
     this.adminExists = sinon.stub().resolves();
 
+    this.asyncStore = {
+      run: sinon.stub().yields(),
+      set: sinon.stub()
+    };
+
     {
       const mockProto = Object.getPrototypeOf(this);
       const kuzzleProto = Object.getPrototypeOf(mockProto);