SQLU DBA Week – Be an Efficient DBA

SQLU DBA Week – Be an Efficient DBA

Welcome back for another day of Administration Week 1 for SQL University. This is day four, and I want to focus in on a term that I hear quite a bit, lazy dba. DBAs are anything but lazy, but the term seems to have come about by the way that we are always lookign for the simplest and quickest way to do something. That’s not being lazy, that’s being efficient. Don’t be a lazy DBA. Be an efficent DBA. I want share some of my favorite efficient ways to do things.

I’m sharing DBA Week 1 with Mike Walsh (blog|@mike_walsh). The goal is to bring you a varying approach to administration and delve into topics to different levels. If you have not already done so, be sure to check out the other posts for this week:

• Day 1 (Mike): SQLU DBA Week – You Can Restore It! (right?)
• Day 2 (Me): SQLU DBA Week – Recovering Lost Data
• Day 3 (Mike): SQLU DBA Week – Set It And….

What’s in the Log

It pains me when I see people using the GUI to look at the SQL log. There’s so much data in there that I don’t want to see. For example, my SQL log is going to be filled with messages about backups. Unless I’m specifically looking at a backup issue, this makes reading the error log difficult. I use the system extended stored procedure xp_readerrorlog to insert the log into a table variable and then return filtered results.

Below is the basic query I use when checking the SQL log. It’s very easy to add or change filters from this point. Over the years, I saved several specialized versions of this query.

Returns the Current Error Log

Declare @ErrorLog Table (LogID int identity(1, 1) not null primary key,
        LogDate datetime null,
        ProcessInfo nvarchar(100) null,
        LogText nvarchar(4000) null) 

Insert Into @ErrorLog (LogDate, ProcessInfo, LogText)
Exec master..xp_readerrorlog

Select *
From @ErrorLog
Where CharIndex('Backup', ProcessInfo) = 0
Order By LogID Desc 

Returns Info and Stats about IO Stall

Declare @Counter int
Declare @ErrorLog Table (LogID int identity(1, 1) not null primary key,
                        LogDate datetime null,
                        ProcessInfo nvarchar(100) null,
                        LogText nvarchar(max) null)

Set @Counter = 0

While @Counter < 2
  Begin
    Insert Into @ErrorLog (LogDate, ProcessInfo, LogText)
    Exec master..xp_readerrorlog @Counter

    Set @Counter = @Counter + 1
  End

Select Count(LogText), Sum(Cast(Left(Right(LogText, Len(LogText) - 27), CharIndex(space(1), Right(LogText, Len(LogText) - 27))) as int))
From @ErrorLog
Where CharIndex('I/O requests taking longer than 15 seconds to complete', LogText) > 0

Select Cast(Convert(varchar, LogDate, 110) as datetime) As dPerDay,
DatePart(hour, LogDate) As PerHour,
DatePart(minute, LogDate) As PerMinute,
Convert(varchar, LogDate, 110) As PerDay, Count(LogText) IOWarningsLogged,
TotalIOSlowDowns = Sum(Cast(Left(Right(LogText, Len(LogText) - 27), CharIndex(space(1), Right(LogText, Len(LogText) - 27))) as int))
From @ErrorLog
Where CharIndex('I/O requests taking longer than 15 seconds to complete', LogText) > 0
Group By Convert(varchar, LogDate, 110), DatePart(hour, LogDate), DatePart(minute, LogDate)
Order By dPerDay desc, PerHour desc, PerMinute desc

When Was Database Integrity Last Checked

A majority of the servers I’m called in to work on don’t have a DBA working with them. In these cases, I like to make recommendations about what maintenance they should be doing, and I like to show them how long it has been since the integrity has been successfully checked on their databases.

This query gives me the date of the last good DBCC for every database on the server:

Declare @DBs Table (
       Id int identity(1,1) primary key,
       ParentObject varchar(255),
       Object varchar(255),
       Field varchar(255),
       Value varchar(255)
)

Insert Into @DBs (ParentObject, Object, Field, Value)
Exec sp_msforeachdb N'DBCC DBInfo(''?'') With TableResults;';

Insert Into @DBs (ParentObject, Object, Field, Value)
Select 'Final Record', 'Final Record', 'dbi_dbname', 'Final Record';

With DBNames (Id, Field, Value, DBID)
As (Select Id, Field, Value,
     ROW_NUMBER() OVER (PARTITION BY Field ORDER BY ID)
    From @DBs
    Where Field = 'dbi_dbname')
, LastDBCC (Id, Field, Value)
As (Select Id, Field, Value
    From @DBs
    Where Field = 'dbi_dbccLastKnownGood')
Select Distinct D1.Value, L.Value
From LastDBCC L
Inner Join DBNames D1 On L.Id > D1.Id
Inner Join DBNames D2 On L.Id < D2.Id And D2.DBID = D1.DBID + 1;

Waits Over the Last one Minute

When looking at waits to try to determine the cause of a performance problem or slow queries, you should be looking at tasks that are currently waiting via sys.dm_os_waiting_tasks. However, I see a lot of people relying on sys.dm_os_wait_stats to troubleshoot issues. This will not give you an accurate view of what is occurring on your server right this moment. I often see people resetting the wait stats so that sys.dm_os_wait_stats will give them current data only. You lose what could be very important data if you do this. I don’t advocate this either.

However, if the server is very busy, then sys.dm_os_waiting_tasks can be difficult to use. Also, tasks can be waiting for more than just a single resource, and you only see the current wait that it is experiencing at the moment you run the query. Even sys.dm_os_waiting_tasks isn’t giving you the complete picture. What I like to do is to calculate the delta of the total wait stats over a given time.

The below query will calculate the key wait stats over a one minute time frame:

Declare @Waits Table (
    WaitID int identity(1, 1) not null primary key,
    wait_type nvarchar(60),
    wait_time_s decimal(12, 2));    

WITH Waits AS
(SELECT wait_type, wait_time_ms / 1000. AS wait_time_s,
    100. * wait_time_ms / SUM(wait_time_ms) OVER() AS pct,
    ROW_NUMBER() OVER(ORDER BY wait_time_ms DESC) AS rn
FROM sys.dm_os_wait_stats
WHERE wait_type NOT IN( 'SLEEP_TASK', 'BROKER_TASK_STOP',
  'SQLTRACE_BUFFER_FLUSH', 'CLR_AUTO_EVENT', 'CLR_MANUAL_EVENT',
  'LAZYWRITER_SLEEP')) -- filter out additional irrelevant waits
Insert Into @Waits (wait_type, wait_time_s)
SELECT W1.wait_type,
  CAST(W1.wait_time_s AS DECIMAL(12, 2)) AS wait_time_s
FROM Waits AS W1
INNER JOIN Waits AS W2
ON W2.rn <= W1.rn
GROUP BY W1.rn, W1.wait_type, W1.wait_time_s, W1.pct
HAVING SUM(W2.pct) - W1.pct < 95; -- percentage threshold

WaitFor Delay '0:01:00';

WITH Waits AS
(SELECT wait_type, wait_time_ms / 1000. AS wait_time_s,
    100. * wait_time_ms / SUM(wait_time_ms) OVER() AS pct,
    ROW_NUMBER() OVER(ORDER BY wait_time_ms DESC) AS rn
FROM sys.dm_os_wait_stats
WHERE wait_type NOT IN( 'SLEEP_TASK', 'BROKER_TASK_STOP',
  'SQLTRACE_BUFFER_FLUSH', 'CLR_AUTO_EVENT', 'CLR_MANUAL_EVENT',
  'LAZYWRITER_SLEEP')) -- filter out additional irrelevant waits
Insert Into @Waits (wait_type, wait_time_s)
SELECT W1.wait_type,
  CAST(W1.wait_time_s AS DECIMAL(12, 2)) AS wait_time_s
FROM Waits AS W1
INNER JOIN Waits AS W2
ON W2.rn <= W1.rn
GROUP BY W1.rn, W1.wait_type, W1.wait_time_s, W1.pct
HAVING SUM(W2.pct) - W1.pct < 95; -- percentage threshold

Select wait_type, MAX(wait_time_s) - MIN(wait_time_s) WaitDelta
From @Waits
Group By wait_Type
Order By WaitDelta Desc