From 518aedc89f0ca2366d547005ba3ac0d6cc5b8e43 Mon Sep 17 00:00:00 2001 From: josieusa Date: Fri, 29 Jul 2016 17:49:32 +0200 Subject: [PATCH 1/6] Use cls-hooked instead of continuation-local-storage, as suggested by @raymondfeng in strongloop/loopback-context PR #1 comment #235931961 --- README.md | 2 +- package.json | 4 ++-- server/current-context.js | 2 +- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index 9572750..57b4c65 100644 --- a/README.md +++ b/README.md @@ -1,7 +1,7 @@ # loopback-context Current context for LoopBack applications, based on -node-continuation-local-storage. +cls-hooked. ## Usage diff --git a/package.json b/package.json index c4f28ae..06d0407 100644 --- a/package.json +++ b/package.json @@ -1,7 +1,7 @@ { "name": "loopback-context", "version": "1.0.0", - "description": "Current context for LoopBack applications, based on node-continuation-local-storage", + "description": "Current context for LoopBack applications, based on cls-hooked", "keywords": [ "StrongLoop", "LoopBack", @@ -20,7 +20,7 @@ }, "license": "MIT", "dependencies": { - "continuation-local-storage": "^3.1.7" + "cls-hooked": "^4.0.1" }, "devDependencies": { "chai": "^3.5.0", diff --git a/server/current-context.js b/server/current-context.js index 733a86a..8a4ad09 100644 --- a/server/current-context.js +++ b/server/current-context.js @@ -16,7 +16,7 @@ var domain = require('domain'); // https://github.com/othiym23/async-listener/issues/57 // It all goes away when instrumentation is disabled. var cls = function() { - return require('continuation-local-storage'); + return require('cls-hooked'); }; var LoopBackContext = module.exports; From 7e60a3f649f48e0dbdad51c9e0447f47cd37790a Mon Sep 17 00:00:00 2001 From: josieusa Date: Tue, 2 Aug 2016 17:30:49 +0200 Subject: [PATCH 2/6] Implement conditional require of cls-hooked As suggested by @raymondfeng in strongloop/loopback-context PR #2 comment #236644728 --- package.json | 6 +++++- server/current-context.js | 24 +++++++++++++++++++++++- 2 files changed, 28 insertions(+), 2 deletions(-) diff --git a/package.json b/package.json index 06d0407..73e0921 100644 --- a/package.json +++ b/package.json @@ -20,7 +20,8 @@ }, "license": "MIT", "dependencies": { - "cls-hooked": "^4.0.1" + "continuation-local-storage": "^3.1.7", + "optional": "^0.1.3" }, "devDependencies": { "chai": "^3.5.0", @@ -30,5 +31,8 @@ "loopback": "^3.0.0-alpha.1", "mocha": "^2.5.3", "supertest": "^1.2.0" + }, + "optionalDependencies": { + "cls-hooked": "^4.0.1" } } diff --git a/server/current-context.js b/server/current-context.js index 8a4ad09..6b392da 100644 --- a/server/current-context.js +++ b/server/current-context.js @@ -6,6 +6,8 @@ 'use strict'; var domain = require('domain'); +var requireOptional = require('optional'); +var deprecated = require('depd')('loopback'); // Require CLS only when using the current context feature. // As soon as this require is done, all the instrumentation/patching @@ -15,8 +17,28 @@ var domain = require('domain'); // and other people have seen similar things: // https://github.com/othiym23/async-listener/issues/57 // It all goes away when instrumentation is disabled. +var _isClsRequired = false; var cls = function() { - return require('cls-hooked'); + var clsHooked = requireOptional('cls-hooked'); + if (!clsHooked) { + // optional dependency not met + if (!_isClsRequired) { + // show deprecation warning only once + deprecated('loopback.getCurrentContext() is deprecated, due to issues ' + + 'with continuation-local storage libraries, mostly with Node versions ' + + 'less than 4.5, or between 5.0 and 5.10 (see async-hook for details). ' + + 'Either upgrade Node to a version outside of these ranges and ' + + 'reinstall cls-hooked locally, or see ' + + 'https://docs.strongloop.com/display/APIC/Using%20current%20context ' + + 'for more details. If you already upgraded Node, maybe this warning is ' + + 'only because cls-hooked failed to install for some reason.'); + _isClsRequired = true; + } + // fallback to legacy module + return require('continuation-local-storage'); + } else { + return clsHooked; + } }; var LoopBackContext = module.exports; From 550b13e807be180a16e6098e082c1f38abdbc955 Mon Sep 17 00:00:00 2001 From: josieusa Date: Wed, 3 Aug 2016 14:03:36 +0200 Subject: [PATCH 3/6] Fix missing depd package --- package.json | 1 + 1 file changed, 1 insertion(+) diff --git a/package.json b/package.json index 73e0921..6b3c018 100644 --- a/package.json +++ b/package.json @@ -21,6 +21,7 @@ "license": "MIT", "dependencies": { "continuation-local-storage": "^3.1.7", + "depd": "^1.1.0", "optional": "^0.1.3" }, "devDependencies": { From 3bae15f5d890ac7a90a4a9765adb43819ddd7796 Mon Sep 17 00:00:00 2001 From: josieusa Date: Mon, 5 Sep 2016 15:27:57 +0200 Subject: [PATCH 4/6] Try cls-hooked-interceptor, add test, edit README --- README.md | 24 +++++++++++++++ package.json | 4 ++- test/main.test.js | 76 ++++++++++++++++++++++++++++++++++++++++++++++- 3 files changed, 102 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 57b4c65..14314ed 100644 --- a/README.md +++ b/README.md @@ -3,6 +3,30 @@ Current context for LoopBack applications, based on cls-hooked. +## Main changes in `cls-hooked` branch + +The work-in-progress `cls-hooked` branch uses `cls-hooked` NPM package, which in turn uses `async-hook`. The latter requires Node > 4.5 as specified in its own `package.json`. **This change alone doesn't solve, for now, any problem with `loopback-context`, especially issues related to lost context (for example see [loopback #1495](https://github.com/strongloop/loopback/issues/1495)), as far as the writer knows**. But it uses Node `AsyncWrap`, which may have some pros in the long term. + +However, as a work-in-progress, this branch also includes the experimental package `cls-hooked-interceptor` (**not ready for production**), which should give useful warnings when there is the risk that the context would get lost at runtime. **Neither this solves any problem with `loopback-context`**. It's just *a work-in-progress that will eventually help with debugging and mantaining apps experiencing such issues, common especially in legacy apps*. + +Therefore, **what is the solution to issues with lost context?** For now, you should implement your own solution. For example, the writer uses the `npm shrinkwrap` solution mentioned in [loopback #1495](https://github.com/strongloop/loopback/issues/1495), but even this could be useless for you, in case you get a broken install (this is unpredictable and hard to notice, and this package wants to change that). + +To test this branch, just run the tests with `npm test`. (You will also see a warning from `cls-hooked-interceptor`, in addition to the test output; this is the desired behavior). + +If you want to see all the infos and warnings that `cls-hooked-interceptor` sends to the `debug` package, declare the environment variable `DEBUG=cls-hooked-interceptor` when running the tests. + +OS X example: + +`DEBUG=cls-hooked-interceptor npm test` + +By default, the test makes the context get lost. If you want to test the opposite case when the package does *not* warn, because the context is *not* lost, just declare the environment variable `KEEP_CONTEXT=true` when running the tests (*this variable has no effect outside of tests!*). + +OS X example: + +`KEEP_CONTEXT=true npm test` + +**TODO**: try to refactor the tests using the package `lose-cls-context`. + ## Usage 1) Add `per-request-context` middleware to your diff --git a/package.json b/package.json index 6b3c018..dda51df 100644 --- a/package.json +++ b/package.json @@ -20,11 +20,13 @@ }, "license": "MIT", "dependencies": { - "continuation-local-storage": "^3.1.7", + "cls-hooked-interceptor": "github:josieusa/cls-hooked-interceptor", + "continuation-local-storage": "3.1.7", "depd": "^1.1.0", "optional": "^0.1.3" }, "devDependencies": { + "async": "1.5.2", "chai": "^3.5.0", "dirty-chai": "^1.2.2", "eslint": "^2.13.1", diff --git a/test/main.test.js b/test/main.test.js index 11e8f30..4508279 100644 --- a/test/main.test.js +++ b/test/main.test.js @@ -5,11 +5,18 @@ 'use strict'; +// If you wish to test when NOT losing context, +// set the environment variable KEEP_CONTEXT to the string 'true'. +// See README for more info. +var keepContext = process.env.KEEP_CONTEXT === 'true'; +if (keepContext) { + require('cls-hooked'); +} var ClsContext = require('..'); +var loopback = require('loopback'); var Domain = require('domain'); var EventEmitter = require('events').EventEmitter; var expect = require('./helpers/expect'); -var loopback = require('loopback'); var request = require('supertest'); describe('LoopBack Context', function() { @@ -99,3 +106,70 @@ describe('LoopBack Context', function() { }); }); }); + +describe('cls-hooked-interceptor', function() { + it('does ' + + (keepContext ? 'not ' : '') + + 'warn when async waterfall does ' + + (keepContext ? 'not ' : '') + + 'lose context', + function(done) { + // If you wish to test if NOT losing context, + // set loseContext to false at the top of the file. + + // Begin intercepting async calls + var warnedDangerousAsyncImport = false; + require('cls-hooked-interceptor')(function(warning) { + if (warning.code !== 'EASYNCCODE') { + console.warn(warning.message); + } + if (warning.code === 'ECLSAFTERINCOMPATIBLEMODULE') { + warnedDangerousAsyncImport = true; + } + }); + // trick cls-hooked-interceptor + if (keepContext) { + require('cls-hooked'); + } + // Make cls-hooked-interceptor emit warnings + // ASYNC VERSION MATTERS! 1.5.2 is required in order for this test to pass. + var async = require('async'); + ClsContext.runInContext(function() { + // function 1 which pulls context + var fn1 = function(cb) { + var ctx = ClsContext.getCurrentContext(); + expect(ctx).is.an('object'); + ctx.set('test-key', 'test-value'); + cb(); + }; + // function 2 which pulls context + var fn2 = function(cb) { + var ctx = ClsContext.getCurrentContext(); + if (keepContext) { + expect(ctx).is.an('object'); + } else { + expect(ctx).is.not.an('object'); + } + var testValue = ctx && ctx.get('test-key', 'test-value'); + cb(null, testValue); + }; + // Trigger async waterfall callbacks + var asyncFn = function() { + async.waterfall([ + fn1, + fn2, + ], function(err, testValue) { + if (keepContext) { + expect(testValue).to.equal('test-value'); + expect(warnedDangerousAsyncImport).to.be.false(); + } else { + expect(testValue).to.not.equal('test-value'); + expect(warnedDangerousAsyncImport).to.be.true(); + } + done(); + }); + }; + asyncFn(); + }); + }); +}); From 08725f5bcc56668265071383484fd82029dd65db Mon Sep 17 00:00:00 2001 From: josieusa Date: Mon, 5 Sep 2016 15:46:59 +0200 Subject: [PATCH 5/6] Fix wrong comment --- test/main.test.js | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/test/main.test.js b/test/main.test.js index 4508279..b714383 100644 --- a/test/main.test.js +++ b/test/main.test.js @@ -114,8 +114,9 @@ describe('cls-hooked-interceptor', function() { (keepContext ? 'not ' : '') + 'lose context', function(done) { - // If you wish to test if NOT losing context, - // set loseContext to false at the top of the file. + // If you wish to test when NOT losing context, + // set the environment variable KEEP_CONTEXT to the string 'true'. + // See at the top of the file; also, see README for more info. // Begin intercepting async calls var warnedDangerousAsyncImport = false; From bf874aa3376b3edc4a6ee64d93855e7420bc71c3 Mon Sep 17 00:00:00 2001 From: josieusa Date: Mon, 5 Sep 2016 17:10:06 +0200 Subject: [PATCH 6/6] Implement handleWarnings() method --- README.md | 37 +++++++++++++++++++++++++++++++++++-- package.json | 1 + server/current-context.js | 4 ++++ test/main.test.js | 16 ++++++++++++++++ 4 files changed, 56 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 14314ed..1592db2 100644 --- a/README.md +++ b/README.md @@ -5,13 +5,46 @@ cls-hooked. ## Main changes in `cls-hooked` branch +The following method (**NOT READY FOR PRODUCTION**) is added: `LoopBackContext.handleWarnings()`. + +Example: + +``` +// as early as possible in your code: +var clsHookedInterceptor = require('cls-hooked-interceptor'); +... +LoopBackContext.handleWarnings(clsHookedInterceptor, callback); +``` + +The callback must have the following form: + +``` +var callback = function(err) { + // do something with err.message, err.code, err.errno +} +``` + +The callback gets called only if and when there is a warning, and only once per warning message. + +The possible warning messages and codes are here: + +[cls-hooked-interceptor/errors.js](https://github.com/josieusa/cls-hooked-interceptor/blob/09933d4429dd93a1ea095fcadbe978bc2b5519b2/errors.js) + + `LoopBackContext.handleWarnings()` fails if you haven't installed the interceptor module yet (**NOT READY FOR PRODUCTION**) by running something similar to this: + +`npm i josieusa/cls-hooked-interceptor` + +(For now, `cls-hooked-interceptor` is not published to NPM. Maybe a recent enough version of NPM is required.) + +This branch is incompatible with `continuation-local-storage` and silently fails at runtime if that is used somewhere. + The work-in-progress `cls-hooked` branch uses `cls-hooked` NPM package, which in turn uses `async-hook`. The latter requires Node > 4.5 as specified in its own `package.json`. **This change alone doesn't solve, for now, any problem with `loopback-context`, especially issues related to lost context (for example see [loopback #1495](https://github.com/strongloop/loopback/issues/1495)), as far as the writer knows**. But it uses Node `AsyncWrap`, which may have some pros in the long term. However, as a work-in-progress, this branch also includes the experimental package `cls-hooked-interceptor` (**not ready for production**), which should give useful warnings when there is the risk that the context would get lost at runtime. **Neither this solves any problem with `loopback-context`**. It's just *a work-in-progress that will eventually help with debugging and mantaining apps experiencing such issues, common especially in legacy apps*. Therefore, **what is the solution to issues with lost context?** For now, you should implement your own solution. For example, the writer uses the `npm shrinkwrap` solution mentioned in [loopback #1495](https://github.com/strongloop/loopback/issues/1495), but even this could be useless for you, in case you get a broken install (this is unpredictable and hard to notice, and this package wants to change that). -To test this branch, just run the tests with `npm test`. (You will also see a warning from `cls-hooked-interceptor`, in addition to the test output; this is the desired behavior). +To test this branch, just run the tests with `npm test`. (You will also see a warning from `cls-hooked-interceptor`, in addition to the `cls-hooked-interceptor` suite output - and only that suite; this is the desired behavior). If you want to see all the infos and warnings that `cls-hooked-interceptor` sends to the `debug` package, declare the environment variable `DEBUG=cls-hooked-interceptor` when running the tests. @@ -19,7 +52,7 @@ OS X example: `DEBUG=cls-hooked-interceptor npm test` -By default, the test makes the context get lost. If you want to test the opposite case when the package does *not* warn, because the context is *not* lost, just declare the environment variable `KEEP_CONTEXT=true` when running the tests (*this variable has no effect outside of tests!*). +By default, the test makes the context get lost. If you want to test the opposite case when the package does *not* warn, because the context is *not* lost, just declare the environment variable `KEEP_CONTEXT=true` when running the tests (*this variable has no effect outside of tests!*). Of course, no warning will be logged to the console! OS X example: diff --git a/package.json b/package.json index dda51df..bf47806 100644 --- a/package.json +++ b/package.json @@ -28,6 +28,7 @@ "devDependencies": { "async": "1.5.2", "chai": "^3.5.0", + "chai-spies": "0.7.1", "dirty-chai": "^1.2.2", "eslint": "^2.13.1", "eslint-config-loopback": "^4.0.0", diff --git a/server/current-context.js b/server/current-context.js index 6b392da..005eb2f 100644 --- a/server/current-context.js +++ b/server/current-context.js @@ -116,3 +116,7 @@ LoopBackContext.createContext = function(scopeName) { } return ns; }; + +LoopBackContext.handleWarnings = function(clsHookedInterceptorInstance, cb) { + clsHookedInterceptorInstance(cb); +}; diff --git a/test/main.test.js b/test/main.test.js index b714383..1d1b415 100644 --- a/test/main.test.js +++ b/test/main.test.js @@ -18,6 +18,11 @@ var Domain = require('domain'); var EventEmitter = require('events').EventEmitter; var expect = require('./helpers/expect'); var request = require('supertest'); +var spies = require('chai-spies'); +var chai = require('chai'); +var clsHookedInterceptor; + +chai.use(spies); describe('LoopBack Context', function() { var runInOtherDomain, runnerInterval; @@ -174,3 +179,14 @@ describe('cls-hooked-interceptor', function() { }); }); }); + +describe('LoopBack Context', function() { + it('replaces cls-hooked-interceptor callback', function() { + var cb = function() {}; + var spy = chai.spy(cb); + ClsContext.handleWarnings(require('cls-hooked-interceptor'), spy); + // trick cls-hooked-interceptor + require('async'); + expect(spy).to.have.been.called(); + }); +});