Help: SQL Server

Sharing my knowlege about SQL Server Troubleshooting Skills

  • Blog Stats

    • 2,153,605 hits
  • Select GETDATE()

    December 2025
    M T W T F S S
    1234567
    891011121314
    15161718192021
    22232425262728
    293031  

Archive for the ‘SQL Server’ Category

SQL Internals : Useful Parameters for xp_readerrorlog

Posted by blakhani on December 10, 2014


I know that most of you have been using sp_readerrorlog for long time. While working with SSMS, I noticed that we have options to put filters on various parameter. I became curious to know what is done in the background.

If we look at code of sp_readerrorlog using sp_helptext system procedure, this is the output.

create proc sys.sp_readerrorlog(
    @p1        int = 0,
    @p2        int = NULL,
    @p3        nvarchar(4000) = NULL,
    @p4        nvarchar(4000) = NULL)
as
begin

    if (not is_srvrolemember(N'securityadmin') = 1)
    begin
       raiserror(15003,-1,-1, N'securityadmin')
       return (1)
    end
    
    if (@p2 is NULL)
        exec sys.xp_readerrorlog @p1
    else
        exec sys.xp_readerrorlog @p1,@p2,@p3,@p4
end


Which means that under the cover, xp_readerrorlog is being used by sp_readerrorlog. Coming back to SSMS, here is the snip of information taken from profiler while launching Log File Viewer. I have done some formatting to make it look proper.

-- Below is the way SSMS Reads the ErrorLog. Can be found via profiler

Declare @InstanceName nvarchar(4000),
        @ArchiveID int,
        @Filter1Text nvarchar(4000),
        @Filter2Text nvarchar(4000),
        @FirstEntry datetime,
        @LastEntry datetime

Select  @InstanceName=NULL,
        @ArchiveID=0,
        @Filter1Text='recovery',
        @Filter2Text='mydb',
        @FirstEntry='2014-11-22 07:14:46.930',
        @LastEntry='2014-11-22 07:14:50.020'

EXEC master.dbo.xp_readerrorlog @ArchiveID, 1, @Filter1Text, @Filter2Text, @FirstEntry, @LastEntry, N'asc', @InstanceName 

 

That gives us a lot of hint about the parameters of xp_readerrorlog. Here is the explanation.

Parameter Name Usage
@ArchiveID Extension of the file which we would like to read.

0 = ERRORLOG/SQLAgent.out

1 = ERRORLOG.1/SQLAgent.1  and so on

@LogType 1 for SQL Server ERRORLOG (ERRORLOG.*)

2 for SQL Agent Logs (SQLAgent.*)
@FilterText1 First Text filter on data
@FilterText2 Another Text filter on data. Output would be after applying both filters, if specified
@FirstEntry Start Date Filter on Date time in the log
@LastEntry End Date Filter on Date time in the log
@SortOrder ‘asc’ or ‘desc’ for sorting the data based on time in log.

 

Sample with explanation

I have customized the script so that you can copy paste in your environment and put the values.

Declare @InstanceName nvarchar(4000),
        @LogType int,
        @ArchiveID int,
        @Filter1Text nvarchar(4000),
        @Filter2Text nvarchar(4000),
        @FirstEntry datetime,
        @LastEntry datetime

Select  @InstanceName=NULL,          -- Don't know 🙂
        @LogType = 2,                -- File Type (1 = ERRORLOG OR 2 = SQLAgent)
        @ArchiveID=3,                -- File Extension (0 = Current i.e. ERRORLOG or SQLAgent.out, 1 = ERRORLOG.1 or SQLAgent.1 and so on)
        @Filter1Text='Waiting',      -- First Text Filter
        @Filter2Text=NULL,           -- Second Text Filter
        @FirstEntry=NULL,            -- Start Date
        @LastEntry=NULL              -- End Date

EXEC master.dbo.xp_readerrorlog @ArchiveID, @LogType, @Filter1Text, @Filter2Text, @FirstEntry, @LastEntry, N'asc', @InstanceName 

Here are few samples

Example 1

Read ERRORLOG and apply filter for ‘login failed’ and ‘sa’

Declare @InstanceName nvarchar(4000),
        @LogType int,
        @ArchiveID int,
        @Filter1Text nvarchar(4000),
        @Filter2Text nvarchar(4000),
        @FirstEntry datetime,
        @LastEntry datetime

Select  @InstanceName=NULL,          -- Don't know 🙂
        @LogType = 1,                -- 1 = ERRORLOG
        @ArchiveID=0,                -- File Extension 0 
        @Filter1Text='Login failed', -- First Text Filter
        @Filter2Text='sa',           -- Second Text Filter
        @FirstEntry=NULL,            -- Start Date
        @LastEntry=NULL              -- End Date

EXEC master.dbo.xp_readerrorlog @ArchiveID, @LogType, @Filter1Text, @Filter2Text, @FirstEntry, @LastEntry, N'asc', @InstanceName 

Here is the output

 

Example 2

In above example, let’s apply date time filer as well. We will filter records only for 05-Dec-2014.

Declare @InstanceName nvarchar(4000),
        @LogType int,
        @ArchiveID int,
        @Filter1Text nvarchar(4000),
        @Filter2Text nvarchar(4000),
        @FirstEntry datetime,
        @LastEntry datetime

Select  @InstanceName=NULL,                  -- Don't know 🙂
        @LogType = 1,                        -- 1 = ERRORLOG
        @ArchiveID=0,                        -- File Extension 0 
        @Filter1Text='Login failed',         -- First Text Filter
        @Filter2Text='sa',                   -- Second Text Filter
        @FirstEntry='2014-12-05 00:00:00',   -- Start Date
        @LastEntry='2014-12-05 23:59:59'     -- End Date

EXEC master.dbo.xp_readerrorlog @ArchiveID, @LogType, @Filter1Text, @Filter2Text, @FirstEntry, @LastEntry, N'asc', @InstanceName 

As expected, the output is similar to Example 1 but with date filter applied.

Example 3

In this example, we are trying to read Read SQLAgent.3 (i.e. LogType = 2 and ArchiveID = 3) and output should be descending date time.

Declare @InstanceName nvarchar(4000),
        @LogType int,
        @ArchiveID int,
        @Filter1Text nvarchar(4000),
        @Filter2Text nvarchar(4000),
        @FirstEntry datetime,
        @LastEntry datetime

Select  @InstanceName=NULL,    -- Don't know 🙂
        @LogType = 2,          -- 2 = SQLAgent
        @ArchiveID=3,          -- File Extension 3 
        @Filter1Text=NULL,     -- First Text Filter
        @Filter2Text=NULL,     -- Second Text Filter
        @FirstEntry=NULL,      -- Start Date
        @LastEntry=NULL        -- End Date

EXEC master.dbo.xp_readerrorlog @ArchiveID, @LogType, @Filter1Text, @Filter2Text, @FirstEntry, @LastEntry, N'DESC', @InstanceName

Here is the output.

Hope this gives you an understanding of neat way of reading SQL Server ERRORLOG and SQLAgent logs.

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Posted in Internals, SQL Server | Tagged: , , , | 4 Comments »

    Help : How to suppress DBCC TRACEON/OFF messages in the Error Log?

    Posted by blakhani on December 9, 2014


    This has been asked into a forum recently (here). I remember that there was a way in SQL 7.0 so I searched and found KB 243352. As per KB article trace Flag 2505 can do that. I decided to test in SQL Server 2014 to see if it still works and I was happy to see that it is still working.

    Trace flag 2505 works as DBCC TRACEON and Startup parameter as well. Here is the script to test it.

    -- recycle the error log
    EXEC sp_cycle_errorlog
    -- turn on deadlock logging trace flag 
    DBCC TRACEON (1222, -1)
    GO
    -- Read ERRORLOG using filter.
    EXEC xp_readerrorlog 0, 1, N'dbcc'
    go
    -- turn off deadlock logging trace flag 
    DBCC TRACEOFF (1222, -1)
    GO
    --Read ERRORLOG
    EXEC xp_readerrorlog 0, 1, N'dbcc'
    go
    -- Now magic trace flag
    DBCC TRACEON (2505, -1)
    GO
    -- 1204 to check if this is logged.
    DBCC TRACEON (1204, -1)
    GO
    -- read ERRORLOG again
    EXEC xp_readerrorlog 0, 1, N'dbcc'
    go
    -- Turn off magic trace flag
    DBCC TRACEOFF (2505, -1)
    GO
    
    
    After 1222 Turn ON

    LogDate ProcessInfo Text ----------------------- ------------ ------------------------------------------------------------------------------------------------------------------- 2014-12-09 05:14:03.920 spid59 DBCC TRACEON 1222, server process ID (SPID) 59. This is an informational message only; no user action is required. (1 row(s) affected)
    After 1222 Turn OFF LogDate ProcessInfo Text ----------------------- ------------ ----------------------------------------------------------------------------------------------------------------- 2014-12-09 05:14:03.920 spid59 DBCC TRACEON 1222, server process ID (SPID) 59. This is an informational message only; no user action is required. 2014-12-09 05:14:03.970 spid59 DBCC TRACEOFF 1222, server process ID (SPID) 59. This is an informational message only; no user action is required. (2 row(s) affected)


    After 2505 and 1204 were ON LogDate ProcessInfo Text ----------------------- ------------ ----------------------------------------------------------------------------------------------------------------- 2014-12-09 05:14:03.920 spid59 DBCC TRACEON 1222, server process ID (SPID) 59. This is an informational message only; no user action is required. 2014-12-09 05:14:03.970 spid59 DBCC TRACEOFF 1222, server process ID (SPID) 59. This is an informational message only; no user action is required.

    As we can see in last output, there are no additional entries made in ERRORLOG for 1204. Interestingly there is no entry for 2505 itself. 

    Note that this trace flag is not listed in documentation other than SQL 7.0 KB article which I mentioned above. So please don’t shoot me if it doesn’t work in any version other than SQL 7.0 but I don’t see any reason why this functionality would be removed.

    Hope this helps.

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Posted in SQL Server, Trace Flag | Tagged: , , , , , | 2 Comments »

    Explanation : Error: 5125, Severity: 24, State: 2

    Posted by blakhani on December 4, 2014


    While playing with log shipping and backup restore, one of my database gone bad and was not coming online. I checked ERRORLOG and found below messages.

    2014-11-20 22:16:59.37 spid51s     Error: 5125, Severity: 24, State: 2.
    2014-11-20 22:16:59.37 spid51s     File ‘C:\SQLServerData\MyTestLogShippping.ndf’ appears to have been truncated by the operating system.  Expected size is 19325 KB but actual size is 0 KB.

     

    The error message is pretty clear and takes away blame from SQL Server. I checked the size of MyTestLogShippping.ndf and it was indeed zero KB. In my case, I was copying the file over the network and something might have gone wrong during that. It is clear that SQL Server checked for “expected” size and “actual” size during recovery of database and if there is a mismatch, above error is logged.

    What can be done to fix the issue? Well, restore from backup is option to get out from this situation. Or, if you can get back the original copy of the problematic file (which is close to impossible) then use that for recovery.

    If its frequent on your environment then you may need to check if you have some third party tool which is doing disk defragmentation.

    hope this helps.

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Posted in Error, SQL Server | Tagged: , , | 1 Comment »