Setup

• AWS Lambda (3s timeout)
• NodeJS 12.x
• mssql 2.6.1
• tedious (dependency of mssql and so it installs tedious 6.7.0)
• SQL Server DB in RDS (db.t3.small)

I'm also dealing with a fair bit of traffic, with roughly 1k invocations per minute.

Problem

Most of the time the Lambda executes just fine. Roughly 0.35% of the time the Lambda throws an error. The logs look like this:

In the screenshot you can see that the function STARTs, prints some debug info, then throws an error, ENDs, and REPORTs.

While this is a "timeout" error, the error message says,

RequestError: Timeout: Request failed to complete in 15000ms

This confuses me because as you see in the REPORT log, the invocation time was just 255.33ms total.

Question

The obvious question is how does something timeout after 15 seconds in just 255ms? Is this an issue with tedious, mssql, my code, or something else? If my code is relevant to the question please let me know and I can add it. I assume the code is basically functional because it works > 99% of the time.

Failed Theories:

• The logs are interleaved and the errors are not from the 225ms invocation. That's wrong because in the screenshot the request ID's match up.
• There's an intermittent error connecting to the DB, possibly a DNS issue. I have seen very rare EAIAGAIN DNS errors when resolving the DB host, but that doesn't seem to match with the steadiness of this error.
• I didn't spot anything super helpful in the GitHub issues for Tedious.

Full Error

{
    "errorType": "Runtime.UnhandledPromiseRejection",
    "errorMessage": "RequestError: Timeout: Request failed to complete in 15000ms",
    "reason": {
        "errorType": "RequestError",
        "errorMessage": "Timeout: Request failed to complete in 15000ms",
        "code": "ETIMEOUT",
        "originalError": {
            "errorType": "RequestError",
            "errorMessage": "Timeout: Request failed to complete in 15000ms",
            "code": "ETIMEOUT",
            "message": "Timeout: Request failed to complete in 15000ms",
            "stack": [
                "RequestError: Timeout: Request failed to complete in 15000ms",
                "    at RequestError (/var/task/node_modules/mssql/node_modules/tedious/lib/errors.js:32:12)",
                "    at Connection.requestTimeout (/var/task/node_modules/mssql/node_modules/tedious/lib/connection.js:1212:46)",
                "    at Timeout._onTimeout (/var/task/node_modules/mssql/node_modules/tedious/lib/connection.js:1180:14)",
                "    at listOnTimeout (internal/timers.js:549:17)",
                "    at processTimers (internal/timers.js:492:7)"
            ]
        },
        "name": "RequestError",
        "number": "ETIMEOUT",
        "precedingErrors": [],
        "stack": [
            "RequestError: Timeout: Request failed to complete in 15000ms",
            "    at Request.userCallback (/var/task/node_modules/mssql/lib/tedious/request.js:429:19)",
            "    at Request.callback (/var/task/node_modules/mssql/node_modules/tedious/lib/request.js:56:14)",
            "    at Connection.endOfMessageMarkerReceived (/var/task/node_modules/mssql/node_modules/tedious/lib/connection.js:2407:20)",
            "    at Connection.dispatchEvent (/var/task/node_modules/mssql/node_modules/tedious/lib/connection.js:1279:15)",
            "    at Parser.<anonymous> (/var/task/node_modules/mssql/node_modules/tedious/lib/connection.js:1072:14)",
            "    at Parser.emit (events.js:315:20)",
            "    at Parser.EventEmitter.emit (domain.js:482:12)",
            "    at Parser.<anonymous> (/var/task/node_modules/mssql/node_modules/tedious/lib/token/token-stream-parser.js:37:14)",
            "    at Parser.emit (events.js:315:20)",
            "    at Parser.EventEmitter.emit (domain.js:482:12)"
        ]
    },
    "promise": {},
    "stack": [
        "Runtime.UnhandledPromiseRejection: RequestError: Timeout: Request failed to complete in 15000ms",
        "    at process.<anonymous> (/var/runtime/index.js:35:15)",
        "    at process.emit (events.js:315:20)",
        "    at process.EventEmitter.emit (domain.js:482:12)",
        "    at processPromiseRejections (internal/process/promises.js:209:33)",
        "    at processTicksAndRejections (internal/process/task_queues.js:98:32)"
    ]
}