Reading SQL Server Error Logs

I wrote a script to allow me to look at the last few days of errors in the SQL error logs. It was rather useful at a previous site, and I wrote them a little note about it, which I then carefully failed to copy for here. Oh well.

Why Script This? What’s Wrong With SSMS’s GUI?

Well, although SSMS does allow you to look at the error logs, it’s not very helpful for filtering – you can only filter for items that match, rather than exclude items. There are a few other filters as well – I guess the whole thing is just a wrapper around xp_readerrorlog below…

What’s wrong with just using sp_readerrorlog or xp_readerrorlog?

The undocumented procedures? Again, limited filtering functionality – you can put in at most two strings to filter match the logs.

What are these procedures anyway?

There are two system stored procedures and two extended stored procedures – all undocumented – that be used to help reading error logs. These are very briefly discussed below.

sp_enumerrorlog & xp_enumerrorlog

These take a single optional parameter, to say which error logs you wish to examine. Values are 1 (default) for SQL Server error log, and 2 for the SQL Agent logs

sp_readerrorlog

Four parameters:

  • Number of the log file to look at – see output from sp_enumerrorlog
  • Whether it’s a SQL Server error log or a SQL Agent log (see above)
  • two filter parameters – error messages containing these strings will be returned

xp_readerrorlog

All the parameters for sp_readerrorlog, and these three:

  • Begin date/time
  • End date/times
  • sort order asc/desc

T-SQL Script to read SQL Server Error Logs

Here’s the script I’ve found useful to read just a few days’ worth of error logs. Other scripts are out there.
I’ve filtered out some of the more boring error messages. You might want to fiddle with those, add your own, whatever.

DECLARE @daysback INT = 0; -- number of days to go back in the logs.  0 = today only

-- table variable for holding the details of the error logs.
-- Yes, I know, table variables are evil.  This one is unlikely to hold more than a few dozen rather narrow lines
DECLARE @ErrorLogs TABLE
(
    Archive INT NOT NULL,
    LogDate DATETIME NOT NULL,
    LogFileSizeBytes BIGINT NOT NULL,
    ReadThis TINYINT NULL
);

-- useful trick if you don't know it: INSERT INTO a table the results of EXECing a SP.
INSERT INTO @ErrorLogs (Archive, LogDate, LogFileSizeBytes)
EXEC sys.sp_enumerrorlogs;

DECLARE @lognum INT = 0;
DECLARE @logdate DATETIME;

--figure out which logfiles we need.
WITH
    NextLog
  AS
  (
      SELECT    Archive,
                LogDate,
                LogFileSizeBytes,
                ReadThis,
                ISNULL(LAG(LogDate) OVER (ORDER BY Archive), LogDate) AS nextlogdate
      FROM      @ErrorLogs
  )
UPDATE          @ErrorLogs
SET             ReadThis = CASE
                               WHEN e.Archive = 1 THEN 1 -- always read the first file; doesn't always get identified by the next line
                               WHEN n.nextlogdate >= DATEADD(DAY, DATEDIFF(DAY, '20100101', GETDATE()) - ABS(@daysback), '20100101') THEN
                                   1
                               ELSE
                                   0
                           END
FROM            NextLog    AS n
    INNER JOIN  @ErrorLogs AS e ON e.Archive = n.Archive;

--just checking which files we're looking at...  Probably comment this line out for production use
SELECT      *
FROM        @ErrorLogs
ORDER BY    Archive;

IF OBJECT_ID('tempdb.dbo.#spErrorLog', 'U') IS NOT NULL BEGIN
    DROP TABLE #spErrorLog;
END;

CREATE TABLE #spErrorLog (logdate DATETIME NOT NULL, ProcessInfo VARCHAR(20) NULL, Text VARCHAR(MAX) NOT NULL);

WHILE @lognum <= (SELECT    MAX(Archive)FROM   @ErrorLogs WHERE ReadThis = 1)
BEGIN
    INSERT INTO #spErrorLog
    EXEC sys.sp_readerrorlog @p1 = @lognum;

    SELECT  @lognum = @lognum + 1;

    SELECT  @logdate = LogDate
    FROM    @ErrorLogs
    WHERE   Archive = @lognum;
END;

SELECT      *
FROM        #spErrorLog
WHERE
            1 = 1
  AND
            (
                ProcessInfo = 'Server' -- we like server-related boot messages.
           OR
                ( -- filter out noisy messages that we don't really need to see here
                    Text NOT LIKE '%Backup Log%'
              AND   Text NOT LIKE 'Log was backed up%'
              AND   Text NOT LIKE 'CHECKDB for database % finished without errors on %This is an informational message only; no user action is required.'
              AND   Text NOT LIKE 'DBCC CHECKDB % WITH all_errormsgs, no_infomsgs, data_purity executed by % found 0 errors and repaired 0 errors.%'
              AND   Text NOT LIKE 'BACKUP DATABASE WITH DIFFERENTIAL successfully processed % pages%'
              AND   Text NOT LIKE 'Database differential changes were backed up. Database: % This is an informational message. No user action is required.'
              AND   Text NOT LIKE 'BACKUP DATABASE successfully processed % pages %'
              AND   Text NOT LIKE 'Database backed up. Database: % This is an informational message only. No user action is required.'
              AND   logdate >= DATEADD(DAY, DATEDIFF(DAY, '20100101', GETDATE()) - ABS(@daysback), '20100101')
                )
            )
ORDER BY    logdate;
Advertisements
Posted in SQLServerPedia Syndication | Tagged , | 8 Comments

DBCC DBINFO() – Don’t rely on undocumented commands

Don’t Rely on Undocumented Commands – A Cautionary Tale

Looking at the output for the (undocumented) DBCC DBINFO() command, I noticed a typo in one of the field names. I wondered about submitting it as a bug, but then looked at some of the other SQL Servers available to me, and saw that it appears to have been fixed.

Running this query:

DECLARE @DBCCDBInfo AS TABLE (ParentObject VARCHAR(MAX), Object VARCHAR(MAX), Field VARCHAR(MAX), Value VARCHAR(MAX));

INSERT INTO @DBCCDBInfo
EXEC ('sp_executesql @statement=N''SET NOCOUNT ON; USE Coredata; DBCC DBINFO() WITH tableresults''');

SELECT  SERVERPROPERTY('ProductVersion') AS ProductVersion,
        Field
FROM    @DBCCDBInfo
WHERE   Field LIKE 'dbi_Cont%';

…against an assortment of SQL Server versions produces slightly different output:

ProductVersion Field
11.0.6260.1 dbi_ContianmentState
11.0.6615.2 dbi_ContianmentState
11.0.7462.6 dbi_ContianmentState
11.0.7469.6 dbi_ContianmentState
12.0.5214.6 dbi_ContainmentState
12.0.5571.0 dbi_ContainmentState
12.0.6024.0 dbi_ContainmentState
13.0.4522.0 dbi_ContainmentState
13.0.5026.0 dbi_ContainmentState
13.0.5081.1 dbi_ContainmentState
13.0.5216.0 dbi_ContainmentState

I don’t have every version available to test, but it does appear that the record indicating Containment State is mis-spelled in SQL Server 2012 as “dbi_ContianmentState”, and then corrected in SQL 2014 and later. It’s a good job I’m not relying on it for anything.

So, yes, don’t rely on undocumented functions – as they may change without notice.

Easier way to check for Containment

Mind you, for what I was actually looking at – the containment state – there’s a much easier way:

SELECT name, containment_desc FROM sys.databases

Containment_desc is either “NONE” or “PARTIAL”. Why only those two? Presumably because they haven’t got as far as “FULL” yet. I vaguely recall conference sessions back when this stuff was being announced indicating that they were looking at incorporating scheduled tasks in the database as well, but this was a few years ago. Maybe they’ll get round to it and make a more contained database.

 

Now, why was I here?

Oh yes.

When was DBCC Last Run?

You can use the same query to check for last known good DBCC check without having to faff about parsing error logs. Search for “Field LIKE ‘%dbcc%'” instead:

SELECT  Field, Value
FROM    @DBCCDBInfo
WHERE   Field LIKE '%DBCC%';

And you get two records:

Field Value
dbi_dbccFlags 2
dbi_dbccLastKnownGood 2019-07-12 23:36:54.447

Search for dbi_dbccLastKnownGood for the date/time stamp. (The dbccFlags value indicates that DBCC was run WITH DATA_PURITY have been performed.)

But, y’know, undocumented and all, so be aware that this could change…

Posted in SQLServerPedia Syndication | Tagged , | 3 Comments

SQL In The City – Summit – London, April 2019

Just a quick plug (no, I don’t get paid for this) for Redgate’s next SQL In The City “Summit” – a higher-end version of their SQL in the city events that they used to hold before they went online a few years ago.

The next one is in London in a few days’ time. Unfortunately, I can’t be there, but you should probably consider attending if you use, or are interested in Redgate products – because you get the chance to talk to the guys that actually write the software that you (will) use. I’ve had many useful conversations at previous SitC events, and have no reason to suppose that the same won’t be possible this time.

Yes, the sessions do plug Redgate products – but in the past, these events have always spent three quarters of the time focusing on a real problem that DBAs have, and then spending a few minutes showing how Redgate tools help you address those problems.

Anyway. Canary Wharf, London, 30th April. Full details at https://www.red-gate.com/hub/events/redgate-events/sqlinthecity-summit/london

Posted in SQLServerPedia Syndication | Tagged , | Leave a comment

Failed to Update Read-Only Database on Backup

A problem at work recently – the Netbackup-driven SQL backups were failing for just one database on a particular server. The database in question was, like one other, set to read-only.

I ran DBCC CHECKDB, on the off-chance that this was the problem; everything was fine.

The database was, like one other database on that server, set to READ_ONLY – and that database wasn’t having problems.

Troubleshooting

I checked in Windows Event Log, and all I got was:

BACKUP failed to complete the command BACKUP DATABASE <<name>>. Check the backup application log for detailed messages.

The Netbackup logs were of no help either.

To get an accurate error message, I ran a native SQL backup, and, in addition to the normal backup / filegroup / page messages, got the following error:

Msg 3906, Level 16, State 1, Line 35
Failed to update database "<<name>>" because the database is read-only.
Msg 3013, Level 16, State 1, Line 35
BACKUP DATABASE is terminating abnormally.

Checking the SQL Server error logs gave a clue:

[INFO] getMaxUnrecoverableCheckpointId(). Database ID: [6]. Start of Log LSN: 00000022:00000097:0023 used to trim unrecoverable checkpoint files tables during full backup.
[INFO] HkHostBackupDeleteContext(). Database ID: [6]. Cleaned up all the allocated buffers.

Hk? That sounds as though it might mean Hekaton. Checking the database properties, it was, indeed, a database with in-memory objects.

Replicating the Problem

A script to replicate the problem. Note that I’m writing to the NUL: device, a hangover from the good old days – it means the whole backup process is running, but I’m just not saving the backup files.

--First, create the database and run a backup
CREATE DATABASE ROInMemBackupTest;
GO
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE RoInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 344 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 1 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 345 pages in 0.064 seconds (42.091 MB/sec).
*/

--Now we add a filegroup to contain memory optimized data
ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
ALTER DATABASE [ROInMemBackupTest] ADD FILEGROUP [InMemData] CONTAINS MEMORY_OPTIMIZED_DATA;
GO
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE RoInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 3 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 363 pages in 0.057 seconds (49.633 MB/sec).
*/

--Now we add a container to hold memory optimized data
ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
ALTER DATABASE ROInMemBackupTest 
ADD FILE 
(
    NAME='MemOptData', 
    FILENAME='C:\Program Files\Microsoft SQL Server\MSSQL13.MSSQLSERVER\MSSQL\DATA\ROInMemBackupTest_MemOptData'
)
TO FILEGROUP InMemData;
GO

--Set to RO & try another backup
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE ROInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 0 pages for database 'ROInMemBackupTest', file 'MemOptData' on file 1.
Processed 2 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
Msg 3906, Level 16, State 1, Line 35
Failed to update database "ROInMemBackupTest" because the database is read-only.
Msg 3013, Level 16, State 1, Line 35
BACKUP DATABASE is terminating abnormally.
*/

ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
BACKUP DATABASE ROInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 0 pages for database 'ROInMemBackupTest', file 'MemOptData' on file 1.
Processed 2 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 362 pages in 0.069 seconds (40.895 MB/sec).
*/


--Tidy up after we're finished
DROP DATABASE ROInMemBackupTest;

Disclaimer

This has been tested on SQL2016SP2, as that’s what this server is, and also on SQLServer 2016 SP2 CU5. I’ve not yet tested it on anything else – feel free to let me know in the comments if it works / fails on other versions of SQL Server.

Posted in SQLServerPedia Syndication | Tagged , , , | 2 Comments

Redgate SQLPrompt – Backup your code snippets

You’ve got a new computer? And you want to copy your code snippets over?

Or you’ve got a new colleague and want to share your stuff?

Or you’ve got multiple machines an want to keep snippets in sync?

You’ll want to know about C:\Users\YourLoginName\AppData\Local\Red Gate\SQL Prompt 9\Snippets

Go on, have a look. You’ll see an assortment of XML-format files, with the extension .sqlpromptsnippet. Those are the files you’re looking for. Knock yourselves out.

Posted in SQLServerPedia Syndication | Tagged , | Leave a comment

Error: There is not enough space on the disk

I was running a query in SQL Server Management Studio (SSMS), nothing too complicated, and got this error, unexpectedly:

An error occurred while executing batch. Error message is: There is not enough space on the disk.

There’s plenty of space on the server, so what’s the problem? The problem is that we’re running a query in SSMS, and SSMS caches resultsets to your %TEMP% directory. And there’s no way to configure that, other than changing where %TEMP% actually *is*.

Just to demonstrate the problem, navigate to %TEMP% – it’s buried somewhere in the user profile AppData directory, so it’s quicker just to open a new explorer window and type %TEMP% into the navigation bar:

Look! SSMS!

However, no sign of any files containing anything useful. Open a command window at this location – quick way is to just put “cmd” into the Navbar and hit return:

That opens up a command window in the right location. Look for hidden files:

There’s the culprit (OK, it’s only 14KB here, bu tit’s a small query just to prove a point…)

To really prove the point, on this particular server, I can do it just by running this:

USE [msdb];

SELECT *
FROM [dbo].[backupset] AS [bs1],
     [dbo].[backupset] AS [bs2],
     [dbo].[backupset] AS [bs3];

…but that would risk crashing the server. So I won’t do that.

What do we learn from this, though? The main points (for me):

  • Don’t run SSMS on servers
  • Make sure there’s plenty of disk space
Posted in SQLServerPedia Syndication | Tagged , | Leave a comment

OBJECT_ID()’s second parameter

I received a supplier-supplied maintenance / check / troubleshooting script that did a whole heap of looking-to see-if-a-default-value-exists-and-if-it-doesn’t-then=create-it type stuff.

As you would expect, it’s a load of

IF NOT EXISTS (SELECT * FROM dbo.sysobjects WHERE id = OBJECT_ID(N'<<DefaultName>>') AND type = 'D')

BEGIN

    ALTER TABLE ... ADD CONSTRAINT...

END

They could have saved themselves a bit of typing (or, let’s be honest, copying-and-pasting) by replacing all those IF NOT EXISTS with

IF OBJECT_ID(N'<<DefaultName>>', N'D') IS NULL

BEGIN

    ALTER TABLE ... ADD CONSTRAINT...

END

Yes. OBJECT_ID can take a second parameter, which is the type of object to look for.

It might be worth noting that, although the type value in sys.objects is of type char(2), the type parameter in OBJECT_ID is implicitly converted to nvarchar if it’s not declared as such. Is this some far-sighted future-proofing? Check the documentation for sys.objects to see the possible values for the type field.

Posted in SQLServerPedia Syndication | Tagged | Leave a comment