locked
Non-yielding scheduler errors and connection timeouts daily RRS feed

  • Question

  • SQL 2008 Standard edition, roughly 250 databases on the server (though this problem has occurred with all but one offline)

    A client's SQL server is logging Non-yielding Scheduler errors and generating a minidump around the same times daily.  These are logged repeatedly and the kernel time increases slightly each time.  There is no noticable spike in CPU/memory load, however, and the only hardware bottleneck we were seeing at the time was disk IO on the log drive (SAN).   Those drives were upgraded and the iops, % disk time and disk queue length have dropped to reasonable levels, but the non-yielding errors persist.   These errors also correspond with intermittent connection issues, which log errors like "The client was unable to reuse a session with SPID 153, which had been reset for connection pooling",  that usually persist for about an hour and clear up on their own.  

    The things I've read on the error point to log IO issues but I cant confirm thats the case based on any stats in perfmon or on the SAN itself.  We have not been able to consistently replicate the problem and it doesn't always happen each day, but the times are consistent between occurrances.  I've ruled out any SQL jobs running at these times, and in the example below the only thing happening before hand was a CheckDB job.  I have little visibility into what the application is doing when this occurs and I'm not entirely sure what to even look for for a cause from that end. 

    Examples from the log are included below.  Has anyone run into this before that can offer any suggestions for a possible cause?

     

    2011-01-11 00:00:04.25 spid21s     This instance of SQL Server has been using a process ID of 2068 since 1/10/2011 10:17:43 PM (local) 1/11/2011 3:17:43 AM (UTC). This is an informational message only; no user action is required.

    2011-01-11 00:00:20.18 spid181     DBCC CHECKDB (dbname1) WITH physical_only executed by DOMAIN\UserA found 0 errors and repaired 0 errors. Elapsed time: 0 hours 0 minutes 33 seconds.  Internal database snapshot has split point LSN = 0004f06e:0000007e:0001 and first LSN = 0004f06e:0000007d:0001.

    2011-01-11 00:00:39.57 spid181     DBCC CHECKDB (dbname2) WITH physical_only executed by DOMAIN\UserA found 0 errors and repaired 0 errors. Elapsed time: 0 hours 0 minutes 12 seconds.  Internal database snapshot has split point LSN = 000008da:00000022:0001 and first LSN = 000008da:00000021:0001.

    2011-01-11 00:00:51.49 spid181     6 transactions rolled forward in database 'dbname' (10). This is an informational message only. No user action is required.

    2011-01-11 00:00:51.56 spid181     0 transactions rolled back in database 'dbname' (10). This is an informational message only. No user action is required.

    2011-01-11 00:01:12.21 Server      Using 'dbghelp.dll' version '4.0.5'

    2011-01-11 00:01:12.44 Server      ***Unable to get thread context for spid 0

    2011-01-11 00:01:12.44 Server      * *******************************************************************************

    2011-01-11 00:01:12.44 Server      *

    2011-01-11 00:01:12.44 Server      * BEGIN STACK DUMP:

    2011-01-11 00:01:12.44 Server      *   01/11/11 00:01:12 spid 2656

    2011-01-11 00:01:12.44 Server      *

    2011-01-11 00:01:12.44 Server      * Non-yielding Scheduler

    2011-01-11 00:01:12.44 Server      *

    2011-01-11 00:01:12.44 Server      * *******************************************************************************

    2011-01-11 00:01:12.44 Server      Stack Signature for the dump is 0x00000221

    2011-01-11 00:01:15.62 Server      External dump process return code 0x20000001.

    External dump process returned no errors.

     

    2011-01-11 00:01:15.62 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 78 ms, user 31 ms. Process Utilization 4%. System Idle 91%. Interval: 70109 ms.

    2011-01-11 00:01:36.97 spid181     DBCC CHECKDB (dbname3) WITH physical_only executed by DOMAIN\UserA found 0 errors and repaired 0 errors. Elapsed time: 0 hours 0 minutes 49 seconds.  Internal database snapshot has split point LSN = 0007bf21:00000065:0006 and first LSN = 0007bf21:0000005c:0007.

    2011-01-11 00:02:01.10 spid181     DBCC CHECKDB (dbname4) WITH physical_only executed by DOMAIN\UserA found 0 errors and repaired 0 errors. Elapsed time: 0 hours 0 minutes 16 seconds.  Internal database snapshot has split point LSN = 0000054c:00000028:0001 and first LSN = 0000054c:00000027:0001.

    2011-01-11 00:02:15.67 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 93 ms, user 62 ms. Process Utilization 4%. System Idle 93%. Interval: 133625 ms.

    2011-01-11 00:02:39.11 spid181     5 transactions rolled forward in database 'dbname6' (10). This is an informational message only. No user action is required.

    2011-01-11 00:02:39.12 spid181     0 transactions rolled back in database 'dbname6' (10). This is an informational message only. No user action is required.

    2011-01-11 00:03:15.71 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 109 ms, user 62 ms. Process Utilization 4%. System Idle 93%. Interval: 193656 ms.

    2011-01-11 00:03:44.50 spid181     DBCC CHECKDB (dbname5) WITH physical_only executed by DOMAIN\UserA found 0 errors and repaired 0 errors. Elapsed time: 0 hours 1 minutes 17 seconds.  Internal database snapshot has split point LSN = 0004ac9c:00000188:000a and first LSN = 0004ac9c:00000182:0004.

    2011-01-11 00:04:15.75 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 125 ms, user 78 ms. Process Utilization 4%. System Idle 94%. Interval: 253703 ms.

    2011-01-11 00:05:15.79 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 171 ms, user 125 ms. Process Utilization 3%. System Idle 94%. Interval: 313750 ms.

    2011-01-11 00:06:15.83 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 203 ms, user 140 ms. Process Utilization 3%. System Idle 95%. Interval: 373781 ms.

    2011-01-11 00:06:50.12 spid582     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:06:50.12 spid582     The client was unable to reuse a session with SPID 582, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:07:15.87 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 250 ms, user 187 ms. Process Utilization 2%. System Idle 95%. Interval: 433828 ms.

    2011-01-11 00:08:15.92 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 250 ms, user 234 ms. Process Utilization 2%. System Idle 96%. Interval: 493875 ms.

    2011-01-11 00:09:15.96 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 375 ms, user 328 ms. Process Utilization 2%. System Idle 96%. Interval: 553906 ms.

    2011-01-11 00:10:16.00 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 437 ms, user 406 ms. Process Utilization 2%. System Idle 96%. Interval: 613953 ms.

    2011-01-11 00:11:16.04 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 515 ms, user 421 ms. Process Utilization 2%. System Idle 96%. Interval: 674000 ms.

    2011-01-11 00:12:16.07 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 609 ms, user 437 ms. Process Utilization 2%. System Idle 96%. Interval: 734031 ms.

    2011-01-11 00:13:16.12 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 625 ms, user 484 ms. Process Utilization 2%. System Idle 96%. Interval: 794078 ms.

    2011-01-11 00:14:16.17 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 687 ms, user 500 ms. Process Utilization 2%. System Idle 96%. Interval: 854125 ms.

    2011-01-11 00:15:16.20 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 718 ms, user 531 ms. Process Utilization 2%. System Idle 97%. Interval: 914156 ms.

    2011-01-11 00:16:16.25 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 734 ms, user 562 ms. Process Utilization 1%. System Idle 97%. Interval: 974203 ms.

    2011-01-11 00:17:16.29 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 734 ms, user 593 ms. Process Utilization 1%. System Idle 97%. Interval: 1034234 ms.

    2011-01-11 00:18:16.32 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 765 ms, user 671 ms. Process Utilization 1%. System Idle 97%. Interval: 1094281 ms.

    2011-01-11 00:19:16.37 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 796 ms, user 703 ms. Process Utilization 1%. System Idle 97%. Interval: 1154328 ms.

    2011-01-11 00:20:16.40 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 890 ms, user 718 ms. Process Utilization 1%. System Idle 97%. Interval: 1214359 ms.

    2011-01-11 00:21:16.46 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 953 ms, user 796 ms. Process Utilization 1%. System Idle 97%. Interval: 1274406 ms.

    2011-01-11 00:22:16.50 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1093 ms, user 828 ms. Process Utilization 1%. System Idle 97%. Interval: 1334453 ms.

    2011-01-11 00:23:16.54 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1203 ms, user 875 ms. Process Utilization 1%. System Idle 97%. Interval: 1394500 ms.

    2011-01-11 00:24:16.58 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1265 ms, user 953 ms. Process Utilization 1%. System Idle 97%. Interval: 1454531 ms.

    2011-01-11 00:25:16.62 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1421 ms, user 953 ms. Process Utilization 1%. System Idle 97%. Interval: 1514578 ms.

    2011-01-11 00:26:16.67 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1609 ms, user 1046 ms. Process Utilization 2%. System Idle 97%. Interval: 1574625 ms.

    2011-01-11 00:27:16.71 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1703 ms, user 1093 ms. Process Utilization 2%. System Idle 97%. Interval: 1634671 ms.

    2011-01-11 00:28:16.75 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1750 ms, user 1140 ms. Process Utilization 2%. System Idle 97%. Interval: 1694703 ms.

    2011-01-11 00:29:16.79 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1812 ms, user 1250 ms. Process Utilization 2%. System Idle 96%. Interval: 1754750 ms.

    2011-01-11 00:30:16.83 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 1875 ms, user 1281 ms. Process Utilization 2%. System Idle 97%. Interval: 1814796 ms.

    2011-01-11 00:31:16.88 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2000 ms, user 1359 ms. Process Utilization 2%. System Idle 96%. Interval: 1874843 ms.

    2011-01-11 00:32:16.92 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2093 ms, user 1437 ms. Process Utilization 2%. System Idle 96%. Interval: 1934875 ms.

    2011-01-11 00:33:16.97 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2171 ms, user 1484 ms. Process Utilization 2%. System Idle 96%. Interval: 1994921 ms.

    2011-01-11 00:34:17.00 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2359 ms, user 1562 ms. Process Utilization 2%. System Idle 96%. Interval: 2054968 ms.

    2011-01-11 00:35:17.05 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2531 ms, user 1671 ms. Process Utilization 2%. System Idle 96%. Interval: 2115000 ms.

    2011-01-11 00:36:17.08 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2687 ms, user 1718 ms. Process Utilization 2%. System Idle 96%. Interval: 2175046 ms.

    2011-01-11 00:37:17.13 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2734 ms, user 1812 ms. Process Utilization 2%. System Idle 96%. Interval: 2235093 ms.

    2011-01-11 00:38:17.17 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2796 ms, user 1859 ms. Process Utilization 2%. System Idle 96%. Interval: 2295125 ms.

    2011-01-11 00:39:17.21 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 2875 ms, user 1906 ms. Process Utilization 2%. System Idle 96%. Interval: 2355171 ms.

    2011-01-11 00:40:17.26 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 3000 ms, user 1968 ms. Process Utilization 2%. System Idle 96%. Interval: 2415218 ms.

    2011-01-11 00:41:17.31 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 3140 ms, user 2031 ms. Process Utilization 2%. System Idle 96%. Interval: 2475250 ms.

    2011-01-11 00:42:17.35 Server      Process 0:0:0 (0xa68) Worker 0x00EDE0D8 appears to be non-yielding on Scheduler 2. Thread creation time: 12939189420203. Approx Thread CPU Used: kernel 3203 ms, user 2109 ms. Process Utilization 2%. System Idle 96%. Interval: 2535296 ms.

    2011-01-11 00:42:38.20 spid153     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:42:38.20 spid153     The client was unable to reuse a session with SPID 153, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:42:38.20 spid163     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:42:38.20 spid163     The client was unable to reuse a session with SPID 163, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:42:38.20 spid268     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:42:38.20 spid268     The client was unable to reuse a session with SPID 268, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:42:38.23 spid134     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:42:38.23 spid134     The client was unable to reuse a session with SPID 134, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:42:38.23 spid160     Error: 18056, Severity: 20, State: 29.

    2011-01-11 00:42:38.23 spid160     The client was unable to reuse a session with SPID 160, which had been reset for connection pooling. The failure ID is 29. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.

    2011-01-11 00:42:38.23 spid166     Error: 18056, Severity: 20, State: 29.

    etc...

    Friday, January 14, 2011 2:27 PM

Answers

  • You need to take a look at the Dumps generated before we can think of possibilities as there could be a number of reasons.

    Would suggest to open a case with Product Support, so that they can help you. You can refer this article for a whole lot of information on scheduler issues.

    http://technet.microsoft.com/en-sg/library/cc917684(en-us).aspx

    Regards 

    Ashwin Menon

    Tuesday, January 18, 2011 3:24 PM

All replies

  • the way SQL works the SQLOS, an internal process, to SQL Server manages threads for SQL Server.  A non-yeilding scheduler is a case where something has gone wrong, and the thread is not releasing. In many cases this can bring down a server.

    I would recommend contacting PSS and having them take a look at your stack dumps.

    This also could be a symptom of something that is fixed in a SP or CU.  What is the build number for your 2008 server?


    SQLBalls: Blog| Twitter | LinkedIn
    Friday, January 14, 2011 4:55 PM
  • Microsoft SQL Server 2008 (SP2) - 10.0.4000.0 (Intel X86)   Sep 16 2010 20:09:22   Copyright (c) 1988-2008 Microsoft Corporation  Standard Edition on Windows NT 5.2 <X86> (Build 3790: Service Pack 2) 


    There was a hotfix for a similar non-yielding scheduler error that was included in SP2 but after applying that pack the error still persists.  What would you suggest looking for "going wrong?"  Is this the result of something from the application side, i.e. the order/volume of transactions running or an internal problem with SQL itself?

    Tuesday, January 18, 2011 2:45 PM
  • You need to take a look at the Dumps generated before we can think of possibilities as there could be a number of reasons.

    Would suggest to open a case with Product Support, so that they can help you. You can refer this article for a whole lot of information on scheduler issues.

    http://technet.microsoft.com/en-sg/library/cc917684(en-us).aspx

    Regards 

    Ashwin Menon

    Tuesday, January 18, 2011 3:24 PM
  • am facing this issue on SQL Server 2008 R2 Standard 64-bit Edition.

     

    I found a Microsoft KB and the Fix appealing for 2005 and 2008. Hope this helps other running on the Severs detailed in "Applied TO" section

    http://support.microsoft.com/kb/974205

    But am trying trying to see if there is a fix for 2008 R2.

     

    Can some one please help

     

    Thanks,

    Praneeth


    praneeth
    Monday, June 27, 2011 2:51 PM
  • Also please refer the belw KB, if it helps

    http://support.microsoft.com/kb/2344600


    praneeth
    Monday, June 27, 2011 2:58 PM
  • Friday, August 24, 2012 7:08 AM
  • Just in case somebody searches for this issue and is fully patched.... Check if a DBCC check is running at the same time. If so, then check if DBCC snapshot files are excluded from a virus scan. Our CISCO AMP scanning the alternate data stream prevented database connections and generated non-yielding scheduler errors. Excluding the mdf files is not enough.

    Microsoft recommended exclusions


    Randy in Marin

    Monday, January 6, 2020 5:31 PM