What happens on connection timeout?

[akc42]

I have an application which I spend a lot of my time debugging the client side. When I do eventually get around to making a database request I quite frequently, but not always get the following error...

Requests can only be made in the LoggedIn state, not the Final state" (edited because I had added some to the error message)

Which I am assuming means I am trying to make a request on a timed out connection or something.

I can post more code if necessary, but for the moment I am not doing anything particularly strange, I just set up a pool as follows.

const ConnectionPool = require('tedious-connection-pool');

  class DB  {
    constructor(ConnectionPool,logger) {
      this.logger = logger;
      this.poolDrained = false;
      this.pool = new ConnectionPool(poolConfig, {
        server: DBHOST,
        userName: DBUSER,
        password: DBPASS,
        options: {
          port: DBPORT,
          database: DBNAME,
          useColumnNames: true,
          connectTimeout: DBCONTO,
          requestTimeout: DBREQTO
        }
      });
      this.pool.on('error', (err) => {
        this.logger('database',err.message);
        this.pool.drain();
        this.poolDrained = true;
        process.kill(process.pid,'SIGINT'); //tells us to shutdown gracefully
      });
    }
    close() {
      if (!this.poolDrained) {
        this.pool.drain();
      }
    }
}

With a pool config of

  var poolConfig = {
    min: (process.env.PAS_POOL_MIN)? process.env.PAS_POOL_MIN : 2,
    max: (process.env.PAS_POOL_MAX)? process.env.PAS_POOL_MAX : 4,
    log: false
  };

The DB Class above wraps an exec method which acquires and releases the connection in one run through returning a promise which resolves when complete. So I am pretty sure I am not holding on to connections that I shouldn't

[akc42]

I just conducted an experiment by switching on logging and also adding a line to log the connection acquired (it would be useful if always did this). With the debugging on, I can see that it closed an idle connection and then handed it to me on the next acquire. My request then immediately failed with "Requests can only be made in the Logged In state"

[akc42]

Done a bit of debugging on this with my own copy. There main issue is that there is a gap between the idle timeout being called and the connection end event being emitted. In that gap the status of the pool for this connection is FREE. As a result new requests can pick this connection up that is in the process of closing and try and re-use them.

The reason that I am seeing the problem quite frequently however (normally a request to close and the end event are very close together) is that once a connection has been used and the reset been called it does not seem to emit the end event. With debug log on, I can see the reset but never see the end. Is the a tedious issue?

[akc42]

OK, all understood now.

The reason I was not seeing the connection end was I had removed all listeners from the connection at the end of the request. So this was making the gap between timing out and closing the connection, and this connection being removed from the connection pool infinitely long. This was a bug on my part and I have fixed it.

I am not sure if there is a gap now between the connection close from the timeout and the connection end being omitted, but why take the chance. I have issued a pull request ( #31 ) that closes that small hole.

In getting to the bottom of this I found it immensely helpful to also know when a connection was acquired, so I have added another pull request #30 which adds that additional line to the logging.

I'll close this issue now