Ola Hallengren – Index Optimization Job – Failure

Background

Reviewing Scheduled Database Maintenance Jobs and found out that our daily database maintenance job failed.

 

Review

SQL Server Agent

SQL Server Agent Job History Review

 

Troubleshooting

SQL Server Agent

Job History

Reviewed Job History for Index Optimize Job…

SQL Server Management Studio ( SSMS )

Using the SSMS GUI reviewed the job log

Image

Explanation

Nothings shows up as to cause of error.

Transact SQL

Let us use code

Code

set nocount on
go

use [msdb]
go

declare @jobName sysname

declare @dtCurrent datetime
declare @dtToday datetime
declare @dtCutoff datetime
declare @iNumberofDays smallint
declare @dateYYYYMMDD  int

set @iNumberofDays = 1

set @dtCurrent = getdate()
set @dtToday = convert(varchar(30), @dtCurrent, 101)
set @dtCutoff = dateadd(day,  @iNumberofDays * -1, @dtToday)
set @dateYYYYMMDD = ltrim(rtrim(
									replace
									(
										convert(varchar(10), @dtCutoff, 127)
										, '-'
										, ''
									)
							))

set @jobName = 'IndexOptimize - USER_DATABASES'

select top 10000

		  [jobname] = tblSJ.[name]
		, [stepID] = tblSJH.[step_id]
		, [stepName] = tblSJH.[step_name]
		, [sqlMessageID] = tblSJH.sql_message_id
		, [sqlSeverity] = tblSJH.sql_severity
		, [message] = tblSJH.[message]
		, [TS] = dbo.agent_datetime
					(
						 tblSJH.[run_date]
						,tblSJH.[run_time]
					)
		, [runDate] = tblSJH.[run_date]
		, [runTime] = tblSJH.[run_time]
		--, tblSJH.*

from   [msdb].[dbo].[sysjobhistory] tblSJH

inner join [msdb].[dbo].[sysjobs] tblSJ

	on tblSJH.[job_id] = tblSJ.[job_id]

where tbLSJ.[name] = @jobName

and   tblSJH.run_date >= @dateYYYYMMDD

order by
		tblSJH.[instance_id] desc

Image

 

Explanation
  1. Nothing useful showed up in terms of error message
  2. But, also noticed that only 100 records showed

 

SQL Server Agent – Job Step – Advanced Configuration

Image

Explanation

  1. Output File
    • E:MicrosoftSQLServerSQLServerAgentjobLogIndexOptimizeIndexOptimize_$(ESCAPE_SQUOTE(JOBID))_$(ESCAPE_SQUOTE(STEPID))_$(ESCAPE_SQUOTE(STRTDT))_$(ESCAPE_SQUOTE(STRTTM)).txt

SQL Server Agent – Job Step – Advanced Configuration – File System

File System Files

Reviewed the File System, specifically the folder where Job Steps are located:

Image – File System Files

Explanation
  1. Noticed that we have a log file for the date when logs are kept
File System Content

Loaded file and reviewed contents

Text – File Contents

Date and time: 2018-02-26 03:09:54
Command: ALTER INDEX [INDX_ID] ON [DBPerf].[extendedEvent].[event] REORGANIZE WITH (LOB_COMPACTION = ON)
Comment: ObjectType: Table, IndexType: NonClustered, ImageText: N/A, NewLOB: No, FileStream: N/A, ColumnStore: No, AllowPageLocks: Yes, PageCount: 2696, Fragmentation: 1.52077
Msg 50000, Level 16, State 1, Server HRDBSQL01, Procedure CommandExecute, Line 152
Msg 1205, Transaction (Process ID 61) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
Outcome: Failed
Duration: 00:00:09
Date and time: 2018-02-26 03:10:03

Explanation
  1. Msg 1205, Transaction (Process ID 61) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
    Outcome: Failed

 

Index Optimization Job

Ola hallengren

Log Table

Table – dbo.CommandLog
SQL

declare @dtCurrent datetime
declare @dtToday datetime
declare @dtCutoff datetime
declare @iNumberofDays smallint

set @iNumberofDays = 1

set @dtCurrent = getdate()
set @dtToday = convert(varchar(30), @dtCurrent, 101)
set @dtCutoff = dateadd(day,  @iNumberofDays * -1, @dtToday)

SELECT
	TOP (1000) 

	   --[ID]

       [StartTime]

      ,[EndTime]

	  ,[durationInSeconds]
			= datediff(second, [StartTime], [EndTime])

		/*

		  ,[durationInMinutes]
				= datediff
					(
						  minute
						, tblCL.[StartTime]
						, tblCL.[EndTime]
					)
		*/

      ,[DatabaseName]

      --,[SchemaName]
      --,[ObjectName]

	  ,[object]
		= quotename([SchemaName])
			+ '.'
		    + quotename([ObjectName])

      --,[ObjectType]
      ,[IndexName]
      --,[IndexType]
      --,[StatisticsName]
      --,[PartitionNumber]
      ,[ExtendedInfo]
      ,[Command]
      ,[CommandType]
      ,[ErrorNumber]
      ,[ErrorMessage]

FROM [dbo].[CommandLog] tblCL

where tblCL.[StartTime] >= @dtCutoff

and tblCL.CommandType in
			(
				  'ALTER_INDEX'
			)		

order by
	  tblCL.ErrorNumber desc
	, datediff(second, [StartTime], [EndTime]) desc
	, tblCL.[ID] desc

Output

Explanation

We have a full insight as to the workings of the Index Optimize tool

  1. ErrorNumber & ErrorMessage
    • Error Number
      • when 0, no error
      • Typical Error
        • 1205 ( deadlock)
    • Error Message
      • Sample
        • Transaction (Process ID 61) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
  2. Columns :- StartTime and EndTime
    • We see how long it takes to optimize each table
  3. ExtendedInfo
    • The Extended Info column show us the PageCount and Fragmentation percentile
  4. CommandType
    • The type of fragmentation that is employed ( REBUILD/RE-ORG )

 

Table – dbo.CommandLog.ExtendedInfo
SQL

declare @dtCurrent datetime
declare @dtToday datetime
declare @dtCutoff datetime
declare @iNumberofDays smallint

set @iNumberofDays = 1

set @dtCurrent = getdate()
set @dtToday = convert(varchar(30), @dtCurrent, 101)
set @dtCutoff = dateadd(day,  @iNumberofDays * -1, @dtToday)

SELECT
	TOP (1000) 

	   [ErrorNumber]

      , [StartTime]
		= convert(varchar(30), [StartTime], 100)

	/*
      ,[EndTime]
		= convert(varchar(30), [EndTime], 100)
	*/

	  ,[durationInSeconds]
			= datediff(second, [StartTime], [EndTime])

	  ,[object]
		= quotename([DatabaseName])
			+ '.'
		    + quotename([SchemaName])
			+ '.'
		    + quotename([ObjectName])
			+ '.'
			+ quoteName([IndexName])

      ,[ExtendedInfo]

      ,[CommandType]

FROM [dbo].[CommandLog] tblCL

where tblCL.[StartTime] >= @dtCutoff

and tblCL.CommandType in
			(
				  'ALTER_INDEX'
			)		

order by
	  tblCL.ErrorNumber desc
	, datediff(second, [StartTime], [EndTime]) desc
	, tblCL.[ID] desc

Output

 

Explanation
  1. Upon taking a keen look at the ExtendedInfo column
    • We see that even for indexes with very low fragmentation levels, we are still issuing a defrag action

Remediation

  1. Review dbo.IndexOptimize Stored Procedure Output statement
    • What values are being passed to it
      • @FragmentationLow
        • If INDEX_REORGANIZE, then you are likely doing Index Re-ORGS when not really needed
        • Please leave at default of NULL, to skip index maintenance for indexes that have low defrag
      • WaitAtLowPriorityMaxDuration
        • Documentation reads
          • The time, in minutes that an online index rebuild operation will wait for low priority locks.”
          • The WaitAtLowPriorityMaxDuration option in IndexOptimize uses the WAIT_AT_LOW_PRIORITY and MAX_DURATION options in the SQL Server ALTER INDEX command.
        • Our Setting
          • We set ours to 2 to indicate 2 minutes
      • @WaitAtLowPriorityAbortAfterWait nvarchar(max)
        • Documented Options
          • NONE :- Continue waiting for locks with normal priority.
          • SELF :- Abort the online index rebuild operation.
          • BLOCKERS Kill :- User transactions that block the online index rebuild operation.
        • Our Setting
          • We set ours to ‘SELF‘ to indicate self abort
          • We will rather take the hit than have the user operations be affected
  2. Also consider increasing the cutoff values in SQL Server Agent Max Log Size In Rows
    • The default values are
      • 1000 for all jobs
      • 100 for each job
    • Ours are now
      • 999,999 for all jobs
        • Essentially 1 million records
      • 100000 for each job
        • Depending on how many scheduled jobs you have, you might want to lower that figure
        • Lowering it will mean that jobs that log quite a bit do not squeeze out jobs that do not log, as much

Sorry

Sorry no edits or proofreading.

It is Monday and I am starting at the back of the pack.

References

  1. Ola Hallengren
    1. SQL Server Index and Statistics Maintenance
      Link

 

 

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

w

Connecting to %s