SSMS (manually) generated jobs run long, then fail.

  • Hello, I have a strange problem SQL, and I am spoiled by SQLs (usually) great logging and error reporting, but this one got me and I can't figure it out.

    So the problem is that simple jobs for taking backup and cleaning up, generated by maintenance plans, run for a long long time, and then fail. This happens to all the jobs that have manually been created using maintenance plans. If i create a job from scratch and enter the T-SQL my self, everything runs fine, for example:

    USE TESTDB

    GO

    BACKUP DATABASE TESTDB

    TO DISK = 'D:\Test\Test_Backup.bak'

    WITH FORMAT,

    MEDIANAME = 'Testbackups',

    NAME = 'Full Backup of TESTDB';

    GO

    If it take the same T-SQL and paste it into a subplan created within a maintenance plan using the Execute T-SQL Statement task, I also get the problem.

    So, that leads me to believe that this is not a permissions issue, at least not on the folders where i try to save and delete backup files or logfiles. It doesn't necessarily have anything to do with the SQL Server Agent being wonky in anyway either. However, something is up with the packages being created using Maintenance Plans, and it doesn't matter what tasks I use to make up the maint.plan, they all fail, from backup, to cleanups to index reorganizing and simple T-SQL executions.

    Even if the jobs execution fails at any step in any job created with a maintenance plan, whatever the task is supposed to do gets done. So that test plan i created to backup my testdb with the Execute T-SQL Statement task does create the file, but the step fails.

    Here is the recorded log from the Log File Browser for one of the jobs, this specific one executes a checkdb-task on all databases:[/b]

    Date07.05.2014 02:05:00

    LogJob History (MaintenancePlan.CheckDB & Indeksvedlikehold)

    Step ID1

    ServerCLUSTERNAME

    Job NameMaintenancePlan.CheckDB & Indeksvedlikehold

    Step NameCheckDB & Indeksvedlikehold

    Duration02:10:42

    Sql Severity0

    Sql Message ID0

    Operator Emailed

    Operator Net sent

    Operator Paged

    Retries Attempted0

    Message

    Executed as user: AD\sqlcluster_clustername. ...0.2100.60 for 64-bit Copyright (C) Microsoft Corporation. All rights reserved. Started: 02:05:00 Progress: 2014-05-07 02:05:01.10 Source: {0CE40B9F-E8F4-47FC-9AD3-505825081534} Executing query "DECLARE @GUID UNIQUEIDENTIFIER EXECUTE msdb..sp...".: 100% complete End Progress Progress: 2014-05-07 02:05:04.36 Source: Check Database Integrity Task Executing query "USE [DATABASE1] ".: 50% complete End Progress Progress: 2014-05-07 02:05:04.84 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE1') WITH NO_INFOMSGS ".: 100% complete End Progress Progress: 2014-05-07 02:05:04.85 Source: Check Database Integrity Task Executing query "USE [DATABASE2] ".: 50% complete End Progress Progress: 2014-05-07 02:05:06.25 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE2') WITH NO_INFOMSGS ".: 100% complete End Progress Progress: 2014-05-07 02:05:06.25 Source: Check Database Integrity Task Executing query "USE [DATABASE3] ".: 50% complete End Progress Progress: 2014-05-07 02:05:06.70 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE3') WITH NO_INFOMSGS ".: 100% complete End Progress Progress: 2014-05-07 02:05:06.71 Source: Check Database Integrity Task Executing query "USE [DATABASE4] ".: 50% complete End Progress Progress: 2014-05-07 02:05:07.67 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE4') WITH NO_INFOMSGS ".: 100% complete End Progress Progress: 2014-05-07 02:05:07.67 Source: Check Database Integrity Task Executing query "USE [DATABASE5] ".: 50% complete End Progress Progress: 2014-05-07 02:05:14.19 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE5') WITH NO_INFO...".: 100% complete End Progress Progress: 2014-05-07 02:05:14.20 Source: Check Database Integrity Task Executing query "USE [DATABASE6] ".: 50% complete End Progress Progress: 2014-05-07 02:05:17.45 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE6') WITH NO_INFOMSGS ...".: 100% complete End Progress Progress: 2014-05-07 02:05:17.45 Source: Check Database Integrity Task Executing query "USE [DATABASE7] ".: 50% complete End Progress Progress: 2014-05-07 02:05:19.47 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE7') WITH NO_INFOMSG...".: 100% complete End Progress Progress: 2014-05-07 02:05:19.48 Source: Check Database Integrity Task Executing query "USE [DATABASE8] ".: 50% complete End Progress Progress: 2014-05-07 02:05:21.60 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE8') WIT...".: 100% complete End Progress Progress: 2014-05-07 02:05:21.60 Source: Check Database Integrity Task Executing query "USE [DATABASE9] ".: 50% complete End Progress Progress: 2014-05-07 02:05:22.97 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE9') WITH NO_IN...".: 100% complete End Progress Progress: 2014-05-07 02:05:22.98 Source: Check Database Integrity Task Executing query "USE [DATABASE10] ".: 50% complete End Progress Progress: 2014-05-07 02:05:24.89 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(N'DATABASE10') WITH NO_IN...".: 100% complete End Progress Progress: 2014-05-07 02:05:24.90 Source: Check Database Integrity Task Executing query "USE [DATABASE11] ".: 50% complete End Progress Progress: 2014-05-07 02:05:26.93 Source: Check Database Integrity Task Executing query "DBCC CHECKDB(... The package execution fa... The step failed.

    Here is the recorded log from the Log File Browser for one of the jobs, this specific one executes a History Cleanup Task:

    Date05.05.2014 00:00:00

    LogJob History (MaintenancePlan.History Cleanup)

    Step ID1

    ServerCLUSTERNAME

    Job NameMaintenancePlan.History Cleanup

    Step NameHistory Cleanup

    Duration00:30:09

    Sql Severity0

    Sql Message ID0

    Operator Emailed

    Operator Net sent

    Operator Paged

    Retries Attempted0

    Message

    Executed as user: AD\sqlcluster_clustername. Microsoft (R) SQL Server Execute Package Utility Version 11.0.2100.60 for 64-bit Copyright (C) Microsoft Corporation. All rights reserved. Started: 00:00:00 Progress: 2014-05-05 00:00:00.95 Source: {68BCDF70-757B-44C4-BC89-2D63AC435C5F} Executing query "DECLARE @GUID UNIQUEIDENTIFIER EXECUTE msdb..sp...".: 100% complete End Progress Progress: 2014-05-05 00:00:01.07 Source: Maintenance Cleanup Task Executing query "EXECUTE master.dbo.xp_delete_file 1,N'D:\MSSQL11.M...".: 100% complete End Progress Error: 2014-05-05 00:30:01.12 Code: 0xC0024104 Source: Maintenance Cleanup Task Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter. End Error Warning: 2014-05-05 00:30:01.12 Code: 0x80019002 Source: History Cleanup Description: SSIS Warning Code DTS_W_MAXIMUMERRORCOUNTREACHED. The Execution method succeeded, but the number of errors raised (2) reached the maximum allowed (1); resulting in failure. This occurs when the number of errors reaches the number specified in MaximumErrorCount. Change the MaximumErrorCount or fix the errors. End Warning DTExec: The package execution returned DTSER_FAILURE (1). Started: 00:00:00 Finished: 00:30:07 Elapsed: 1807.27 seconds. The package execution failed. The step failed.

    This task was set up to delete old backup files

    Date06.05.2014 10:00:47

    LogJob History (Rydde plass.Full)

    Step ID1

    ServerCLUSTERNAME

    Job NameRydde plass.Full

    Step NameDiff

    Duration00:33:22

    Sql Severity0

    Sql Message ID0

    Operator Emailed

    Operator Net sent

    Operator Paged

    Retries Attempted0

    Message

    Executed as user: AD\sqlcluster_clustername. Microsoft (R) SQL Server Execute Package Utility Version 11.0.2100.60 for 64-bit Copyright (C) Microsoft Corporation. All rights reserved. Started: 10:00:47 Progress: 2014-05-06 10:00:48.13 Source: {C7AE56D7-5826-4DA4-A913-FCB34D71181A} Executing query "DECLARE @GUID UNIQUEIDENTIFIER EXECUTE msdb..sp...".: 100% complete End Progress Progress: 2014-05-06 10:04:05.15 Source: Maintenance Cleanup Task Executing query "EXECUTE master.dbo.xp_delete_file 0,N'\\fileserver...".: 100% complete End Progress Error: 2014-05-06 10:34:05.20 Code: 0xC0024104 Source: Maintenance Cleanup Task Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter. End Error Warning: 2014-05-06 10:34:05.20 Code: 0x80019002 Source: Diff Description: SSIS Warning Code DTS_W_MAXIMUMERRORCOUNTREACHED. The Execution method succeeded, but the number of errors raised (2) reached the maximum allowed (1); resulting in failure. This occurs when the number of errors reaches the number specified in MaximumErrorCount. Change the MaximumErrorCount or fix the errors. End Warning DTExec: The package execution returned DTSER_FAILURE (1). Started: 10:00:47 Finished: 10:34:07 Elapsed: 1999.96 seconds. The package execution failed. The step failed.

    In addition to this, i get these messages on some jobs in the SQL Server Agent log (I have been manually cancelling jobs, but some of them go back pretty far, and before i started testing):

    Date07.05.2014 12:49:36

    LogSQL Server Agent (Current - 07.05.2014 12:17:00)

    Message

    [136] Job Test Backup.Subplan_1 reported: Unable to terminate process 2d3c launched by step 1 of job 0x0D6DFB8BDE6EA6439908CFF05196AA3C (reason: Access is denied)

    When I try to delete any of the test maintenance plans i created i get this:

    TITLE: Microsoft SQL Server Management Studio

    ------------------------------

    Exception has been thrown by the target of an invocation. (mscorlib)

    ------------------------------

    ADDITIONAL INFORMATION:

    An exception occurred while executing a Transact-SQL statement or batch. (Microsoft.SqlServer.ConnectionInfo)

    ------------------------------

    Lock request time out period exceeded.

    The DELETE statement conflicted with the REFERENCE constraint "FK_sysmaintplan_log_subplan_id". The conflict occurred in database "msdb", table "dbo.sysmaintplan_log", column 'subplan_id'.

    The DELETE statement conflicted with the REFERENCE constraint "FK_subplan_job_id". The conflict occurred in database "msdb", table "dbo.sysmaintplan_subplans", column 'job_id'.

    Transaction count after EXECUTE indicates a mismatching number of BEGIN and COMMIT statements. Previous count = 1, current count = 0.

    The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION.

    The statement has been terminated.

    The statement has been terminated. (Microsoft SQL Server, Error: 1222)

    For help, click: http://go.microsoft.com/fwlink?ProdName=Microsoft%20SQL%20Server&ProdVer=11.00.3128&EvtSrc=MSSQLServer&EvtID=1222&LinkId=20476

    ------------------------------

    BUTTONS:

    OK

    ------------------------------

    Since this is a production environment, I have not yet failed over to the other node in order to give the services a restart, but if this continues to happen even after that, then I don't really know what the problem could be.

  • It looks like a series of problems, but I can't see the complete error messages. I'd suggest modifying the jobs so that they output everything to a file so you can see the full error messages. You can do this by modifying the job in the advanced tab.

    "The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
    - Theodore Roosevelt

    Author of:
    SQL Server Execution Plans
    SQL Server Query Performance Tuning

  • Microsoft (R) SQL Server Execute Package Utility

    Version 11.0.2100.60 for 64-bit

    Copyright (C) Microsoft Corporation. All rights reserved.

    Started: 14:44:11

    Error: 2014-05-07 14:44:11.72

    Code: 0xC000F427

    Source: test2

    Description: To run a SSIS package outside of SQL Server Data Tools you must install {5A140578-FE0B-4E5B-BF1F-DD6B836A0B6C} of Integration Services or higher.

    End Error

    Error: 2014-05-07 14:44:11.73

    Code: 0xC000F427

    Source: test2

    Description: To run a SSIS package outside of SQL Server Data Tools you must install {5A140578-FE0B-4E5B-BF1F-DD6B836A0B6C} of Integration Services or higher.

    End Error

    Error: 2014-05-07 15:14:12.86

    Code: 0xC0024104

    Source: Back Up Database Task

    Description: The Execute method on the task returned error code 0x80131501 (An exception occurred while executing a Transact-SQL statement or batch.). The Execute method must succeed, and indicate the result using an "out" parameter.

    End Error

    DTExec: The package execution returned DTSER_FAILURE (1).

    Started: 14:44:11

    Finished: 15:14:18

    Elapsed: 1806.9 seconds

  • So that error is pretty straight forward. You have the wrong version of the SSIS service running on the system. You'll need to fix that.

    "The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
    - Theodore Roosevelt

    Author of:
    SQL Server Execution Plans
    SQL Server Query Performance Tuning

  • Usually i do not install this service because I seldom set up a system that needs it (these are small relatively environments that only need basic hosting of DB and basic maintenance plans even if it is a cluster) , the only services installed are, browser, engine, agent and full-text filter daemon launcher...those that followed during the installation when I under feature selection chose Database Engine Service.

  • Well, if you want to use this generated job you'll need to get SSIS on it.

    "The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
    - Theodore Roosevelt

    Author of:
    SQL Server Execution Plans
    SQL Server Query Performance Tuning

  • Alright, shouldn't be a problem adding the services, but there has had to be some sort of change to the setup recently, because I haven't had to use it before on the exact same system, it has worked for months and all of the sudden SQL says, nope, I don't want to without SSIS 😎

  • Yeah, not sure. Just following where the error messages lead.

    "The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
    - Theodore Roosevelt

    Author of:
    SQL Server Execution Plans
    SQL Server Query Performance Tuning

  • So I had the SQL services failed over to the other node in our cluster in order to give the services a restart, and I decided to test something I've seen as an issue or perhaps bug, before. I tested the existing jobs, and they still failed with the same error messages. Then I created some new ones and these worked as intended.

  • You mentioned that you use Maintenance Plans. One of the reasons that I don't is that I've experienced issues where a task in a Maintenance Plan fails because a database has been taken offline or detached; the Maintenance Plan doesn't seem to check the state of a database.

    Having said that, if everything started working after you failed over to the other node, that would seem to preclude the above as being the cause.

    Regards

    Lempster

  • Yes on some setups, but we recetly changed to ola hallegrens maint script 🙂

Viewing 11 posts - 1 through 10 (of 10 total)

You must be logged in to reply to this topic. Login to reply