balderdashy / sails

Realtime MVC Framework for Node.js
https://sailsjs.com
MIT License
22.84k stars 1.95k forks source link

Node module caching causes cookie-parser error after lowering and re-lifting Sails in test suite: TypeError: Cannot read property 'cookie' of undefined #4842

Open blah238 opened 5 years ago

blah238 commented 5 years ago

Node version: 10.5.3 Sails version (sails): 1.1.0 ORM hook version (sails-hook-orm): n/a Sockets hook version (sails-hook-sockets): n/a Organics hook version (sails-hook-organics): n/a Grunt hook version (sails-hook-grunt): n/a Uploads hook version (sails-hook-uploads): n/a DB adapter & version (e.g. sails-mysql@5.55.5): n/a Skipper adapter & version (e.g. skipper-s3@5.55.5): n/a


I have created a minimal reproduction of my code in which Sails is unable to be lifted a second time in tests due to an error in the cookie-parser dependency:

TypeError: Cannot read property 'cookie' of undefined
 at cookieParser (node_modules\cookie-parser\index.js:45:31)
 at sails-cookie-error\node_modules\sails\lib\hooks\http\get-configured-http-middleware-fns.js:134:16
 at getBuiltInHttpMiddleware (node_modules\sails\lib\hooks\http\get-configured-http-middleware-fns.js:144:7)
 at _afterLoadingSessionHookIfApplicable (node_modules\sails\lib\hooks\http\initialize.js:298:43)
 at sails-cookie-error\node_modules\sails\lib\hooks\http\initialize.js:31:18
 at sails-cookie-error\node_modules\sails\lib\app\private\after.js:111:14
 at sails-cookie-error\node_modules\async\dist\async.js:3861:9
 at sails-cookie-error\node_modules\async\dist\async.js:421:16
 at iteratorCallback (node_modules\async\dist\async.js:998:13)
 at sails-cookie-error\node_modules\async\dist\async.js:906:16
 at sails-cookie-error\node_modules\async\dist\async.js:3858:13
 at handlerFn (node_modules\sails\lib\app\private\after.js:85:18)
 at sails-cookie-error\node_modules\async\dist\async.js:3853:24
 at eachOfArrayLike (node_modules\async\dist\async.js:1003:9)
 at eachOf (node_modules\async\dist\async.js:1051:5)
 at _parallel (node_modules\async\dist\async.js:3852:5)
 at Object.parallelLimit [as parallel] (node_modules\async\dist\async.js:3935:5)
 at Sails.emitter.after (node_modules\sails\lib\app\private\after.js:105:11)
 at _waitForSessionHookIfApplicable (node_modules\sails\lib\hooks\http\initialize.js:30:15)
 at Hook.initialize (node_modules\sails\lib\hooks\http\initialize.js:42:7)
 at Hook.wrapper [as initialize] (node_modules\@sailshq\lodash\lib\index.js:3275:19)
 at sails-cookie-error\node_modules\sails\lib\hooks\index.js:122:20
 at sails-cookie-error\node_modules\async\dist\async.js:421:16
 at processQueue (node_modules\async\dist\async.js:1565:20)
 at taskComplete (node_modules\async\dist\async.js:1588:9)
 at sails-cookie-error\node_modules\async\dist\async.js:1612:17
 at sails-cookie-error\node_modules\async\dist\async.js:906:16
 at Hook.loadModules (node_modules\sails\lib\hooks\index.js:178:14)
 at Hook.wrapper [as loadModules] (node_modules\@sailshq\lodash\lib\index.js:3275:19)
 at modules (node_modules\sails\lib\hooks\index.js:86:25)
 at runTask (node_modules\async\dist\async.js:1621:13)
 at sails-cookie-error\node_modules\async\dist\async.js:1559:13
 at processQueue (node_modules\async\dist\async.js:1569:13)
 at Object.auto (node_modules\async\dist\async.js:1555:5)
 at Hook.load (node_modules\sails\lib\hooks\index.js:80:13)
 at Hook.wrapper [as load] (node_modules\@sailshq\lodash\lib\index.js:3275:19)
 at loadHook (node_modules\sails\lib\app\private\loadHooks.js:212:17)
 at sails-cookie-error\node_modules\sails\lib\app\private\loadHooks.js:344:13
 at sails-cookie-error\node_modules\async\dist\async.js:3083:16
 at eachOfArrayLike (node_modules\async\dist\async.js:1003:9)
 at eachOf (node_modules\async\dist\async.js:1051:5)
 at Object.eachLimit (node_modules\async\dist\async.js:3145:5)
 at load (node_modules\sails\lib\app\private\loadHooks.js:342:17)
 at sails-cookie-error\node_modules\async\dist\async.js:3853:24
 at replenish (node_modules\async\dist\async.js:946:17)
 at iterateeCallback (node_modules\async\dist\async.js:931:17)
 at sails-cookie-error\node_modules\async\dist\async.js:906:16
 at sails-cookie-error\node_modules\async\dist\async.js:3858:13
 at sails-cookie-error\node_modules\async\dist\async.js:421:16
 at iteratorCallback (node_modules\async\dist\async.js:998:13)
 at sails-cookie-error\node_modules\async\dist\async.js:906:16
 at process._tickCallback (internal/process/next_tick.js:61:11)

I can get the tests passing by using import-fresh to "re-require" the config/http.js file (by commenting out and uncommenting the marked lines in test/helpers/appHelper.js).

Anyone know what's going on here?

sailsbot commented 5 years ago

@blah238 Thanks for posting! We'll take a look as soon as possible.

In the mean time, there are a few ways you can help speed things along:

Please remember: never post in a public forum if you believe you've found a genuine security vulnerability. Instead, disclose it responsibly.

For help with questions about Sails, click here.

raqem commented 5 years ago

Hi @blah238 Thank you for providing a repo for your issue. I was able to reproduce your issue by following your instructions on the repo. Can you please give a little more information about what your trying to accomplish?

blah238 commented 5 years ago

Hi @raqem glad to hear you were able to reproduce the issue.

I am primarily trying to upgrade my existing Sails 0.12.x application to 1.x. This issue appeared in our test suite which lifts a Sails instance once at the beginning, lowers it once at the end, and in some tests (generally ones that modify the test database), lowers and re-raises Sails as part of the test setup or teardown to get back to a clean slate.

It would appear that there is some shared state that isn't properly getting cleaned up between lift/lower cycles, and I'm not sure if that's a problem in Sails or my code, but since it only started happening with the Sails 1.x codebase I'm guessing it's a problem with Sails.

But even with my workaround above in my real application's codebase, some of my other tests are having a similar issue with a different 3rd party package (passport and passport-local) after a second lift, so I'm currently looking into that and will post another issue when I can minimally reproduce it as well.

So I'm guessing that there is something about the middleware system in Sails 1.x that has changed and is causing this since it only occurs with 1.x and not 0.12.x.

rachaelshaw commented 5 years ago

@blah238 before we start digging into this more: was your example app generated with Sails v1? (I'm assuming it was, but just want to rule out any kind of upgrade issue since you mentioned running into this while upgrading)

In the mean time, might be helpful to have a look at the changelog to see if anything jumps out at you - at first glance, I'm seeing some links to a few issues related to lift & lower, so there may be something relevant there.

blah238 commented 5 years ago

@rachaelshaw correct, I used Sails 1.1.0 to generate the example: https://github.com/blah238/sails-cookie-error/blob/b591687ff7d85f5b18293cf52052584c662fd18a/.sailsrc#L6-L7

I did skim through the changelog but didn't see anything pertinent to this issue, although I have run into an error with lift not working at all in tests, which was fixed by updating captains-log and rc. This issue is also present in the 0.12.x branch, so I will open have opened a PR to update those and hopefully get a new 0.12.x release as well.

blah238 commented 5 years ago

@rachaelshaw rather than open another issue I have added a branch in my sails-cookie-error repo that reproduces the issue with passport not working upon a 2nd lift:

Error: Unknown authentication strategy "local"
    at attempt (sails-cookie-error\node_modules\passport\lib\middleware\authenticate.js:186:37)
    at authenticate (sails-cookie-error\node_modules\passport\lib\middleware\authenticate.js:362:7)
    at Object.processLogin [as auth/processlogin] (sails-cookie-error\api\controllers\AuthController.js:32:7)
    at sails-cookie-error\node_modules\sails\lib\router\bind.js:248:46
    at routeTargetFnWrapper (sails-cookie-error\node_modules\sails\lib\router\bind.js:392:9)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:137:13)
    at Route.dispatch (sails-cookie-error\node_modules\express\lib\router\route.js:112:3)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at sails-cookie-error\node_modules\express\lib\router\index.js:281:22
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:335:12)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:127:14)
    at addResponseMethods (sails-cookie-error\node_modules\sails\lib\hooks\responses\index.js:149:18)
    at routeTargetFnWrapper (sails-cookie-error\node_modules\sails\lib\router\bind.js:392:9)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:137:13)
    at Route.dispatch (sails-cookie-error\node_modules\express\lib\router\route.js:112:3)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at sails-cookie-error\node_modules\express\lib\router\index.js:281:22
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:354:14)
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:365:14)
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:410:3)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:127:14)
    at _addResViewMethod (sails-cookie-error\node_modules\sails\lib\hooks\views\res.view.js:426:3)
    at routeTargetFnWrapper (sails-cookie-error\node_modules\sails\lib\router\bind.js:392:9)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:137:13)
    at Route.dispatch (sails-cookie-error\node_modules\express\lib\router\route.js:112:3)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at sails-cookie-error\node_modules\express\lib\router\index.js:281:22
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:354:14)
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:365:14)
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:410:3)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:127:14)
    at addMixins (sails-cookie-error\node_modules\sails\lib\hooks\request\index.js:97:18)
    at routeTargetFnWrapper (sails-cookie-error\node_modules\sails\lib\router\bind.js:392:9)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at next (sails-cookie-error\node_modules\express\lib\router\route.js:137:13)
    at Route.dispatch (sails-cookie-error\node_modules\express\lib\router\route.js:112:3)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at sails-cookie-error\node_modules\express\lib\router\index.js:281:22
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:354:14)
    at param (sails-cookie-error\node_modules\express\lib\router\index.js:365:14)
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:410:3)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at Function.handle (sails-cookie-error\node_modules\express\lib\router\index.js:174:3)
    at router (sails-cookie-error\node_modules\express\lib\router\index.js:47:12)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at trim_prefix (sails-cookie-error\node_modules\express\lib\router\index.js:317:13)
    at sails-cookie-error\node_modules\express\lib\router\index.js:284:7
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:335:12)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at xPoweredBy (sails-cookie-error\node_modules\sails\lib\hooks\http\get-configured-http-middleware-fns.js:189:7)
    at Layer.handle [as handle_request] (sails-cookie-error\node_modules\express\lib\router\layer.js:95:5)
    at trim_prefix (sails-cookie-error\node_modules\express\lib\router\index.js:317:13)
    at sails-cookie-error\node_modules\express\lib\router\index.js:284:7
    at Function.process_params (sails-cookie-error\node_modules\express\lib\router\index.js:335:12)
    at next (sails-cookie-error\node_modules\express\lib\router\index.js:275:10)
    at sails-cookie-error\node_modules\skipper\lib\skipper.js:122:47
    at sails-cookie-error\node_modules\body-parser\lib\read.js:130:5
    at invokeCallback (sails-cookie-error\node_modules\raw-body\index.js:224:16)
    at done (sails-cookie-error\node_modules\raw-body\index.js:213:7)
    at IncomingMessage.onEnd (sails-cookie-error\node_modules\raw-body\index.js:273:7)
    at IncomingMessage.emit (events.js:194:15)
    at endReadableNT (_stream_readable.js:1125:12)
    at process._tickCallback (internal/process/next_tick.js:63:19)

To work around the issue I am using the decache module to clear the AuthController module from the node modules cache between lower/lift cycles. Using decache on the sails module also has the same effect, but may be overkill.

As it seems to be a similar issue if not quite the same I opted not to create a separate issue for it while you are looking into the original cookie-parser issue. Hope that is ok.

Thanks!

blah238 commented 5 years ago

A followup to my previous comment, I was able to refactor my example app to work around the passport error: https://github.com/blah238/sails-cookie-error/compare/passport-error...passport-error-fix

The cookie-parser error still occurs, however, if config/http is not cleared from the node module cache.

raqem commented 5 years ago

Hi @blah238 I realized there are some examples of test in Ration (a dummy site created by @mikermcneil during the Platzi course) Maybe looking through those can help you get some ideas of what to try next.

blah238 commented 5 years ago

@raqem I did not see anything particularly relevant in those links but thanks anyways.

I was able to successfully complete my upgrade to 1.x (actually 1.2.1 which I saw was just released), so I am no longer actively looking into this. I am still using the workaround of clearing config/http for my tests, e.g. https://github.com/blah238/sails-cookie-error/blob/9c9570fd2e1dad91be9bf3f04e2dfac952057d5e/test/helpers/appHelper.js#L50

Hopefully someday I can remove it 😄

raqem commented 5 years ago

Happy to hear you were able to finish the upgrade!