Request timeout problems once in a while

[Cottin]

We're running a next.js application on a Windows Server using iisnode.

Everything works fine, but during every ~50th user session we experience: RequestError: Timeout: Request failed to complete in 15000ms. It's enough to be a hassle but not enough to be able to be reproduced.

Is there anything conceptually wrong with the way we're using a global connection pool? (Simplified code below)
Or is this kind of "once in a while" timeout problems common when using mssql with pools?

helpers.js

import mssql from 'mssql'

const sqlConfig = {
  ...
  pool: {
    max: 10,
    min: 0,
    idleTimeoutMillis: 10000,
  },
  options: {
    trustServerCertificate: true,
  },
};

const mainSqlPool = new mssql.ConnectionPool(sqlConfig);
let sqlPool = null;

async function getSqlPool() {
  if (!sqlPool) {
    try {
      const tempPool = await mainSqlPool.connect();
      sqlPool = tempPool;
    } catch (err) {
      console.error('Failed to connect to SQL pool:', err);
      throw err;
    }
  }
  return sqlPool;
}

mainSqlPool.on('error', (err) => {
  console.error('SQL pool error', err);
  sqlPool = null;
});



export async function runQuery(query) {
  try {
    const pool = getSqlPool()
    const request = new mssql.Request(pool);
    const result = await request.query(query);
    return result;
  } catch (err) {
    console.error('err', err);
    throw err;
  }
}

api/createUser.js

export default handler = (req, res) => {
  return await runQuery("insert into UserTable (name) values ('John Doe')")
}

[dhensby]

It's not normal to see intermittent timeouts. There would need to be an investigation into the underlying problem to determine why some queries are timing-out. It's not possible to give a speculative reason for this but this does come up every now and again in the repo and when people do come back to update the underlying cause, it's not a bug in the library.

Have you looked through past issues to see if there's anything relevant to you?

[Cottin]

Thanks for the tips! I spent the morning reading through old issues and found some intermittent timeout problems like you said, but there is no relevant help there. Funnily we're running an old version of our app using the tedious package directly without any problems (but obviously without any pool).

Like discussed in previous issues, the timeouts could be related to infrastructure but probably requires advanced logging to find the root cause. Since the problem is so intermittent and impossible to reproduce except for letting prod run for several days, it's hard to debug.

The docs has an example of how to implement a global pool for Express but there is no example for how to do it in Next.js though, which as I understand don't have a single long-lived process like Express so you'd have to do something similar like I'm doing above instead of calling connect() only once at the top of the file.

I'll try one variation to move the new mssql.ConnectionPool(sqlConfig) inside the getSqlPool() and also attach the .on('error', ... to the pool instead of the mainSqlPool and let it run for a while and see if there's any difference. I'll also decrease the requestTimeout and do 1 retry for each request on any transient errors like ETIMEOUT, ESOCKET, ECONNRESET, ECONNREFUSED.

If no improvement, I guess I'll go down the pool.healty and the .query('SELECT 1') route.

Updates to minimal example:

let sqlPool = null;

async function getSqlPool() {
  if (!sqlPool) {
    try {
      const tempPool = await new mssql.ConnectionPool(sqlConfig).connect()
      tempPool.on('error', (err) => {
        console.error('SQL pool error', err);
        sqlPool = null;
      });
      sqlPool = tempPool;
    } catch (err) {
      console.error('Failed to connect to SQL pool:', err);
      throw err;
    }
  }
  return sqlPool;
}

[dhensby]

Next.js will have a single long running process (that's how JS apps work); but your implementation vs using the built-in global pool won't make much difference apart from potentially at startup where there's a risk you'll create several pools because each call to getSqlPool() will spin up a new pool until the initial connect() call resolves. That won't happen with the global pool.

Without knowing things like the specific query (or queries) that timeout, nor access to the server to understand if there's some kind of deadlock that's not being released, it's not possible to help debug this.

[Cottin]

Thanks a lot for the clarification!
I see your point. I guess a promise based approach instead of async/await would get rid of the potential risk of creating several pools at startup? eg.

let sqlPoolPromise = null;

function getSqlPool() {
  if (sqlPoolPromise) return sqlPoolPromise;

  sqlPoolPromise = new sql.ConnectionPool(sqlConfig)
    .connect()
    .then((pool) => {
      pool.on('error', (err) => {
        console.error('SQL pool error:', err);
        sqlPoolPromise = null;
      });
      return pool;
    })
    .catch((err) => {
      sqlPoolPromise = null;
      throw err;
    });

  return sqlPoolPromise;
}

ie. first call to getSqlPool() will set sqlPoolPromise and the subsequent calls will just return that same promise (even if connect() has not resolved yet).

We don't have a specific query that timesout, just basically any of 7 different INSERT / UPDATE / DELETE queries that works flawlessly 99.7% of the time and that are simple CRUD queries.

So what would your recommendation be for using mssql with a pooled approach in a next.js application?

• Just use the global connection pool ?
• or as said in the docs "it is better to maintain your own reference to the pool, where connect() is called once, and the resulting global pool's connection promise is re-used throughout the entire application." ?

The approach for express in the docs of

appPool.connect().then(function(pool) {
  app.locals.db = pool;
  const server = app.listen(3000, function () {
    ...
  })
})

will obviously not work because there's no app.listen in next.js.

But I guess something like this would be the same approach in a "next.js fashion"?

// lib/db.js
const sql = require('mssql');
const sqlConfig = { /* ... */ };

const poolPromise = new sql.ConnectionPool(sqlConfig)
  .connect()
  .then(pool => {
    pool.on('error', (err) => {
      console.error('SQL pool error', err);
    });
    return pool;
  })
  .catch(err => {
    console.error('Error connecting to SQL pool', err);
    throw err;
  });

module.exports = {
  sql,
  poolPromise
};

// pages/api/example.js
const { poolPromise } = require('../../lib/db');

module.exports = async function handler(req, res) {
  const pool = await poolPromise;
  const result = await pool.request().query('SELECT 1');
  res.status(200).json(result.recordset);
}

Would that approach be appropriate for both a self-hosted and a serverless next.js environment?

[dhensby]

Your initial suggestion of holding a reference to the Promise would work, yes. That's how I would do it, however I think the docs are a bit out of date:

it is better to maintain your own reference to the pool, where connect() is called once, and the resulting global pool's connection promise is re-used throughout the entire application.

The backend now supports multiple calls to connect() resolving to a single pool, which didn't used to be the case. I think you can safely rely on the global pool if you want to.

Regarding the single entry point, I'm not a nextjs expert, so I can't provide an authoritative view on this; but it does look like you can use the instrumentation file for bootstrapping dependencies.

[Cottin]

Thanks so much for your help!

It sounds like a key takeaway is that the docs are out of date and that it's safe to to rely on the global pool not having to jump through the hoops of custom pool creation/singleton. I'll try that and see if it has any positive effect.

Instrumentation might work for this purpose but as I understand, it's more for side-effects like logging and similar, so maybe could work but is probably not the idiomatic next.js way.

Edit: Exact same problem with global app pool. I'll try some trouble shootings and creative workarounds and update the thread if anyone else stumbles on similar problems.

[dhensby]

Edit: Exact same problem with global app pool. I'll try some trouble shootings and creative workarounds and update the thread if anyone else stumbles on similar problems.

Sorry, I didn't see the edit. The only thing I can really recommend is to try to log things like the particular query that is timing out, the state of the pool (is it healthy, are there available connections, etc), and then any backend correlation that can be done to see if that query is running slow on the server for some reason (maybe a deadlock, or something?).

[Cottin]

After a couple of months of debugging, I found the issue. You were right all along, there was no problem with node-mssql or the pool, it was a select query that was run before the CRUD queries for validation that got stuck when there was a lock on the main table.

The problem was I kept drawing the wrong conclusions cus I did not have enough access to the db to run diagnostics or logging and the locks only appeared certain periods every month so if testing raw Tedious with unlucky timing you'd think that it solved all the issues...

Anyway, thank's for the support! When not having weird issues like that, node-mssql is quite a lot nicer than running raw Tedious like we've done in earlier apps.

[dhensby]

Thanks for the update and I'm really glad you got to the bottom of it. It can be really hard to get to the root cause of this kind of thing, as you've experienced, but great job finding out the cause.

For others that experience a similar thing, do you have any tips on how they could "easily" determine if it is caused by table locks or similar DB level problem? It can be really difficult to provide help to people who see these kinds of problems and want help from a library maintainer!

[Cottin]

I can imagine it's hard as a lib maintainer to provide much help in these situations.

One simple way to test if DB locks are blocking your query is to SET LOCK_TIMEOUT 1000. Instead of getting a timeout after requestTimeout ms, you'd get a 1222 error Lock request time out period exceeded after 1 sec and then you'd know it was because of a lock blocking you. (Be sure to reset it later though unless you want all requests on that connection to timeout after 1 sec, or use a separate pool for lock sensitive queries).

Otherwise it's probably good to periodically and when issues happen run queries against sys.dm_exec_requests, sys.dm_os_wait_stats, sys.dm_exec_sessions... to get more info what queries get stuck etc. Also consider logging of slow query traces etc. Also, if you have head blockers, instead of just killing them in SSMS, identify what queries are causing it by running queries against dm_exec_requests or in SSMS Activity Monitor click Details > Copy SQL or similar.

---

I'm not a backend / DB expert but here are some of my findings and tips from the last months troubleshooting.

The preface is you're having intermittent timeout problems or similar in production that is not reproducible in a dev environment and that you don't have enough access to run diagnostics as described above.

Log queries application side
What solved it for me was having detailed logging of queries on my application side.

• Log query start, query completion + time elapsed (it's important that logs for stuck queries that never finish are not swallowed)
• Tag it with request id, user id, etc. so that it's possible to filter and analyse from thousands of logs in production
• Log a special warning if a query takes long to finish, eg.

const warnTimer = setTimeout(() => {
  config.log('[QUERY-WARN]', sqlQuery, params, '- Still running after 5000 ms');
}, 5000);

try {
  // Run query...
} catch (error) {
  // Log error...
} finally {
  clearTimeout(warnTimer)
}

Log the state of the pool
For your own peace of mind, try logging the state of the pool in reasonable places.
eg.

const poolStatusString = (pool) => {
  const props = [
    { name: '_connected', type: 'property' },
    { name: '_connecting', type: 'property' },
    { name: '_healthy', type: 'property' },
    { name: 'connected', type: 'property' },
    { name: 'connecting', type: 'property' },
    { name: 'healthy', type: 'property' },
    { name: 'size', type: 'property' },
    { name: 'available', type: 'property' },
    { name: 'pending', type: 'property' },
    { name: 'borrowed', type: 'property' },
    { name: 'listenerCount', type: 'function' }
  ];

  const lines = props.map(({ name, type }) => {
    try {
      const value = type === 'function' ? pool[name]() : pool[name];
      return `${name}: ${value}`;
    } catch (err) {
      return `${name}: <error accessing>`;
    }
  });

  return lines.join('\n');
};

Resulting in something like so:

_connected: true
_connecting: false
_healthy: true
connected: true
connecting: false
healthy: true
size: 8
available: 3
pending: 0
borrowed: 5
listenerCount: 0

I never ran into any pool related issues, but it's nice to be able to see the status of the pool if you're having issues in production.

abortTransactionOnError: true
If you're running transactions and sometimes end up with head blockers, it could be good to enable abortTransactionOnError: true (XACT_ABORT) in the driver config. It might not solve everything but probably a reasonable thing to add if you're having those kinds of issues.

Test the effects of LOCKS locally
You might not be able to reproduce the exact same issues that's seen in production but you can reproduce how a table lock would affect your application.
Eg. if you're having a save action that results in a UPDATE company SET name='Vandalay' WHERE id=1.
Run a transaction query similar to this in your query editor before clicking the save button in your application:

BEGIN TRAN;
UPDATE company
SET Descr = Descr + '.'  -- dummy write to lock the row
WHERE id = 1;
WAITFOR DELAY '00:00:10';
ROLLBACK TRAN;

It will create a lock that blocks your query for 10 seconds. Resulting in either a timeout error or a 1222 Lock request time out period exceeded if you've set LOCK_TIMEOUT.
This might not reproduce the real timeout issues you're having in production, but it's nice as a developer to be able to test how the app would behave in such a situation.

Experiment with SET LOCK_TIMEOUT
If you're suspecting timeout issues coming from table locks, it could be worth experimenting with await request.batch("SET LOCK_TIMEOUT 2000"). If a query gets blocked by a lock, instead of getting queued for a potentially long time, you'll get a 1222 error Lock request time out period exceeded after 2 sec. It could be a nice UX displaying something like "DB is busy" to the user quickly instead of having them wait for 30 sec allowing them to keep the "edit view" open and press "save" a bit later. Like so, you're also not overloading the DB with lots of queued queries if you're having many users getting frustrated and spamming the save button:)
Although, make sure to reset (await request.batch("SET LOCK_TIMEOUT -1") unless you want all requests on that connection to have the same behaviour to locks or use a separate pool for lock sensitive queries. (Note that if a request failed within a transaction, we can't call .batch("SET LOCK_TIMEOUT -1") on that same request if XACT_ABORT is ON because then the transaction will have been aborted and the .batch() will fail with ENOTBEGUN. So we need to reach for the pool (.parent) and get a fresh request to set the LOCK_TIMEOUT on)

Experiment with WITH (NOLOCK)
If you're suspecting timeout issues coming from table locks, it could be worth experimenting with WITH (NOLOCK). Eg. if you're running queries like SELECT ref FROM invoicing WHERE name like 'abc' and you know that invoicing has lots of transactions running against it that locks it up for long periods, it could be worth adding SELECT ref FROM invoicing WITH (NOLOCK) WHERE name like 'abc'. Then you would not get stuck on the lock but you do risk of reading stale data or maybe even uncommitted data that might be rolled back. But depending on what you're reading, this could be a reasonable tradeoff.

Be careful with "dynamic" queries
If you're having problems with table locks blocking your queries, investigate how you're queries look like. Eg. SELECT name FROM company WHERE id=1 will only get blocked if a transaction or similar has a lock on the row with id=1. But a query like SELECT name FROM company WHERE name LIKE 'abc%' might get blocked by more locks. Check if you have queries that may result in table scans as these have a higher risk of getting blocked.

Be careful with many retries and low requestTimeout
One strategy I tried was to have a low requestTimeout (~6 sec) and instead do 4 retries. It ended up creating more complexity and spamming so at least for me the better option was to leave requestTimeout long (30-40 sec) and not doing any retries at all and instead show a nice wait UX for the users. Also, if you're doing transactions, don't do any retries of queries within the transaction, better to just fail it and roll back since otherwise your own transaction probably holds locks that affect others so you could end up with a blocking chain. Better to just put a low LOCK_TIMEOUT on queries executed within a transaction so it either succeeds or fails fast if you're having issues with head blockers.

A nice waiting UX
If you're dealing with a (legacy) system / DB that regularly are taking table locks, you might just have to accept and plan for it. A frozen save button quickly gets frustrating for users and might cause them to leave or refresh and their action might finish "silently" on the server without them realising it. We saw a big increase in willingness to wait when adding a special "wait popup" with a spinner and messages that kept changing to keep the user engaged (Waiting for the server...., It seems to be busy today..., ...). The perceived stability of an app is quite a psychological thing in my experience.

And again, I'm not a DB expert so don't blindly trust these tips:)
It's just a couple of conclusions I got after weeks of troubleshooting timeout issues with mssql in production.

[dhensby]

Wow, @Cottin - thanks so much for taking your time to write all of that up. I'm tempted to pin this issue to the repo for people to read... At the very least I'll be directing people here when they report these similar kinds of issues.

[Cottin]

No worries, I thought I'd write it down while it was still fresh in mind. Exactly, I felt a bit lost in april when I was faced with these problems so I thought it could be nice to have some tips for others facing similar issues. Do what you think is best.