ekm51
asked on
SQL server hangs on scheduled maintence plan
Our SQL server is hanging and crashing every night. It looks like it happens when the schedule backup job is suppose to start. Here are the sql logs:
Date Source Message
2006-12-07 10:25:53.60 server Microsoft SQL Server 2000 - 8.00.2039 (Intel X86) ...
2006-12-07 10:25:53.62 server Logging SQL Server messages in file 'e:\Program Files\Microsoft SQL Server\MSSQ
2006-12-07 10:25:53.62 server Server Process ID is 1824.
2006-12-07 10:25:53.62 server All rights reserved.
2006-12-07 10:25:53.62 server Copyright (C) 1988-2002 Microsoft Corporation.
2006-12-07 10:25:53.67 server SQL Server is starting at priority class 'normal'(1 CPU detected).
2006-12-07 10:25:54.03 server SQL Server configured for thread mode processing.
2006-12-07 10:25:54.04 server Using dynamic lock allocation. [2500] Lock Blocks, [5000] Lock Owner Blocks.
2006-12-07 10:25:54.15 server Attempting to initialize Distributed Transaction Coordinator.
2006-12-07 10:25:55.28 spid3 Starting up database 'master'.
2006-12-07 10:25:59.01 spid3 Recovery is checkpointing database 'master' (1)
2006-12-07 10:25:59.01 spid3 0 transactions rolled back in database 'master' (1).
2006-12-07 10:25:59.45 spid5 Starting up database 'model'.
2006-12-07 10:25:59.45 server SQL server listening on 127.0.0.1: 1433.
2006-12-07 10:25:59.45 server SQL server listening on 192.168.2.84: 1433.
2006-12-07 10:25:59.45 server Using 'SSNETLIB.DLL' version '8.0.2039'.
2006-12-07 10:25:59.50 spid3 Server name is 'SSQL2000'.
2006-12-07 10:25:59.53 spid9 Starting up database 'pubs'.
2006-12-07 10:25:59.53 spid8 Starting up database 'msdb'.
2006-12-07 10:25:59.56 spid11 Starting up database 'cp2'.
2006-12-07 10:25:59.56 spid10 Starting up database 'Northwind'.
2006-12-07 10:25:59.62 server SQL Server is ready for client connections
2006-12-07 10:25:59.62 server SQL server listening on TCP, Shared Memory, Named Pipes.
2006-12-07 10:25:59.76 spid5 Clearing tempdb database.
2006-12-07 10:26:00.28 spid9 Starting up database 'childplus'.
2006-12-07 10:26:00.45 spid10 Starting up database 'cp3'.
2006-12-07 10:26:00.68 spid8 23 transactions rolled forward in database 'msdb' (4).
2006-12-07 10:26:01.06 spid11 Starting up database 'distribution'.
2006-12-07 10:26:01.09 spid8 0 transactions rolled back in database 'msdb' (4).
2006-12-07 10:26:01.15 spid8 Recovery is checkpointing database 'msdb' (4)
2006-12-07 10:26:01.48 spid5 Starting up database 'tempdb'.
2006-12-07 10:26:01.70 spid11 36 transactions rolled forward in database 'distribution' (10).
2006-12-07 10:26:01.79 spid11 0 transactions rolled back in database 'distribution' (10).
2006-12-07 10:26:01.81 spid9 1 transactions rolled back in database 'childplus' (8).
2006-12-07 10:26:01.85 spid11 Recovery is checkpointing database 'distribution' (10)
2006-12-07 10:26:01.98 spid9 Recovery is checkpointing database 'childplus' (8)
2006-12-07 10:26:03.35 spid3 SQL global counter collection task is created.
2006-12-07 10:26:03.35 spid3 Recovery complete.
2006-12-07 10:26:03.42 spid3 Launched startup procedure 'sp_MSrepl_startup'
2006-12-07 10:26:04.56 spid52 Using 'xpsqlbot.dll' version '2000.80.2039' to execute extended stored procedur
2006-12-07 10:27:53.61 spid53 Using 'xpstar.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 10:37:45.75 spid52 Using 'xplog70.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 10:37:59.13 spid52 Starting up database 'distribution'.
2006-12-07 10:37:59.33 spid52 Non-clustered index restored for distribution.sysobjects.
2006-12-07 10:37:59.38 spid52 Non-clustered index restored for distribution.sysobjects.
2006-12-07 10:37:59.42 spid52 index restored for distribution.syscolumns.
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysfilegroups .
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysfulltextca talogs.
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysproperties .
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysusers.
2006-12-07 10:37:59.44 spid52 index restored for distribution.systypes.
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsnapshot_ag ents.
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsubscriber_ schedule.
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsubscriber_ info.
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSrepl_origin ators.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublication s.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublisher_d atabases.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublication _access.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSmerge_agent s.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSdistributio n_agents.
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSlogreader_a gents.
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSmerge_subsc riptions.
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSsubscriptio ns.
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSsync_states .
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSarticles.
2006-12-07 10:38:00.06 spid52 Using 'xprepl.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 23:45:24.71 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:50:05.70 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:52:25.95 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:55:32.54 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:56:26.82 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:00:45.49 spid1 SQL Server has encountered 2 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:06:36.69 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:12:07.51 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:15:58.19 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:19:28.69 spid2 SQL Server has encountered 4 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:24:29.43 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:30:10.42 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:39:33.04 server Sleeping until external dump process completes.
2006-12-08 00:39:53.93 server Timeout while waiting for external dump.
2006-12-08 00:40:57.16 server Stack Signature for the dump is 0x00000000
2006-12-08 00:40:57.16 server Resuming after waiting on external debug process for 20 seconds.
2006-12-08 00:42:12.30 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:42:12.30 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:44:07.41 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:44:07.41 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:46:37.90 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:46:37.90 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:48:48.15 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:48:48.15 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:51:18.65 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:51:18.65 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:53:54.17 spid2 SQL Server has encountered 2 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:55:28.95 server Process 2:0 (1b4) UMS Context 0x002973E0 appears to be non-yielding on Schedule
2006-12-08 00:55:28.95 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:58:34.95 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 01:02:35.68 spid2 SQL Server has encountered 3 occurrence(s) of IO requests taking longer than 15
Looked on the MS site and it said to install the lateset SP but we already have installed SP4.
Date Source Message
2006-12-07 10:25:53.60 server Microsoft SQL Server 2000 - 8.00.2039 (Intel X86) ...
2006-12-07 10:25:53.62 server Logging SQL Server messages in file 'e:\Program Files\Microsoft SQL Server\MSSQ
2006-12-07 10:25:53.62 server Server Process ID is 1824.
2006-12-07 10:25:53.62 server All rights reserved.
2006-12-07 10:25:53.62 server Copyright (C) 1988-2002 Microsoft Corporation.
2006-12-07 10:25:53.67 server SQL Server is starting at priority class 'normal'(1 CPU detected).
2006-12-07 10:25:54.03 server SQL Server configured for thread mode processing.
2006-12-07 10:25:54.04 server Using dynamic lock allocation. [2500] Lock Blocks, [5000] Lock Owner Blocks.
2006-12-07 10:25:54.15 server Attempting to initialize Distributed Transaction Coordinator.
2006-12-07 10:25:55.28 spid3 Starting up database 'master'.
2006-12-07 10:25:59.01 spid3 Recovery is checkpointing database 'master' (1)
2006-12-07 10:25:59.01 spid3 0 transactions rolled back in database 'master' (1).
2006-12-07 10:25:59.45 spid5 Starting up database 'model'.
2006-12-07 10:25:59.45 server SQL server listening on 127.0.0.1: 1433.
2006-12-07 10:25:59.45 server SQL server listening on 192.168.2.84: 1433.
2006-12-07 10:25:59.45 server Using 'SSNETLIB.DLL' version '8.0.2039'.
2006-12-07 10:25:59.50 spid3 Server name is 'SSQL2000'.
2006-12-07 10:25:59.53 spid9 Starting up database 'pubs'.
2006-12-07 10:25:59.53 spid8 Starting up database 'msdb'.
2006-12-07 10:25:59.56 spid11 Starting up database 'cp2'.
2006-12-07 10:25:59.56 spid10 Starting up database 'Northwind'.
2006-12-07 10:25:59.62 server SQL Server is ready for client connections
2006-12-07 10:25:59.62 server SQL server listening on TCP, Shared Memory, Named Pipes.
2006-12-07 10:25:59.76 spid5 Clearing tempdb database.
2006-12-07 10:26:00.28 spid9 Starting up database 'childplus'.
2006-12-07 10:26:00.45 spid10 Starting up database 'cp3'.
2006-12-07 10:26:00.68 spid8 23 transactions rolled forward in database 'msdb' (4).
2006-12-07 10:26:01.06 spid11 Starting up database 'distribution'.
2006-12-07 10:26:01.09 spid8 0 transactions rolled back in database 'msdb' (4).
2006-12-07 10:26:01.15 spid8 Recovery is checkpointing database 'msdb' (4)
2006-12-07 10:26:01.48 spid5 Starting up database 'tempdb'.
2006-12-07 10:26:01.70 spid11 36 transactions rolled forward in database 'distribution' (10).
2006-12-07 10:26:01.79 spid11 0 transactions rolled back in database 'distribution' (10).
2006-12-07 10:26:01.81 spid9 1 transactions rolled back in database 'childplus' (8).
2006-12-07 10:26:01.85 spid11 Recovery is checkpointing database 'distribution' (10)
2006-12-07 10:26:01.98 spid9 Recovery is checkpointing database 'childplus' (8)
2006-12-07 10:26:03.35 spid3 SQL global counter collection task is created.
2006-12-07 10:26:03.35 spid3 Recovery complete.
2006-12-07 10:26:03.42 spid3 Launched startup procedure 'sp_MSrepl_startup'
2006-12-07 10:26:04.56 spid52 Using 'xpsqlbot.dll' version '2000.80.2039' to execute extended stored procedur
2006-12-07 10:27:53.61 spid53 Using 'xpstar.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 10:37:45.75 spid52 Using 'xplog70.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 10:37:59.13 spid52 Starting up database 'distribution'.
2006-12-07 10:37:59.33 spid52 Non-clustered index restored for distribution.sysobjects.
2006-12-07 10:37:59.38 spid52 Non-clustered index restored for distribution.sysobjects.
2006-12-07 10:37:59.42 spid52 index restored for distribution.syscolumns.
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysfilegroups
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysfulltextca
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysproperties
2006-12-07 10:37:59.44 spid52 index restored for distribution.sysusers.
2006-12-07 10:37:59.44 spid52 index restored for distribution.systypes.
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsnapshot_ag
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsubscriber_
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSsubscriber_
2006-12-07 10:37:59.47 spid52 index restored for distribution.MSrepl_origin
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublication
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublisher_d
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSpublication
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSmerge_agent
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSdistributio
2006-12-07 10:37:59.48 spid52 index restored for distribution.MSlogreader_a
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSmerge_subsc
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSsubscriptio
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSsync_states
2006-12-07 10:37:59.50 spid52 index restored for distribution.MSarticles.
2006-12-07 10:38:00.06 spid52 Using 'xprepl.dll' version '2000.80.2039' to execute extended stored procedure
2006-12-07 23:45:24.71 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:50:05.70 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:52:25.95 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:55:32.54 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-07 23:56:26.82 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:00:45.49 spid1 SQL Server has encountered 2 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:06:36.69 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:12:07.51 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:15:58.19 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:19:28.69 spid2 SQL Server has encountered 4 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:24:29.43 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:30:10.42 spid2 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:39:33.04 server Sleeping until external dump process completes.
2006-12-08 00:39:53.93 server Timeout while waiting for external dump.
2006-12-08 00:40:57.16 server Stack Signature for the dump is 0x00000000
2006-12-08 00:40:57.16 server Resuming after waiting on external debug process for 20 seconds.
2006-12-08 00:42:12.30 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:42:12.30 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:44:07.41 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:44:07.41 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:46:37.90 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:46:37.90 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:48:48.15 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:48:48.15 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:51:18.65 server Process 54:0 (508) UMS Context 0x0029FD60 appears to be non-yielding on Schedul
2006-12-08 00:51:18.65 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:53:54.17 spid2 SQL Server has encountered 2 occurrence(s) of IO requests taking longer than 15
2006-12-08 00:55:28.95 server Process 2:0 (1b4) UMS Context 0x002973E0 appears to be non-yielding on Schedule
2006-12-08 00:55:28.95 server Error: 17883, Severity: 1, State: 0
2006-12-08 00:58:34.95 spid1 SQL Server has encountered 1 occurrence(s) of IO requests taking longer than 15
2006-12-08 01:02:35.68 spid2 SQL Server has encountered 3 occurrence(s) of IO requests taking longer than 15
Looked on the MS site and it said to install the lateset SP but we already have installed SP4.
ASKER
I was able to install:
http://support.microsoft.com/kb/899761
But I was not able to install the security update as it said I was running the wrong version. I tried installing all 3 as well but no success.
Interesting. 8.00.760 SP3 is the version I'm running (I got this by going into Enterprise Manager and examining the Properties of a particular server. What version do you see when you do the same?
ASKER
8.00.2040 (SP4)
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
ASKER
SP4 is suppose to contain the MS03-031 patch so i'm still outta luck. thx for the help anyways...
SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
http://www.dbtalk.net/microsoft-public-sqlserver-server/non-yielding-scheduler-0-a-255408.html
http://support.microsoft.com/kb/816840
http://support.microsoft.com/kb/815056
Since your service pack is up to date, it may be the security patch you are missing. This error is not a security error, but apparently they included code to fix it in the security path. It has to do with the scheduler waiting for a task that completed before it started listening (if I understand it correctly) due to a disk system that worked much faster than the original design allowed for.
Please let me know if this works :)