othiym23 / node-continuation-local-storage

implementation of https://github.com/joyent/node/issues/5243
BSD 2-Clause "Simplified" License
1.13k stars 207 forks source link

How to isolate sessions within an event callback? #129

Open JemiloII opened 6 years ago

JemiloII commented 6 years ago

So I'm running into an issue, if I have the same event fire multiple times in quick succession, with promises nested, My sessions are overlapped and my first event call is now having data from my second or third call.

Essentially here is my poc I'm working on. Note that logger.js is just an exported winton logger with custom levels equal to the levels array.

// kafkaLogger.js
const {getNamespace} = require('continuation-local-storage');
const logger = require('./logger.js');

const levels = ['debug', 'error', 'extra', 'failure', 'history', 'info', 'memory', 'notice', 'warn', 'verbose'];

class KafkaLogger {
    constructor() {
        this.session = getNamespace('kafka');
        levels.forEach(level => (this[level] = this.add(level)));
    }

    add(level) {
        return (...message) => logger.log(level, `${this.session.get('id')}:`, ...message);
    }
}

module.exports = KafkaLogger;

This next file, test.js is the file that I am simulating an event I receive from kafka. The id property is what I am using to track my logs with. I am using message as a payload test, sometimes I may have more than just an id and a message.

// test.js
const {createNamespace} = require('continuation-local-storage');
const Events = require('events');
const KafkaLogger = require('./kafkaLogger.js');
const utils = require('../common/utils.js');

class TestEvents extends Events {}

const testEvents = new TestEvents();
const session = createNamespace('kafka');
session.bindEmitter(testEvents);

testEvents.on('message', ({id, message}) => {
    session.set('id', id);
    const test2 = require('./tests2.js');
    const logger = new KafkaLogger();
    logger.debug(message, 'test1');
    test2.doStuff(message)
        .then(test2.doStuff)
        .then(() => logger.error('=================='));
});

testEvents.on('error', error => {
    console.log('Error:', new Error(error));
});

module.exports = testEvents;

setInterval(() => testEvents.emit('message', {id: '1a2a3a', message: 'Hello Earth!'}), 1000);
setInterval(() => testEvents.emit('message', {id: '2e45re', message: 'Hello Venus!'}), 1000);
// test2.js
const bluebird = require('bluebird');
const KafkaLogger = require('./kafkaLogger.js');
const test3 = require('./tests3.js');

const logger = new KafkaLogger();

const doStuff = (message) =>
    bluebird.resolve(message)
        .then((message) => {
            logger.debug(message, 'test2');
            return message;
        })
        .then(test3.doMoreStuff)
        .catch(error => logger.error(error, 'test2'));

module.exports = {
    doStuff
};
// test3.js
const bluebird = require('bluebird');
const KafkaLogger = require('./kafkaLogger.js');

const logger = new KafkaLogger();

const doMoreStuff = (message) =>
    bluebird.resolve(message)
        .then((message) => {
            logger.debug(message, 'test3');
            return message;
        })
        .catch(error => logger.error(error, 'test3 error'));

module.exports = {
    doMoreStuff
};

Currently it outputs:

2018-03-05T23:18:59.357Z - debug: 1a2a3a: Hello Earth! test1
2018-03-05T23:18:59.363Z - debug: 2e45re: Hello Venus! test1
2018-03-05T23:18:59.367Z - debug: 1a2a3a: Hello Earth! test2
2018-03-05T23:18:59.367Z - debug: 1a2a3a: Hello Venus! test2
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test3
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Venus! test3
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test2
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Venus! test2
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test3
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Venus! test3
2018-03-05T23:18:59.369Z - error: 1a2a3a: ==================
2018-03-05T23:18:59.369Z - error: 1a2a3a: ==================

However, I am expecting this:

2018-03-05T23:18:59.357Z - debug: 1a2a3a: Hello Earth! test1
2018-03-05T23:18:59.363Z - debug: 2e45re: Hello Venus! test1
2018-03-05T23:18:59.367Z - debug: 1a2a3a: Hello Earth! test2
2018-03-05T23:18:59.367Z - debug: 2e45re: Hello Venus! test2
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test3
2018-03-05T23:18:59.368Z - debug: 2e45re: Hello Venus! test3
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test2
2018-03-05T23:18:59.368Z - debug: 2e45re: Hello Venus! test2
2018-03-05T23:18:59.368Z - debug: 1a2a3a: Hello Earth! test3
2018-03-05T23:18:59.368Z - debug: 2e45re: Hello Venus! test3
2018-03-05T23:18:59.369Z - error: 1a2a3a: ==================
2018-03-05T23:18:59.369Z - error: 2e45re: ==================

Essentially, 1a2a3a should be paired with Hello Earth! and 2s3s4s should be paired with 'Hello Venus!`