locked
Strange performance issues after mirror failover in SQL Server 2008R2 RRS feed

  • Question

  • I'm working on trying to resolve some performance issues that have cropped up in very strong correlation with a failover test we ran recently.  The test involved failing over to the new mirror partner, which is a VM.  After we failed back to the original server, we started seeing some issues which were not there previously.

    I have a set of symptoms, but it's not clear which ones are caused by or causing the problem. For instance, one small, high activity table started seeing deadlocking frequently, where previously there was none.  A process which updates data once a day, has started reaching a timeout, where previously it had no issues.

    CPU usage is up by about about 2x. Soft memory faults are up by a factor of 2-3x.

    I haven't found any causes for all these things, or why failing over the server would cause this to appear.  There doesn't appear to be memory pressure in SQL(cache hit ratios are in the 99% range, and buffer page life is long). It doesn't appear to be mirror performance, sync is maintained well with 1ms or less of backlog.

    Any ideas why I'm seeing these widespread changes in performance?

    Thank you!

    Wednesday, September 11, 2013 7:07 PM

All replies

  • >>>After we failed back to the original server, we started seeing some issues which were not there previously.

    That means you are backed to the principal and seen issues that have not seen before fail over?

    You say it is high activities... Is that possible some blocking?

    >>>>CPU usage is up by about about 2x.

    ---This first thing to check if CPU is at 100% is to look for parallel queries:

    -- Tasks running in parallel (filtering out MARS requests below):
    select * from sys.dm_os_tasks as t
     where t.session_id in (
       select t1.session_id
        from sys.dm_os_tasks as t1
       group by t1.session_id
      having count(*) > 1
      and min(t1.request_id) = max(t1.request_id));

    -- Requests running in parallel:
     select *
       from sys.dm_exec_requests as r
       join (
               select t1.session_id, min(t1.request_id)
              from sys.dm_os_tasks as t1
             group by t1.session_id
            having count(*) > 1
               and min(t1.request_id) = max(t1.request_id)
          ) as t(session_id, request_id)
         on r.session_id = t.session_id
        and r.request_id = t.request_id;


    Best Regards,Uri Dimant SQL Server MVP, http://sqlblog.com/blogs/uri_dimant/

    MS SQL optimization: MS SQL Development and Optimization
    MS SQL Blog: Large scale of database and data cleansing
    Remote DBA Services: Improves MS SQL Database Performance

    Thursday, September 12, 2013 5:47 AM
  • Well, I don't get parallel queries showing up so far, but I do get a parallel request once in a while.  The deadlocking in particular happens sporadically, but multiple times throughout the day, on no discernible pattern that I have noticed. The CPU usage on the other hand is consistently about double what it was, although I'm not 100% certain that is a symptom either. I should clarify that double doesn't mean it's high, it puts it around the 20-30% mark.

    I haven't noticed any unusual blocking, but I've been focused on trying to address the deadlocks.  I'll keep an eye out for it though.

    Thanks!

    Friday, September 13, 2013 1:46 PM
  • Hi,

    Does the problem persist if you pause mirroring?

    Nearly everything you've said; deadlocking, CPU ramp, timeouts, smacks of indexes and/or statistics needing rebuilding/updating. Has that been done recently?


    Thanks, Andrew

    Friday, September 13, 2013 3:03 PM
  • Can you post the deadlock output?

    Best Regards,Uri Dimant SQL Server MVP, http://sqlblog.com/blogs/uri_dimant/

    MS SQL optimization: MS SQL Development and Optimization
    MS SQL Blog: Large scale of database and data cleansing
    Remote DBA Services: Improves MS SQL Database Performance

    Sunday, September 15, 2013 7:17 AM
  • Hi,

    Does the problem persist if you pause mirroring?

    Nearly everything you've said; deadlocking, CPU ramp, timeouts, smacks of indexes and/or statistics needing rebuilding/updating. Has that been done recently?


    Thanks, Andrew

    I haven't yet tried pausing the mirror, I did try running the database in question in high performance mode, but that seemed to have no effect.

    The database and table in question are very small, only 30-40K rows typically, but if high traffic.  I did do some manual stats updates and flagged the sproc that shows up in many deadlocks for recompiling, but it didn't seemed to affect the issue at all.  I also looked at the indexes, and in one case it seemed like an index might help so I added one on a test server.  But even then, it was still just getting scanned, I assume because the table was just too small for the indexes to help more then hinder.

    But pausing is something I've been considering to see if it helps. I may bump that up as a test.

    Thanks!

    Monday, September 16, 2013 5:31 PM
  • There are several variations of the deadlocks, but there appear to always appear one of 2 queries.  One of the queries is a dynamic SQL update statement, the other is an update contained in a sproc.  Here's an example deadlock graph.

    <deadlock-list>
     <deadlock victim="process29f1f3b88">
      <process-list>
       <process id="process29f1f3b88" taskpriority="0" logused="0" waitresource="PAGE: 5:1:399" waittime="3172" ownerId="2264754373" transactionname="UPDATE" lasttranstarted="2013-09-11T08:13:34.403" XDES="0x35ae643b0" lockMode="IU" schedulerid="6" kpid="10148" status="suspended" spid="665" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2013-09-11T08:13:34.403" lastbatchcompleted="2013-09-11T08:13:34.403" clientapp=".Net SqlClient Data Provider" hostname="SCAPP07" hostpid="98168" loginname="scsession" isolationlevel="read committed (2)" xactid="2264754373" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
        <executionStack>
         <frame procname="scSession.httpsession.spInsertOrRefreshSession" line="33" stmtstart="2390" stmtend="2660" sqlhandle="0x0300050059ed607f97f80b01409e00000100000000000000">
    UPDATE httpsession.SessionState
             SET AccessTime = @createTime
             WHERE CookieValue = @cookieValue;     </frame>
        </executionStack>
        <inputbuf>
    Proc [Database Id = 5 Object Id = 2137058649]    </inputbuf>
       </process>
       <process id="process33087d288" taskpriority="0" logused="0" waitresource="KEY: 5:72057594038452224 (c0830788f789)" waittime="1263" ownerId="2264752024" transactionguid="0x3a879fe6eab90448b2a2fb6b25cd60b9" transactionname="user_transaction" lasttranstarted="2013-09-11T08:13:33.950" XDES="0x46c671620" lockMode="U" schedulerid="7" kpid="14572" status="suspended" spid="82" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2013-09-11T08:13:34.040" lastbatchcompleted="2013-09-11T08:13:34.040" clientapp=".Net SqlClient Data Provider" hostname="SCAPP07" hostpid="94972" loginname="scsession" isolationlevel="read uncommitted (1)" xactid="2264752024" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
        <executionStack>
         <frame procname="adhoc" line="1" stmtstart="146" sqlhandle="0x02000000db3a3c071084a50d284b8b0bb0271e6c4f9fceed">
    UPDATE ss
                                           SET ss.Value = @value
                                              , ss.AccessTime = @accessTime
                                           FROM httpsession.SessionState AS ss
                                           WHERE ss.CookieValue = @cookieValue     </frame>
         <frame procname="unknown" line="1" sqlhandle="0x000000000000000000000000000000000000000000000000">
    unknown     </frame>
        </executionStack>
        <inputbuf>
    (@cookieValue nvarchar(32),@value nvarchar(560),@accessTime nvarchar(10))UPDATE ss
                                           SET ss.Value = @value
                                              , ss.AccessTime = @accessTime
                                           FROM httpsession.SessionState AS ss
                                           WHERE ss.CookieValue = @cookieValue    </inputbuf>
       </process>
       <process id="process402072088" taskpriority="0" logused="236" waitresource="PAGE: 5:1:399" waittime="1136" ownerId="2264751964" transactionguid="0xfb5580270c517f488fc22293f73c19a6" transactionname="user_transaction" lasttranstarted="2013-09-11T08:13:33.937" XDES="0x3fe11f620" lockMode="IU" schedulerid="1" kpid="16304" status="suspended" spid="153" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2013-09-11T08:13:36.450" lastbatchcompleted="2013-09-11T08:13:36.450" clientapp=".Net SqlClient Data Provider" hostname="SCAPP07" hostpid="43872" loginname="scsession" isolationlevel="read uncommitted (1)" xactid="2264751964" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
        <executionStack>
         <frame procname="scSession.httpsession.spInsertOrRefreshSession" line="33" stmtstart="2390" stmtend="2660" sqlhandle="0x0300050059ed607f97f80b01409e00000100000000000000">
    UPDATE httpsession.SessionState
             SET AccessTime = @createTime
             WHERE CookieValue = @cookieValue;     </frame>
        </executionStack>
        <inputbuf>
    Proc [Database Id = 5 Object Id = 2137058649]    </inputbuf>
       </process>
      </process-list>
      <resource-list>
       <pagelock fileid="1" pageid="399" dbid="5" objectname="scSession.httpsession.SessionState" id="lock5feb84600" mode="U" associatedObjectId="72057594041466880">
        <owner-list>
         <owner id="process33087d288" mode="U"/>
        </owner-list>
        <waiter-list>
         <waiter id="process29f1f3b88" mode="IU" requestType="wait"/>
        </waiter-list>
       </pagelock>
       <keylock hobtid="72057594038452224" dbid="5" objectname="scSession.httpsession.SessionState" indexname="PK_SessionState" id="lock4500c4c80" mode="X" associatedObjectId="72057594038452224">
        <owner-list>
         <owner id="process402072088" mode="X"/>
        </owner-list>
        <waiter-list>
         <waiter id="process33087d288" mode="U" requestType="wait"/>
        </waiter-list>
       </keylock>
       <pagelock fileid="1" pageid="399" dbid="5" objectname="scSession.httpsession.SessionState" id="lock5feb84600" mode="U" associatedObjectId="72057594041466880">
        <owner-list/>
        <waiter-list>
         <waiter id="process402072088" mode="IU" requestType="wait"/>
        </waiter-list>
       </pagelock>
      </resource-list>
     </deadlock>
    </deadlock-list>
    

    Tuesday, September 17, 2013 1:46 PM