Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

This problem has been haunting me for a while but I actually fixed the queries that caused the problems (after I finally found them) but i'm curious if it's an SQL Process that's the underlying problem our that our raidcontrollers are shit or what the problem truely is. So here's the scenario that's been bothering us.

@ 11:10~ and 01:10~ the server would give these IO errors, even through Remote desktop the servers would fail, management studio would give timeouts, everything would point towards imminent failure of the cluster.

(The servers are identical, we run Windows Server 2012 standard, clustered in an AlwaysOn running SQL Server 2012 Enterprise edition).

Around 5-15 minutes later, the servers would come back to live (without anything in the eventlogs except for the Event ID 833 which is the "well known": SQL Server has encountered 16870 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [E:\XXXXXXXX.mdf] in database [XXXXX] (10). The OS file handle is 0x0000000000001284. The offset of the latest long I/O is: 0x0000041fb3c000).

Now I was running profilers to find out which queries were running, doing anything I could to figure out what would cause the servers to just freeze up and refuse to service properly. The event log aims towards a specific Database to I searched in that direction and yesterday I found a table that looked odd to me.

The specific table was 11 gigs large, had indexes worth 23 gigs (haven't looked into those yet but that seemed wrong to me) and had 80 million records. Considering the table should hold around 2 million and be growing relatively slowly this sparked my interested and I found three stored procedures which fill this table.

All three storedprocedures had flaws which made them insert not a few hundred records but over 500.000 each time they ran. (These are now fixed so the issue doesn't present itself but I feel there is an underlying problem here).

These stored procedures would run @ 09:00 and 23:00 (excatly 2 hours before the problems occurred). The procedures themselves would take around 5 minutes to run to completion.

Now I'm wondering why it would take the servers two hours to start dying on me after the actual storedprocedures in question would already have been done. I don't run any index maintenance at that point, or anything else for that matter (it's the first thing I checked for). For all I know nothing runs @ the specific times. Could it be SQL Server does some 'self maintenance' and notices that some indexes need to be defragmentated or something even if I haven't asked for any such thing?

Could it be our raidcontrollers (or even the SSD's that are connected to them) that are flawed and after A LOT of activity decide to show signs of degration after 2 hours?

I simply can not explain this behavior and I'm worried our production servers might be unreliable (which would suck since they're around 4 months old). Now i've fixed this issue last evening, and for 24 hours we haven't had this problem (I wouldn't call it 'resolved' unless it's been stable for multiple days) but I'm still very curious what the hell my servers are doing.

share|improve this question
    
Sounds like maybe a hardware issue to me, I'd probably start by having a look at the server vendors documentation for any updated firmware or drivers available, especially if they're IBMs as we've had loads of issues caused by crappy firmware with these. –  steoleary Oct 17 '13 at 16:19
    
Are your memory settings okay (i.e., there is free memory on each node)? –  Jon Seigel Oct 17 '13 at 16:28
    
Ye, we've got spare memory in both nodes, I'll check when at work tomorrow, I could possibly limit the SQL to not take all memory so there is some free. Pretty sure that I did that already. What I don't get is how 2 hours AFTER the storedprocedure completes... The servers have IO problems... I just can't wrap my head around that. –  F.B. ten Kate Oct 17 '13 at 17:43
    
Please read this and this. Both MSDN articles are trying to help you find this long IO error. Might find something helpful. –  Marian Oct 17 '13 at 21:23
    
Will look at those two, but I'm curious (i'm not a DBA) if there is anyone who knows why SQL Server (it has to be SQL Server no other processes run on these servers) would cause huge IO just around 2 Hours after updating a very large table. WITHOUT Explicit index maintenance or something, is there some implicit maintenance I'm not aware of causing this? –  F.B. ten Kate Oct 18 '13 at 6:29

3 Answers 3

up vote 1 down vote accepted

BOL refers to 833 event ID as :

This problem can be caused system performance issues, hardware errors, firmware errors, device driver problems, or filter driver intervention in the IO process.

What it means is that

  • SQL server is doing more I/O's that what the disk subsystem can handle.
  • There could be some rogue process running on the system that is saturating the disks with all the I/O requests.

Below is the approach I would follow:

Troubleshoot using Wait Statistics - DMV's

WITH [Waits] AS
    (SELECT
        [wait_type],
        [wait_time_ms] / 1000.0 AS [WaitS],
        ([wait_time_ms] - [signal_wait_time_ms]) / 1000.0 AS [ResourceS],
        [signal_wait_time_ms] / 1000.0 AS [SignalS],
        [waiting_tasks_count] AS [WaitCount],
        100.0 * [wait_time_ms] / SUM ([wait_time_ms]) OVER() AS [Percentage],
        ROW_NUMBER() OVER(ORDER BY [wait_time_ms] DESC) AS [RowNum]
    FROM sys.dm_os_wait_stats
    WHERE [wait_type] NOT IN (
        N'CLR_SEMAPHORE',    N'LAZYWRITER_SLEEP',
        N'RESOURCE_QUEUE',   N'SQLTRACE_BUFFER_FLUSH',
        N'SLEEP_TASK',       N'SLEEP_SYSTEMTASK',
        N'WAITFOR',          N'HADR_FILESTREAM_IOMGR_IOCOMPLETION',
        N'CHECKPOINT_QUEUE', N'REQUEST_FOR_DEADLOCK_SEARCH',
        N'XE_TIMER_EVENT',   N'XE_DISPATCHER_JOIN',
        N'LOGMGR_QUEUE',     N'FT_IFTS_SCHEDULER_IDLE_WAIT',
        N'BROKER_TASK_STOP', N'CLR_MANUAL_EVENT',
        N'CLR_AUTO_EVENT',   N'DISPATCHER_QUEUE_SEMAPHORE',
        N'TRACEWRITE',       N'XE_DISPATCHER_WAIT',
        N'BROKER_TO_FLUSH',  N'BROKER_EVENTHANDLER',
        N'FT_IFTSHC_MUTEX',  N'SQLTRACE_INCREMENTAL_FLUSH_SLEEP',
        N'DIRTY_PAGE_POLL',  N'SP_SERVER_DIAGNOSTICS_SLEEP')
    )
SELECT
    [W1].[wait_type] AS [WaitType],
    CAST ([W1].[WaitS] AS DECIMAL(14, 2)) AS [Wait_S],
    CAST ([W1].[ResourceS] AS DECIMAL(14, 2)) AS [Resource_S],
    CAST ([W1].[SignalS] AS DECIMAL(14, 2)) AS [Signal_S],
    [W1].[WaitCount] AS [WaitCount],
    CAST ([W1].[Percentage] AS DECIMAL(4, 2)) AS [Percentage],
    CAST (([W1].[WaitS] / [W1].[WaitCount]) AS DECIMAL (14, 4)) AS [AvgWait_S],
    CAST (([W1].[ResourceS] / [W1].[WaitCount]) AS DECIMAL (14, 4)) AS [AvgRes_S],
    CAST (([W1].[SignalS] / [W1].[WaitCount]) AS DECIMAL (14, 4)) AS [AvgSig_S]
FROM [Waits] AS [W1]
INNER JOIN [Waits] AS [W2]
    ON [W2].[RowNum] <= [W1].[RowNum]
GROUP BY [W1].[RowNum], [W1].[wait_type], [W1].[WaitS],
    [W1].[ResourceS], [W1].[SignalS], [W1].[WaitCount], [W1].[Percentage]
HAVING SUM ([W2].[Percentage]) - [W1].[Percentage] < 95; -- percentage threshold
GO

Look at the pending I/O's

SELECT database_id
    ,file_id
    ,io_stall
    ,io_pending_ms_ticks
    ,scheduler_address
FROM sys.dm_io_virtual_file_stats(NULL, NULL) t1
    ,sys.dm_io_pending_io_requests AS t2
WHERE t1.file_handle = t2.io_handle

Below are PERFMON counters that will help you:

  • Avg. Disk sec/Transfer => Time taken to perform the I/O operation
  • Disk Bytes /sec => Total reads and writes to disk per second in bytes.
  • Process:IO Data Bytes/Sec => Total reads and writes to disk per second in bytes by each process.
  • Buffer Manager: Page Read/sec + Page Writes/sec =>Total reads and writes to disk per second in bytes by SQL Server process.

Also, sometimes such errors can also occur when a different Power Management scheme is selected for the server. So better check your Windows Power Plan setting, and make sure you are using the High Performance Power Plan.

All three storedprocedures had flaws which made them insert not a few hundred records but over 500.000 each time they ran. (These are now fixed so the issue doesn't present itself but I feel there is an underlying problem here).

If you are inserting a huge amount of data, then you need to refer to The Data Loading Performance Guide to cater your server for such operations e.g. enabling trace flag 610.

Note: Others have mentioned that Auto Update Stats might be causing it, which is also worth looking at, but I would primarily concentrate on finding out rouge process that is causing lots of Disk I/Os and checking the storage subsystem to see if all the divers, etc are up-to-date and is configured correctly.

Good reading links :

share|improve this answer

I might be teaching my grandmother to suck eggs here. If so, apologies.

DMVs (http://technet.microsoft.com/en-us/library/ms188754.aspx) could help you rule out a lot of things inside the RDMS. At the very least you'll be able to see what is running when and where... assuming the DBAs let you have access.

If the RDMS turns out not to be the culprit, you could look at enabling some PerfMon perf counters or event collectors to see if you can identify any driver or app that may be hitting your OS (http://technet.microsoft.com/en-us/library/cc749249.aspx).

share|improve this answer
    
I'll look into those, I've already run some perfmon's but these might be different and more usefull. –  F.B. ten Kate Oct 22 '13 at 11:38

You mention that the stored procedures should be done. My guess is that without any transaction marshaling the data is accumulated and then finally committed about 2 hours later.

You mention you ran profiler, but I would look at Adam Machanic's sp_whoisactive at http://sqlblog.com/blogs/adam_machanic/archive/tags/who+is+active/default.aspax

It will give you all sorts of information.

share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.