0

I use asp.net mvc, sql server. Query in my repository's class. Sometimes query is executed in 10 seconds, sometimes in 3 minutes!! Why? I used a SQL Server Profiler, but I realy don't understand what could be the cause and how I can find it.

Query:

SELECT 
    [Extent1].[Id] AS [Id], 
    [Extent1].[FirstAddressId] AS [FirstAddressId], 
    [Extent1].[SecondAddressId] AS [SecondAddressId], 
    [Extent1].[Distance] AS [Distance], 
    [Extent1].[JsonRoute] AS [JsonRoute]
    FROM [dbo].[AddressXAddressDistances] AS [Extent1]
Anna
  • 9
  • 2
  • When you execute the query directly on the database using SQLCMD or SSMS, how long does it take? – mason Jun 06 '16 at 17:20
  • 1
    First guess is blocking, see `blocking_session_id` in `sys.dm_exec_requests` – James Z Jun 06 '16 at 17:20
  • @mason it takes less than 1 minute in SQL Server Management Studio – Anna Jun 06 '16 at 17:31
  • @JamesZ: I have run my query and this query: SELECT session_id ,status ,blocking_session_id ,wait_type ,wait_time ,wait_resource ,transaction_id FROM sys.dm_exec_requests WHERE status = N'suspended'; GO I have received error "The underlying provider failed on Open" in application. And query "sys.dm_exec_requests" is executed for 4 minutes. Result: 53 suspended 0 PAGEIOLATCH_SH 48 6:1:414 1647388 – Anna Jun 06 '16 at 18:03
  • Is your SQL Server instance running on a dedicated server? – Chris Pratt Jun 06 '16 at 19:49
  • @ChrisPratt : No, I run SQL Server and my application on laptop – Anna Jun 06 '16 at 20:58
  • At last I have got blocks for my database: Lock:Timeout sa(LoginName) 8(SPID) 2016-06-07 09:38:27.510 2016-06-07 09:38:27.510 125315 1(IsSystem) PC\SQLEXPRESS(ServerName) 6(DBId) Couriers(DBName) 0 - LOCK 3 - S 4 - SHARED_TRANSACTION_WORKSPACE 0 2 - DATABASE If I run the query I have another LoginName and I have Application name. This lock can be the cause of the problem? Why this lock occurs? – Anna Jun 07 '16 at 05:55

2 Answers2

0

Check your query plan. Just run your SELECT statement in SqlServer Management Studio to obtain real query plan. More info is here: Query plan.

If they are the same, but response time differs significantly between the calls, than probably the issue is with lockc on db level (or huge active workloads). I mean incorrect transaction isolation level for instance or some reports running in the meantime obtaining too much resources (or generating locks "because of something" to ensure some data consistency enforced by some developer). Many factors have influence on performance (including memory available at the moment of query execution).

You can run also a few queries to analyze quality of your statistics (or just update all of them using EXEC sp_updatestats) or please analyze fragmentation of the indexes. I guess, but by me locks and outdated stats or defragmented indexes, can force SqlServer to choose very inefficient query plan. Some info on active locks: Active locks on table

Additional info 1: If you are the only user of this db and it's on your local machine (you use SQLServer Express) the issue with locks is rather less possible then other problems. Try to open Event Log of SqlServer. It's available in SqlServer Management Studio on left side (tree) under your engine instance here: Management/Sql Server Logs/Current. Do you see any unusual info there? Try to review system log also (using Event Viewer app). In case of hardware problems you should see there also some info. Btw: how many rows do your have in the table? Try to review also behavior of your disks in some Process Explorer or Performance Monitor. If disk queue length is to big it can be main source of the problem (in such case look what apps stress disk)...

More info on locks:

    SELECT 
      [spid] = session_Id
    , ecid
    , [blockedBy] = blocking_session_id 
    , [database] = DB_NAME(sp.dbid)
    , [user] = nt_username
    , [status] = er.status
    , [wait] = wait_type
    , [current stmt] = 
        SUBSTRING (
            qt.text, 
            er.statement_start_offset/2,
            (CASE 
                WHEN er.statement_end_offset = -1 THEN DATALENGTH(qt.text)  
                ELSE er.statement_end_offset 
            END - er.statement_start_offset)/2)
    ,[current batch] = qt.text
    , reads
    , logical_reads
    , cpu
    , [time elapsed (ms)] = DATEDIFF(mi, start_time,getdate())
    , program = program_name
    , hostname
    --, nt_domain
    , start_time
    , qt.objectid
FROM sys.dm_exec_requests er
INNER JOIN sys.sysprocesses sp ON er.session_id = sp.spid
CROSS APPLY sys.dm_exec_sql_text(er.sql_handle)as qt
WHERE session_Id > 50              -- Ignore system spids.
AND session_Id NOT IN (@@SPID)     -- Ignore this current statement.
ORDER BY 1, 2
GO
Community
  • 1
  • 1
  • Thanks for your reply. I have checked the query plans - they are the same. – Anna Jun 07 '16 at 04:49
  • I have run profiler with "Lock:Timeout" and I have got many Timeout rows for another Databases. I don't use this databases right now. Why I have this blocks: Lock:Timeout sa(LoginName)0(Duration) 8(SPID) 2016-06-07 07:55:47.710 2016-06-07 07:55:47.710 124278 PC\SQLEXPRESS MyDB(DBName) 1(IsSystem) 0 - LOCK 3 - S 4 - SHARED_TRANSACTION_WORKSPACE 0 2 - DATABASE Lock:Timeout sa(LoginName)0(Duration) 35(SPID) 2016-06-07 07:55:47.710 2016-06-07 07:55:47.710 124279 PC\SQLEXPRESS Lists (DBName) 1(IsSystem) 0 - LOCK 5 - X 5 - EXCLUSIVE_TRANSACTION_WORKSPACE 0 2 - DATABASE Is it normal? – Anna Jun 07 '16 at 05:07
  • What version of Express edition do you use? Is it 12, 14, 2016 or RC of 2016? – Aleksander Stankiewicz Jun 07 '16 at 08:03
  • I use Microsoft SQL Server 2014 - 12.0.2000.8 (X64) Express Edition (64-bit). I have got blocks for my database: Lock:Timeout sa(LoginName) 8(SPID) 2016-06-07 09:38:27.510 2016-06-07 09:38:27.510 125315 1(IsSystem) PC\SQL(ServerName) 6(DBId) Couriers(DBNam‌​e) 0 - LOCK 3 - S 4 - SHARED_TRANSACTION_WORKSPACE 0 2 - DATABASE If I run the query I have another LoginName. This lock can be the cause of the problem? Why this lock occurs? – Anna Jun 07 '16 at 13:46
  • About the event log. I found a lot of logs about starting all of the databases that I have. But I don't run them. 06/07/2016 17:23:21,spid30s,Starting up database 'MyDB'. 06/07/2016 17:23:21,spid30s,Starting up database 'Lists'. 06/07/2016 17:23:20,spid30s,Starting up database 'Tasklist'. 06/07/2016 17:23:20,spid30s,Starting up database 'Students'. 06/07/2016 17:23:19,spid30s,Starting up database 'Postmen'. 06/07/2016 16:53:13,spid29s,Starting up database 'MyDB'. 06/07/2016 16:53:13,spid29s,Starting up database 'Lists'. – Anna Jun 07 '16 at 14:02
  • What version of Windows do you use? – Aleksander Stankiewicz Jun 08 '16 at 10:34
  • Could you paste the result of the query for lock sources I pasted above? The info about the starting all the databases you have is ok - it's message from the engine all the dbs are ready to use. – Aleksander Stankiewicz Jun 08 '16 at 10:51
  • 54 0 0 master Chibiusa suspended TRACEWRITE select * from OpenRowset(TABLE TRCDATA, @ traceid, @ record create procedure sys.sp_trace_getdata(@ traceid int,@ records int = 0)as select * from OpenRowset(TABLE TRCDATA, @ traceid, @ records)8 30 1485 1957 SQL Server Profiler-6dd3f5bc-b247-41df-9021-553948a02041 CHIBI-PC 2016-06-07 09:32:59.370 -508658945 I use Windows 8.1 – Anna Jun 08 '16 at 14:22
  • When an application is stuck, I tried to run your code. Your query was executed very slow. Then I have got logs with locks. Then I have got your query result. Can I show you the information about locks? – Anna Jun 08 '16 at 14:43
  • Yes, please. Do you "select" data in your code only or upload also when you observe locking? – Aleksander Stankiewicz Jun 08 '16 at 15:40
  • What about disk led in your notebook? Does it show the disk is active all the time you wait for the query results? If yes, maybe you have to few gigs of memory there (in such case check in Task Manager swap file usage or main memory workload)... – Aleksander Stankiewicz Jun 08 '16 at 15:44
0

Before you waste any more time on this, you should realize that something like the time a query takes in development is essentially meaningless. In development, you're running a single-threaded web server in IIS Express, which means that you've also got VS running, sitting on roughly 2-4 GB of RAM. Together with that, you're running a SQL Server instance, that's fighting the system for both RAM and hard drive time. You haven't given any specs of your system, but if you also happen to be sporting a consumer-class 5400 or 7200 RPM platter-style drive rather than an SSD, that's going to severely impact performance as well. Then, we haven't even got into what else might be running on this system. Photoshop? Outlook? Your favorite playlists of MP3s decoding in the background? What's Windows doing? It might be downloading/applying updates, indexing your drive for search, etc. None of that applies any more when you move into production (or at least shouldn't). In production, you should have a dedicated server with 4-8 GB of RAM and an SSD or enterprise-class 15,000+ RPM platter drive devoted just to SQL Server, so it can spit out query results at lightning speeds.

Long and short, if you want to guage website/query performance of your application, you need to deploy it to a facsimile of what you'll be running in production. There, you can pound the hell out of it and get some real data you can actually do something with. Trying to profile your app in development is just a total waste of time.

Chris Pratt
  • 232,153
  • 36
  • 385
  • 444
  • I use only VS and Google Chrome Browser with one tab. Yes, i have 4 GB of RAM. But i think that 100 rows in table are not so difficult for the system – Anna Jun 07 '16 at 17:10