Help: SQL Server

Sharing my knowlege about SQL Server Troubleshooting Skills

  • Blog Stats

    • 2,029,093 hits
  • Select GETDATE()

    February 2023
    M T W T F S S
     12345
    6789101112
    13141516171819
    20212223242526
    2728  

Posts Tagged ‘SQL’

Log Shipping Message : Skipping log backup file since load delay period has not expired

Posted by blakhani on August 21, 2014


During my last visit to one of my friend’s home I was surprised to hear that he had a problem in log shipping where he wanted my help. It was a family meet-up and I never thought it would become technical. Anyways, I asked the problem and he mentioned that he has configured log-shipping for one database between two servers. He told me that he was getting some “delay” error and I asked to give the exact error message. Below is what we saw in “Restore Job history”

2014-06-21 06:14:30.45     Starting transaction log restore. Secondary ID: ‘8a3c7cae-6df2-4c6e-b528-2062d4b830f0’
2014-06-21 06:14:30.45     Retrieving restore settings. Secondary ID: ‘8a3c7cae-6df2-4c6e-b528-2062d4b830f0’
2014-06-21 06:14:30.45     Retrieved common restore settings. Primary Server: ‘SQLPAPA’, Primary Database: ‘LogShipDemo’, Backup Destination Directory: ‘E:\LS\Secondary’, File Retention Period: 4320 minute(s)
2014-06-21 06:14:30.45     Retrieved database restore settings. Secondary Database: ‘SomeName’, Restore Delay: 2, Restore All: True, Restore Mode: No Recovery, Disconnect Users: False, Last Restored File: E:\LS\Secondary\SomeName_20140621004200.trn, Block Size: Not Specified, Buffer Count: Not Specified, Max Transfer Size: Not Specified
2014-06-21 06:14:30.51     Skipping log backup file since load delay period has not expired. Secondary DB: ‘SomeName’, File: ‘E:\LS\Secondary\SomeName_20140621004231.trn’
2014-06-21 06:14:30.51     The restore operation was successful. Secondary Database: ‘SomeName’, Number of log backup files restored: 0
2014-06-21 06:14:30.51     Deleting old log backup files. Primary Database: ‘SomeName’
2014-06-21 06:14:30.51     The restore operation was successful. Secondary ID: ‘8a3c7cae-6df2-4c6e-b528-2062d4b830f0’
2014-06-21 06:14:30.51     —– END OF TRANSACTION LOG RESTORE     —–

So the question he asked were:

  • What is this "Load delay period" and what’s the meaning of the error?
  • Can we configure this somehow, somewhere?

Answer

  • Load delay is a period what is given to secondary server to wait to restore the backup file. We can use this if we want to wait upon the copy job.
  • We can set this value in the SSMS
    Database > Right click > properties -> Transaction Log shipping -> Secondary databases -> Restore Transaction Log

image

If we want to check via T-SQL then we can see that in MSDB database of secondary server.

Select  secondary_database, 
        restore_delay 
from    msdb.dbo.log_shipping_secondary_databases

If the load delay is set to zero and still we are seeing a long delay in restore job picking the file to restore then next thing to check would be if there is a time difference between primary and secondary servers. Having different time zone is not a problem but but UTC time should match else we would see such problems.

Hope this helps!

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Author: SQL Server 2012 AlwaysOnPaperback, Kindle
  • Posted in Logshipping | Tagged: , , , | 3 Comments »

    Tips and Tricks : OS error: 32(The process cannot access the file because it is being used by another process.).

    Posted by blakhani on August 7, 2014


    While playing with tempDB database on my machine, I have made some mistake and then was not able to start one SQL Instance. As usual, started troubleshooting and used sysinternals tool to find the cause of the problem.

    First, I looked into ERRORLOG and found below messages. I have highlighted some text for clarity.

    2014-08-07 05:53:44.13 spid11s     Clearing tempdb database.
    2014-08-07 05:53:44.40 spid11s     Error: 5123, Severity: 16, State: 1.
    2014-08-07 05:53:44.40 spid11s     CREATE FILE encountered operating system error 32(The process cannot access the file because it is being used by another process.) while attempting to open or create the physical file ‘E:\TempDB\tempdb.mdf’.

    2014-08-07 05:53:45.42 spid11s     Error: 17204, Severity: 16, State: 1.
    2014-08-07 05:53:45.42 spid11s     FCB::Open failed: Could not open file E:\TempDB\tempdb.mdf for file number 1.  OS error: 32(The process cannot access the file because it is being used by another process.).
    2014-08-07 05:53:45.43 spid11s     Error: 5120, Severity: 16, State: 101.
    2014-08-07 05:53:45.43 spid11s     Unable to open the physical file "E:\TempDB\tempdb.mdf". Operating system error 32: "32(The process cannot access the file because it is being used by another process.)".
    2014-08-07 05:53:45.46 spid11s     Error: 1802, Severity: 16, State: 4.
    2014-08-07 05:53:45.46 spid11s     CREATE DATABASE failed. Some file names listed could not be created. Check related errors.
    2014-08-07 05:53:45.46 spid11s     Could not create tempdb. You may not have enough disk space available. Free additional disk space by deleting other files on the tempdb drive and then restart SQL Server. Check for additional errors in the event log that may indicate why the tempdb files could not be initialized.
    2014-08-07 05:53:45.46 spid11s     SQL Trace was stopped due to server shutdown. Trace ID = ‘1’. This is an informational message only; no user action is required.
    2014-08-07 05:53:49.68 Logon       Error: 17188, Severity: 16, State: 1.
    2014-08-07 05:53:49.68 Logon       SQL Server cannot accept new connections, because it is shutting down. The connection has been closed. [CLIENT: <local machine>]

    Due to OS Error 32, SQL was not able to use files which are needed by TempDB database and unable to start.

    Next task for us would be to find out which is that “another process”. If it’s an open handle by a use mode process we would be able to find out using Process Explorer. Once you download and run it, we can see something like below.

    image

    Then press Ctrl+F or use Menu option “Find” > “Find Handle or DLL” as shown below

    image

    In the find window provide file name with complete path and search. I was able to get below

    image

    Now, since I know that “another process” I can take the action which is suitable. This happened to me because my two instances are pointing to same location for tempdb database files. I have rectified them on non-starting instance by below steps.

    1. Started SQL Server using “Net Start MSSQL$SQL2014 /mSQLCMD /f /T3608”
    2. Connected to SQL via SQLCMD –S(local)\SQL2014
    3. Executed below T-SQL

    USE master; 
    GO 
    ALTER DATABASE tempdb 
    MODIFY FILE (NAME = tempdev, FILENAME = 'E:\Program Files\Microsoft SQL Server\MSSQL12.SQL2014\MSSQL\DATA\tempdb.mdf'); 
    GO 
    ALTER DATABASE tempdb 
    MODIFY FILE (NAME = templog, FILENAME = 'E:\Program Files\Microsoft SQL Server\MSSQL12.SQL2014\MSSQL\DATA\tempdb.ldf'); 
    GO 

     

    4. Stopped SQL via “net stop MSSQL$SQL2014”

    5. Started SQL normally.

    image

    (Click on Image to enlarge)

    Hope this would help you in troubleshooting OS Error 32 for other application as well.

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Author: SQL Server 2012 AlwaysOnPaperback, Kindle
  • Posted in Troubleshooting | Tagged: , , , , , , , , | 2 Comments »

    Tips and Tricks : BACKUP LOG … TRUNCATE_ONLY

    Posted by blakhani on July 29, 2014


    Below are the most common search terms when someone is sees a big file with extension LDF and identifies that it’s used by SQL Server.

    • LDF file is huge
    • LDF Files Too Large
    • Shrink huge LDF File SQL
    • How to Shrink LDF File

    There are many article on the internet which can explain what these files are and how to reduce the size. Here is an official KB http://support.microsoft.com/kb/317375 If the size growth is due to the fact that database is in full recovery model and no log backup taken from long time then here are few common tasks are:

    • Take a transaction log backup and then shrink the LDF file.
    • Change recovery model to simple and then shrink the file.

    One situation which I faced recently that we were even unable to change the recovery model of the database because the drive the completely full. There was no space so taking log backup was not an option. In earlier version of SQL there was a option called TRUNCATE_ONLY which is removed in later versions of SQL but in SQL 2008 onwards, we would get below error message.

    Msg 155, Level 15, State 1, Line 2
    ‘TRUNCATE_ONLY’ is not a recognized BACKUP option.

    Before attempting backup to NUL device (explained below) there are other thing you might want to try.

    • Add a new LDF file to database and take regular log backup and then shrink the log.
      • Above option would be a safe option as you still have log backups.
    • Change recovery model to simple and make it full again.
      • This will cause flush of inactive portion of log and you should be able to shrink the log.
      • Make sure you take a full backup immediate and this is your baseline.

    In certain situations the only option would be to take backup on NUL device (Yes that single L in NUL). What is NUL device? Try creating a folder with name NUL or rename a folder to NUL, you would get below error message.

    image

    [Window Title]
    Rename

    [Content]
    The specified device name is invalid.

    [OK]

    As per WikiPedia http://en.wikipedia.org/wiki/NUL:  The null device is a device file that discards all data written to it but reports that the write operation succeeded. … NUL: or NUL on DOS…
    The very important point here is “discards all data written” which means if we take backup using below command it would be reported as success but nothing is backed up.

    BACKUP DATABASE [Sales] TO  DISK = N'NUL' 
    


    Here is what we would see in ERRORLOG

    2014-07-29 07:41:07.67 Backup      Database backed up. Database: Sales, creation date(time): 2014/06/03(11:08:59), pages dumped: 315, first LSN: 48:360:37, last LSN: 48:392:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {‘NUL’}). This is an informational message only. No user action is required.

    2014-07-29 07:41:07.69 Backup      BACKUP DATABASE successfully processed 306 pages in 0.077 seconds (31.047 MB/sec).

    If we use DISK = NULL then it’s NOT The same.

    2014-07-29 07:45:50.10 Backup      Database backed up. Database: Sales, creation date(time): 2014/06/03(11:08:59), pages dumped: 316, first LSN: 49:16:37, last LSN: 49:48:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {‘E:\Program Files\Microsoft SQL Server\MSSQL12.SQL2014\MSSQL\Backup\NULL’}). This is an informational message only. No user action is required.

    2014-07-29 07:45:50.20 Backup      BACKUP DATABASE successfully processed 306 pages in 0.289 seconds (8.272 MB/sec).

    IMPORTANT: Taking backup like this would break the log chain which means next log backup would not be restorable. Here is what I mean.

    create database TestMe
    go
    alter database TestMe set recovery full
    go
    /*
    Command(s) completed successfully.
    */
    use TestMe
    go
    backup database TestMe to disk = 'F1.bak'
    go
    /*
    Processed 296 pages for database 'TestMe', file 'TestMe' on file 1.
    Processed 3 pages for database 'TestMe', file 'TestMe_log' on file 1.
    BACKUP DATABASE successfully processed 299 pages in 0.363 seconds (6.435 MB/sec).
    */
    use TestMe
    go
    Create Table TestTable1 (i int)
    go
    backup log TestMe to disk = 'T1.trn'
    go
    /*
    Processed 6 pages for database 'TestMe', file 'TestMe_log' on file 1.
    BACKUP LOG successfully processed 6 pages in 0.205 seconds (0.209 MB/sec).
    */
    use TestMe
    go
    Create Table TestTable2 (i int)
    go
    backup log TestMe to disk = 'NUL'
    go
    /*
    Processed 1 pages for database 'TestMe', file 'TestMe_log' on file 1.
    BACKUP LOG successfully processed 1 pages in 0.001 seconds (7.812 MB/sec).
    */
    use TestMe
    go
    Create Table TestTable3 (i int)
    go
    backup log TestMe to disk = 'T2.trn'
    go
    /*
    Processed 1 pages for database 'TestMe', file 'TestMe_log' on file 1.
    BACKUP LOG successfully processed 1 pages in 0.133 seconds (0.058 MB/sec).
    */
    
    use master 
    go
    drop database TestMe
    go
    
    
    

    Here is the attempt to restore the backups.

    USE [master]
    go
    RESTORE DATABASE [TestMe] FROM  DISK = N'F1.bak' WITH NORECOVERY,  NOUNLOAD,  STATS = 5
    GO
    RESTORE LOG [TestMe] FROM  DISK = N'T1.trn' WITH NORECOVERY,  NOUNLOAD,  STATS = 5
    GO
    RESTORE LOG [TestMe] FROM  DISK = N'T2.trn' WITH NORECOVERY,  NOUNLOAD,  STATS = 5
    GO
    

    and the error while restoring T2 is below

    Msg 4305, Level 16, State 1, Line 6

    The log in this backup set begins at LSN 48000000022400001, which is too recent to apply to the database. An earlier log backup that includes LSN 48000000020800001 can be restored.

    Msg 3013, Level 16, State 1, Line 6

    RESTORE LOG is terminating abnormally.


    Hope this gives you some idea about usage of backup to NUL device and danger as well.

  • Cheers,
  • Balmukund Lakhani
  • Twitter @blakhani
  • Posted in Tips and Tricks | Tagged: , , | 4 Comments »