context is lost on 'end' event of http request stream

[aidinrs]

Here is a sample snippet:

const http = require('http');
var createNamespace = require('cls-hooked').createNamespace;
var session = createNamespace('session-ns');


const server = http.createServer(function (request, response) {
    session.run(function (ctx) {
        session.set('key', 1)
        read(request, response, function (req, res) {
            process._rawDebug(`DONE - key: ${session.get('key')}`)
            res.end(`key: ${session.get('key')}\r\n`)
        })
    })
})

server.listen(8080)

function read(req, res, done) {
    let body = [];
    req
        .on('data', function (chunk) {
            body.push(chunk)
        })
        .on('end', function () {
            body = Buffer.concat(body).toString()
            process._rawDebug(`End - key: ${session.get('key')}`)
            done(req, res)
        });
}

As you can see I have created a http server and read the body by a stream. run the snippet then use curl.
curl http://localhost:8080
console output:

End - key: 1  
DONE - key: 1

for simple GET requests the context is correct, but when you send data in the body the context is lost.
curl http://localhost:8080 -X POST -d aaaaaaaaaa
console output:

End - key: undefined   
DONE - key: undefined

This issues is also related to this skonves/express-http-context#4. The problem is not the body-parser package, I have tracked it down and found that it is caused by the same issue as here, the callback of 'end' event looses context.

Node runtime: reproducible on all v8.14.0, v10.4.0, v10.3.0, and v10.14.1
OS: Ubuntu 18.04
cls-hooked: 4.2.2

[aidinrs]

@Jeff-Lewis I think this issue is related to cls-hooked, I can pass context in the sample by a naive implementation using async_hooks

[Strate]

@AiDirex did you find solution for your problem?

[PoslavskySV]

Same here. Any solution?

[aidinrs]

@Strate @PoslavskySV I decided to use my own naive implementation.

const asyncHooks = require('async_hooks')

let contexts = {}

asyncHooks.createHook({
  init (asyncId, type, triggerAsyncId, resource) {
    if (contexts[triggerAsyncId] !== undefined) {
      contexts[asyncId] = contexts[triggerAsyncId]
    } else {
      contexts[asyncId] = {}
    }
  },

  destroy (asyncId) {
    delete contexts[asyncId]
  }
}).enable()


function run (callback) {
  let eid = asyncHooks.executionAsyncId()
  contexts[eid] = {}
  callback()
}

function set (k, v) {
  let eid = asyncHooks.executionAsyncId()
  let ctx = contexts[eid]
  if (ctx !== undefined) {
    ctx[k] = v
  }
}

function get (k) {
  let eid = asyncHooks.executionAsyncId()
  let ctx = contexts[eid]
  return ctx !== undefined ? ctx[k] : undefined
}

module.exports = {get, set, run, contexts}

It doesn't have the above issue, and I use it with async/await on node 8.14 without any problems. Also, I use these packages on my project: express, body-parse, Sequelize, oauth2-server, cookie-parser, and request-promise-native.
Though I had some issues with nested Promises at first but when I rewrote them with async/await it worked fine.

[PoslavskySV]

@AiDirex Thanks!

[Strate]

@AiDirex have you tried namespace.bindEmitter(), as described in readme of this lib?

[aidinrs]

@Strate no.

[PoslavskySV]

@Strate I tried, still bug is present.

[aidinrs]

@Strate my code snippet worked without any problems so far.

[aidinrs]

This is also a middleware for express which does something like the express-http-context package.

const uuid = require('uuid/v4')
const {run, set} = require('./context')


module.exports = (req, res, next) => {
  run(() => {
      let ctxId = uuid()
      set('context-id', ctxId)
      next()
  })
}

Then in the rest of your middleware chain you can use get('context-id') to retrieve the id for that context.

[Strate]

@AiDirex sounds very promising! I am bit confused, that originally this library has a bit more code, especially inside async hook.

I've tested your code against bluebird, context losed (I think this is bluebird's problem).

Would you release your code as a package with cls-interfaces support? (for example, to just drop-replace this library?)

[aidinrs]

@Strate it may have some issues with non-native promise implementations. I use it with async/await and native promises. It has more code because you can have multiple namespaces, my snippet is just one namespace. However, adding namespaces is easy.
Yes, I plan to publish a package.

[Jeff-Lewis]

@AiDirex I think you might have found the issue/cause for why the http/net tests are failing in the dev branch of cls-hooked. I haven't had a chance to look into it but now that you have a working example, I will compare and see what the difference is. I will publish a new version when it's resolved. Thank for your help!

[Jeff-Lewis]

@Strate there's cls-bluebird that wraps bluebird very well and is agnostic to the cls library as long as is it supports the cls namespace psuedo interface.
Also, there's been a request to make Bluebird support async_hooks but it looks like it hasn't gone anywhere yet.

[Jeff-Lewis]

Essentially the behavior of async_hooks changed in 8.10.0 which is described in nodejs #21078. Options we have are to either change behavior back to what it used to be and what is documented by node, or stick with existing behavior.

Either way, the best option for cls-hooked is to accommodate the behavior inconsistencies across node versions and handle it appropriately.

[Jeff-Lewis]

@AiDirex - I'm debugging this and it appears to be an issue isolated the the end event on a POST. The data event does propagate context correctly. I'm exploring adding a work around for the related node issue #21078.

[Strate]

@Jeff-Lewis am I right, that core difference between original cls-hooked mechanic and @AiDirex 's solution is triggerAsyncId() in cls-hooked vs executionAsyncId() in other's. And this is core thing that makes @AiDirex 's solution worked for this case. For me it is more cleaner to use executionAsyncId(), as it requires less hooks (lower performance impact) and cleaner to understand. But, I may miss something.

[Jeff-Lewis]

@Strate My quick answer is that using triggerAsyncId in this case does work, but it will be inconsistent in other scenarios.

The best option for cls-hooks is to have a workaround to the change in the behavior of Node, which is now inconsistent to the node docs, with regards to the net behavior of async-hooks. See my comment immediately above regards to node isse #21078

[Jeff-Lewis]

I'm hoping some changes to async_hook, specifically nodejs/node#27581, would resolve this. Needs to be tested...

[kjavaherpour]

Hi @Jeff-Lewis, any progress on this?

[kibertoad]

@Jeff-Lewis There was a reply from Node maintainer side, they are OK with documenting status quo as the intended behaviour.

[alexandruluca]

@Jeff-Lewis
Any updates on this? I still have the issue on node v12.18.0

[kibertoad]

@alexandruluca There are no good reasons to keep using cls-hooked on node 12.18.0, async-local-storage is fully supported there and is a recommended and actually properly supported alternative.
You can check this bridge lib to see the ALS equivalents to cls-hooked:
https://github.com/kibertoad/asynchronous-local-storage/blob/master/lib/cls-fallback.ts
https://github.com/kibertoad/asynchronous-local-storage/blob/master/lib/als.ts

[alexandruluca]

Big thanks

…

On Mon, 11 Jan 2021 at 20:53, Igor Savin ***@***.***> wrote: @alexandruluca <https://github.com/alexandruluca> There are no good reasons to keep using cls-hooked on node 12.18.0, async-local-storage is fully supported there and is a recommended and actually properly supported alternative. You can check this bridge lib to see the ALS equivalents to cls-hooked: https://github.com/kibertoad/asynchronous-local-storage/blob/master/lib/cls-fallback.ts https://github.com/kibertoad/asynchronous-local-storage/blob/master/lib/als.ts — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#36 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABSAHNWAIR5PU3HHNPKVQDTSZNCLXANCNFSM4GJOPIYQ> .

[heby281]

@kibertoad We use ALS of node 12.21.0, but the problem still exists.