tedious: Library (node-mssql) doesnt recover after db outage

I have an issue i cannot find a solution for (https://github.com/tediousjs/node-mssql/issues/701), and I would like to try here as well, maybe someone could help. I am using node-mssql, and my problem is that if the database goes down, and then recovers, the library doesn’t recover and keeps returning TimeoutError: ResourceRequest timed out. I have enabled debugging, and what i see is that, after the database is up again, a prelogin message is sent, and the socket is ended. Compared to at the beginning, when the database is up, it responds to the prelogin:

connected to localhost:1433

Sent type:0x12(PRELOGIN), status:0x01(EOM), length:0x002F, spid:0x0000, packetId:0x01, window:0x00 0000 00001A00 06010020 00010200 21000103 00220004 04002600 01FF0000 00010001 … …!.. ."…&. … 0020 02000000 000000 … PreLogin - version:0.0.0.1 1, encryption:0x02(NOT_SUP), instopt:0x00, threadId:0x00000000, mars:0x00(OFF) State change: Connecting -> SentPrelogin

Received type:0x04(TABULAR_RESULT), status:0x01(EOM), length:0x002B, spid:0x0000, packetId:0x01, window:0x00 0000 00001A00 06010020 00010200 21000103 00220000 04002200 01FF0E00 0BDD0000 … …!.. .“…”. … 0020 020000 … PreLogin - version:14.0.11.221 0, encryption:0x02(NOT_SUP), instopt:0x00, threadId:0x00000000, mars:0x00(OFF)

… (stop & start the database)

onPoolError listener Failed to connect to localhost:1433 - Could not connect (sequence) State change: Connecting -> Final names err: TimeoutError: ResourceRequest timed out at ResourceRequest._fireTimeout (/Users/alex/projects/sofy-unit2/node_modules/generic-pool/lib/ResourceRequest.js:62:17) at Timeout.bound (/Users/alex/projects/sofy-unit2/node_modules/generic-pool/lib/ResourceRequest.js:8:15) at ontimeout (timers.js:475:11) at tryOnTimeout (timers.js:310:5) at Timer.listOnTimeout (timers.js:270:5) onPoolError listener Failed to connect to localhost:1433 - Could not connect (sequence) State change: Connecting -> Final next connected to localhost:1433

Sent type:0x12(PRELOGIN), status:0x01(EOM), length:0x002F, spid:0x0000, packetId:0x01, window:0x00 0000 00001A00 06010020 00010200 21000103 00220004 04002600 01FF0000 00010001 … …!.. ."…&. … 0020 02000000 000000 … PreLogin - version:0.0.0.1 1, encryption:0x02(NOT_SUP), instopt:0x00, threadId:0x00000000, mars:0x00(OFF) State change: Connecting -> SentPrelogin socket ended State change: SentPrelogin -> Final connection to localhost:1433 closed State is already Final names err: TimeoutError: ResourceRequest timed out at ResourceRequest._fireTimeout (/Users/alex/projects/sofy-unit2/node_modules/generic-pool/lib/ResourceRequest.js:62:17) at Timeout.bound (/Users/alex/projects/sofy-unit2/node_modules/generic-pool/lib/ResourceRequest.js:8:15) at ontimeout (timers.js:475:11) at tryOnTimeout (timers.js:310:5) at Timer.listOnTimeout (timers.js:270:5)

This is the code i am testing with:

index.js

const app = require('./app');
app(3);

app.js

const sql = require('mssql');

class Repo {
    constructor(connectionPool) {
        /**
         * @private
         */
        this.connectionSett = connectionPool;
    }

    async names() {
        const pool = await this.connectionSett;

        const queryRes = await pool
            .request()
            .query(
                'select name from names'
            );

        return queryRes['recordset'].map(r => r.name);
    }
}

function createConn() {
    const user = 'sa';
    const password = 'P@55w0rd';
    const server = 'localhost';
    const database = 'test';

    const pool = new sql.ConnectionPool({user, password, server, database, debug: true, pool: {acquireTimeoutMillis: 5000}});

    pool.on('error', err => {
        console.error('onPoolError listener');
        //console.error(err);
    });

    pool.on('debug', (connection, message) => {
        //console.log(connection);
        console.log(message);
    });

    return pool.connect();
}

module.exports = (
    intervalSeconds,
    repo = new Repo(createConn())
) => {
    const main = () => run().catch(console.error);
    main();
    setInterval(
        main,
        intervalSeconds * 1000
    );

    async function run() {
        console.log("next");

        await repo.names()
            .then(res => console.log(`names res: ${res}`))
            .catch(err => console.error(`names err: ${err.stack}`));
    }
};

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Comments: 19 (10 by maintainers)

Most upvoted comments

Hey @madal3x, this issue is fixed by PR https://github.com/tediousjs/tedious/pull/769. I tested the PR with your repro code in docker, driver throws connection lost error and cleans things up. Issue you see in tediousjs/node-mssql should vanish once #769 gets merged.

Are you referring to SQL Server in this line?

The db is a docker container that i stop through kitematic.

When I mention db, I’m referring to the individual database inside the Server. Can you share tedious debug logs? Enable them in connection config

options: {
	debug: {
	packet:  true,
	data:  true,
	payload:  true,
	token:  true,
	log:  true
	}
}

@Suraiya-Hameed yes, true, though i thought one would replace the connection if it had an error. So i recreated the scenario just by using tedious, starting the script when db is up, then stopping the db and starting it again while the script was running. And the results were that after the db was up, the library kept outputting the same error:

RequestError: Requests can only be made in the LoggedIn state, not the Final state at RequestError (/Users/alex/projects/sofy-unit2/node_modules/tedious/lib/errors.js:34:12) at Connection.makeRequest (/Users/alex/projects/sofy-unit2/node_modules/tedious/lib/connection.js:1584:26) at Connection.execSql (/Users/alex/projects/sofy-unit2/node_modules/tedious/lib/connection.js:1347:12) at Promise (/Users/alex/projects/sofy-unit2/testpromise/app-tedious.js:66:24) at new Promise (<anonymous>) at Repo.names (/Users/alex/projects/sofy-unit2/testpromise/app-tedious.js:17:16) at <anonymous> at process._tickCallback (internal/process/next_tick.js:188:7)

In the process i’ve discovered that the request.on(‘done’) was not called, but the doneInProc and doneProc were called. Unfortunately these were called with the value of rows being an empty array. Therefore I had to aggregate the rows inside the row event for request.

Code:

app.js

const Connection = require('tedious').Connection;
const Request = require('tedious').Request;

class Repo {
    constructor(connection) {
        /**
         * @private
         * @type {Promise<Connection>}
         */
        this.connection = connection;
    }

    async names() {
        const connection = await this.connection;
        const allRows = [];

        return new Promise(((resolve, reject) => {
            const request = new Request("select name from names", function(err, rowCount) {
                if (err) {
                    return reject(err);
                } else {
                    console.log(rowCount + ' rows');
                }
            });

            request.on('row', function(columns) {
                console.log('onRow');

                columns.forEach(function(column) {
                    const row = [];
                    row.push({
                        metadata: column.metadata,
                        value: column.value,
                        toString: () => column.value
                    });
                    allRows.push(row);
                });
            });

            /*
            request.on('done', function(rowCount, more) {
                console.log('onDone');

                return resolve(rows);
            });
            */

            /*
            request.on('doneInProc', function (rowCount, more, rows) {
                console.log('onDoneInProc');

                console.log(rows);

                return resolve(rows);
            });
            */

            request.on('doneProc', function (rowCount, more, returnStatus, rows) {
                console.log('onDoneProc');

                //console.log(rows);

                return resolve(allRows);
            });

            connection.execSql(request);
        }));
    }
}

/**
 *
 * @return {Promise<Connection>}
 */
function createConn() {
    const user = 'sa';
    const password = 'P@55w0rd';
    const server = 'localhost';
    const database = 'test';

    const config = {
        server: server,
        userName: user,
        password: password,
        options: {
          debug: {
            packet: true,
            data: true,
            payload: true,
            token: false,
            log: true
          },
          database: database,
          //encrypt: true // for Azure users
        }
    };

    const connection = new Connection(config);

    connection.on('errorMessage', err => {
        console.error('onError')
        //console.error(err);
    });

    return new Promise(((resolve, reject) => {
        connection.on('connect', err => {
            if (err) {
                console.error('onConnectionError');

                reject(err)
            } else {
                resolve(connection);
            }
        });
    }));
}

module.exports = (
    intervalSeconds,
    repo = new Repo(createConn())
) => {
    const main = () => run().catch(console.error);
    main();
    setInterval(
        main,
        intervalSeconds * 1000
    );

    async function run() {
        console.log("next");

        await repo.names()
            .then(res => console.log(`names res: ${res}`))
            .catch(err => console.error(`names err: ${err.stack}`));
    }
};

index.js

const app = require('./app');
app(3);