SQL query timeout from application but works fast from SSMS

Recently faced very strange problem. Application which was working great during last two years just suddenly had timeout on one particular page. The page was always very fast and was showing just last 12 records from the table.

So I did what always was doing to check slow performing query, started SQL Profiler to trace the query. Query by itself is pretty complex and had a lot of parameters, Profiler is the best tool I think in that cases.

After I easily found long running query in Profiler I copy pasted it into SSMS and what a surprize query just run in 300ms. Meanwhile the query from UI (asp.net) was running almost 2 minutes.

The first to be different is session variables. To get info about sessions you can just select from the sys.dm_exec_sessions table.
more info about table https://docs.microsoft.com/en-us/sql/relational-databases/system-dynamic-management-views/sys-dm-exec-sessions-transact-sql

Easy way to compare between sessions:

SELECT
    session_id,
    [ansi_defaults],
    [ansi_null_dflt_on],
    [ansi_nulls],
    [ansi_padding],
    [ansi_warnings],
    [arithabort],
    [concat_null_yields_null],
    [deadlock_priority],
    [quoted_identifier],
    [transaction_isolation_level]
FROM
    sys.dm_exec_sessions
WHERE
    session_id IN (, );

To get session Id from from simple SQL query just run SELECT @@SPID, so this had to be your probably fast executing query. Session id for slow executing Application you can find in profiler, it is a column in UI.

As a result I got these two rows, 1st row is slow session, 2nd row is second session


As you can see the only difference is arithabort setting.
More information about it can be found here
https://docs.microsoft.com/en-us/sql/t-sql/statements/set-arithabort-transact-sql

Strange thing I had no arithmetic expressions in my query which could lead to the problem.
So for an experiment I added this query to SSMS which was executing fast to see if it will slow down

SET ARITHABORT OFF
DECLARE @ARITHABORT VARCHAR(3) = 'OFF';
IF ( (64 & @@OPTIONS) = 64 ) SET @ARITHABORT = 'ON';
SELECT @ARITHABORT AS ARITHABORT;

It had expected effect, query just slowed to 2 mins from 200ms!
After playing with query a little bit I found that issue was in comparing date part of the query
Fast:
AND (@FromDate IS NULL OR o.Created >= @FromDate)
            AND (@ToDate IS NULL OR o.Created < @ToDate)
Slow:
AND (@FromDate IS NULL OR o.Created >= @FromDate)
            AND (@ToDate IS NULL OR o.Created <= @ToDate)
Not sure what has to do <= Datetime compare with arithmetic overflow but at least it helped.

As a solution I could
1. change <= to <
2. Add SET ARITHABORT OFF to the query
3. change setting for the table

I have chosen 3rd option, which should prevent from similar problems later.
Switching in UI the parameter to True fixed the slow running query immidietly.



Comments

Popular posts from this blog

How to poll database using WCF-SQL adapter

Security overdone?