tediousjs / node-mssql

Microsoft SQL Server client for Node.js
https://tediousjs.github.io/node-mssql
MIT License
2.23k stars 466 forks source link

mssql suddenly stopped working with INSERTS to sql server db from AWS Lambda, with no changes anywhere. Had been working fine for years. #1650

Closed ANTGOMEZ closed 3 months ago

ANTGOMEZ commented 4 months ago

Runnung from AWS Lambda mssql hanging at the point of executing insert command

Expected behaviour: Expect Inserts to insert data into table when called through mssql

Actual behaviour: Hangs during insert and subsequently times out. It's an insert to the same table always. Has always worked until now.

We've been running an AWS Lambda that connects to an Onprem SQL Server DB and makes an Insert into a table (below). Has been running for years like this without issues. All of a sudden, this just stopped working. The insert hangs at the point that the code attempts to execute the query. The odd thing is that after doing a trace, we can see that pool.connect() actually sends a validation query to the server (SELECT 1). Also, select statements work went sent through using the same code. The logs show: "executing query" but nothing beyond that and then Lambda times out. If we could see some kind of error that could tell us something, that would be nice, but mssql just times out.

Ran below code on an independent Linux server on AWS and it behaves the same way, get ETIMEOUT.

I did try getting a verbose log from mssql but it's not helpful, just shows that dependent libraries executed. Like this DEBUG=mssql:* node app.js

Now, if I send a smaller insert statement, then it works. But like I said before, the full insert had been working for years. And, no, there are no syntax errors that would cause a failure or something.

Configuration:

Here's the entirety of the code used to connect and exec queries:

const sql = require("mssql");

let poolRequest;

function getConnection(config) {
    if (!poolRequest) {
        console.log("creating new connection");
        const pool = new sql.ConnectionPool(config);
        poolRequest = pool.connect();
    }
    return poolRequest;
}

async function execSQL(conn_cfg, cmd) {
    let res;
    try {
        const pool = await getConnection(conn_cfg);

        console.log("executing query");
        res = await pool
            .request() 
            .query(cmd)
            .then(() => {
                console.log("query completed successfully");
            })
            .catch(err => {
                console.log(`query error: ${err}`);
                throw err;
            });

    } catch (err) {
        console.log(`execSQL error: ${err}`);
        throw err;
    } finally {
        poolRequest = null;
    }
    return res;
}

This is the table, 114 columns:

[dbo].[tbl_OpptStaging](
    [EventDateInserted] [datetime] NULL,
    [EventId] [uniqueidentifier] NULL,
    [EventType] [nvarchar](20) NULL,
    [EventSource] [nvarchar](20) NULL,
    [CorrelationId] [uniqueidentifier] NULL,
    [CorrelationOrigin] [nvarchar](20) NULL,
    [Timestamp] [datetime] NULL,
    [OpportunityItemId] [int] NULL,
    [OpportunityType] [nvarchar](20) NULL,
    [OpportunityFormType] [nvarchar](20) NULL,
    [OpportunityOpenClosed] [nvarchar](20) NULL,
    [OpportunityStatus] [nvarchar](20) NULL,
    [OpportunityItemCloseDate] [datetime2](7) NULL,
    [DateCreated] [datetime2](7) NULL,
    [ExpectedCloseDate] [datetime2](7) NULL,
    [PreviousTransDate] [datetime2](7) NULL,
    [PreviousExpireDate] [datetime2](7) NULL,
    [LastUpdated] [datetime2](7) NULL,
    [TrialEndDate] [datetime2](7) NULL,
    [IsTrial] [bit] NULL,
    [ItemStage] [nvarchar](20) NULL,
    [NewRenewal] [nvarchar](20) NULL,
    [CustId] [nvarchar](20) NULL,
    [Probability] [decimal](3, 2) NULL,
    [PreviousTerm] [int] NULL,
    [TermInMonths] [nvarchar](20) NULL,
    [IsRenewedAmountProrated] [bit] NULL,
    [ProductOfferingCode] [nvarchar](20) NULL,
    [CurrencyISO4217AlphaCode] [nvarchar](3) NULL,
    [LostReason] [nvarchar](256) NULL,
    [PipelineNote] [nvarchar](max) NULL,
    [SalesRepNSKeyId] [int] NULL,
    [OpsAllocationId] [int] NULL,
    [TerritoryNSKeyId] [int] NULL,
    [SegmentNSKeyId] [int] NULL,
    [MarketNSKeyId] [int] NULL,
    [OpsSegmentID] [int] NULL,
    [OpsTerritoryID] [int] NULL,
    [OpsMarketID] [int] NULL,
    [AllocationPercentage] [decimal](5, 4) NULL,
    [NetAmount] [decimal](19, 4) NULL,
    [WeightedAmount] [decimal](19, 4) NULL,
    [GrossPrice] [decimal](19, 4) NULL,
    [USDConvertedNetAmount] [decimal](19, 4) NULL,
    [USDConvertedWeightedAmount] [decimal](19, 4) NULL,
    [USDConvertedGrossPrice] [decimal](19, 4) NULL,
    [USDConvertedAllocatedFullRevenue] [decimal](19, 4) NULL,
    [USDConvertedAllocatedWeightedRevenue] [decimal](19, 4) NULL,
    [USDConvertedAllocatedGrossPrice] [decimal](19, 4) NULL,
    [LocalCurrencyAllocatedFullRevenue] [decimal](19, 4) NULL,
    [LocalCurrencyAllocatedWeightedRevenue] [decimal](19, 4) NULL,
    [LocalCurrencyAllocatedGrossPrice] [decimal](19, 4) NULL,
    [ConversionRate] [decimal](3, 2) NULL,
    [GeomarketId] [int] NULL,
    [ContainerCategory] [nvarchar](50) NULL,
    [RequiresRoyalty] [bit] NOT NULL,
    [SalesRepRenewalNsKeyId] [int] NULL,
    [SalesRepLSDNsKeyId] [int] NULL,
    [SalesManagerRenewalNsKeyId] [int] NULL,
    [SalesManagerLSDNsKeyId] [int] NULL,
    [RenewalIncreaseLoaded] [decimal](19, 4) NULL,
    [RenewalIncreaseThreshold] [decimal](19, 4) NULL,
    [RenewalIncreaseApplied] [decimal](19, 4) NULL,
    [LSDRoyaltyMargin] [decimal](19, 4) NULL,
    [LSDRoyaltyMarkup] [decimal](19, 4) NULL,
    [LSDMarginThresholdPercent] [decimal](19, 4) NULL,
    [LSDMarkupThresholdPercent] [decimal](19, 4) NULL,
    [SalesRepRenewalReasonId] [int] NULL,
    [SalesRepRenewalReasonValue] [nvarchar](250) NULL,
    [SalesRepRenewalReasonNote] [nvarchar](2500) NULL,
    [SalesRepRenewalTimeSubmitted] [datetime2](7) NULL,
    [SalesRepLSDReasonId] [int] NULL,
    [SalesRepLSDReasonValue] [nvarchar](250) NULL,
    [SalesRepLSDReasonNote] [nvarchar](2500) NULL,
    [SalesRepLSDTimeSubmitted] [datetime2](7) NULL,
    [SalesManagerRenewalApprovalStatus] [nvarchar](30) NULL,
    [SalesManagerRenewalTimeSubmitted] [datetime2](7) NULL,
    [SalesManagerRenewalApprovedReasonId] [int] NULL,
    [SalesManagerRenewalApprovedReasonValue] [nvarchar](250) NULL,
    [SalesManagerRenewalApprovedReasonNote] [nvarchar](2500) NULL,
    [SalesManagerRenewalDeclinedReasonId] [int] NULL,
    [SalesManagerRenewalDeclinedReasonValue] [nvarchar](250) NULL,
    [SalesManagerRenewalDeclinedReasonNote] [nvarchar](2500) NULL,
    [SalesManagerLSDApprovalStatus] [nvarchar](30) NULL,
    [SalesManagerLSDTimeSubmitted] [datetime2](7) NULL,
    [SalesManagerLSDApprovedReasonId] [int] NULL,
    [SalesManagerLSDApprovedReasonValue] [nvarchar](250) NULL,
    [SalesManagerLSDApprovedReasonNote] [nvarchar](2500) NULL,
    [SalesManagerLSDDeclinedReasonId] [int] NULL,
    [SalesManagerLSDDeclinedReasonValue] [nvarchar](250) NULL,
    [SalesManagerLSDDeclinedReasonNote] [nvarchar](2500) NULL,
    [SalesManagerReassignToNsKeyId] [int] NULL,
    [SalesManagerReassignByNsKeyId] [int] NULL,
    [SalesManagerReassignReasonId] [int] NULL,
    [SalesManagerReassignReasonValue] [nvarchar](250) NULL,
    [SalesManagerReassignComment] [nvarchar](2500) NULL,
    [OpportunityRenewalFlagType] [varchar](30) NULL,
    [OpportunityLSDFlagType] [varchar](30) NULL,
    [LastYearRetail] [decimal](19, 4) NULL,
    [OpportunityListRate] [nvarchar](250) NULL,
    [OpportunityRenewalNote] [nvarchar](max) NULL,
    [DiscountType] [nvarchar](100) NULL,
    [PreviousPackageId] [int] NULL,
    [PreviousPackageName] [nvarchar](2000) NULL,
    [PreviousPackagePrice] [decimal](19, 4) NULL,
    [LastYearRoyaltyValue] [decimal](19, 4) NULL,
    [LastYearRoyaltyComment] [nvarchar](300) NULL,
    [DiscountAmount] [decimal](19, 4) NULL,
    [MaxSimultaneousUsers] [int] NULL,
    [UserLicenseComments] [nvarchar](500) NULL,
    [LicenseId] [int] NULL,
    [LicenseTypeOfUser] [varchar](30) NULL,
    [LicenseNumberOfUsers] [int] NULL,
    [LicensePricePerUser] [decimal](19, 4) NULL,
    [LicenseCostPerUserType] [decimal](19, 4) NULL
)

Here's the same config we've always used and worked just fine: {"user": "usx", "password": "psx", "server": "X.X.X.X", "database": "MYDB", "port": 1433, "trustServerCertificate": true, "connectionTimeout": 900000, "requestTimeout": 900000, "pool": {"max": 10, "min": 0, "idleTimeoutMillis": 10000}}

Software versions

dhensby commented 4 months ago

From my experience it's very rare that something stops working when there have been "no changes anywhere".

This needs debugging from your end as there's very little help I can provide for your setup given I'm not your DBA. I can't see anything from what you've said that this would be an issue with the SQL client.

Things that spring to mind:

I see that your config has a request timeout of 15 minutes, so your system is used to requests taking a very long time, I'd aim to investigate the route cause of this as 15mins is a fairly undesirable duration for requests to the database to go through - perhaps your inserts are now taking 15 mins and 1 second and so are timing out?

It is difficult to debug the root cause of timeouts from the client side because the timeout is a client side feature; the library sets a timer and, if no response to the request is received before the timer expires, the request is aborted and an error raised. You'd have to interrogate the SQL server to understand better what is going on.