Dear All,

I have a Primary Site & trying to setup a DR site. I created a Log shipping between the two database, Backup & Copy jobs works fine. Restore also works fine for the 1st time however after that restore fails & database goes to Recovery mode (showing restoring) from the Standby Mode.

The Backup & Copy folders have correct permissions & i am using AD account to run the Agent service on both the servers.

Please advise what could be wrong.

Below is the restore log.

Message
current state is closed.(System.Data) ***
2015-01-23 11:50:13.28 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 Skipping log backup file 'E:\foldername\xxxxxxxx.trn' for secondary database 'Databasename' because the file could not be verified.
2015-01-23 11:50:13.37 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 *** Error: An error occurred restoring the database access mode.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteScalar requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 *** Error: An error occurred restoring the database access mode.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteScalar requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.37 Deleting old log backup files. Primary Database: 'databasename'
2015-01-23 11:50:13.37 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.37 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.39 The restore operation completed with errors. Secondary ID: 'eb149c41-c657-4f42-925c-6cd635addcb9'
2015-01-23 11:50:13.39 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.39 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.39 *** Error: Could not cleanup history.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-23 11:50:13.39 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-23 11:50:13.39 ----- END OF TRANSACTION LOG RESTORE --

is this the full log?

Could you try manually restoring that one tlog which is being skipped and then see if others are getting restored?

Dear Ashwin,

The log is not full & this happens with all the databases for which is setup for the new Log shipping job.

please post the full log especially what is before the start

current state is closed.(System.Data) ***

Also could you try restoring the tlog mentioned in the log file for any one database and see if it works fine?

Dear Arvind,

I created a fresh SQL Log shipping database & executed Backup / Copy & Restore manually. The Restore worked 3 times well.

However 4th time it failed. Below is the  log for all the restore jobs. After the restore job fails, database goes in to restoring mode. I had selected Standby mode with Disconnect users during restore option.



2nd Restore JOb
====================

2015-01-28 18:45:00.58 Found first log backup file to restore. Secondary DB: 'Databasename', File: 'D:\SQLTRANLOG\Databasename\Databasename_20150128130010.trn'
2015-01-28 18:45:00.58 Disconnecting users. Secondary DB: 'Live'

3rd Restore Job
=====================

Message
2015-01-28 18:49:14.19 Restored log backup file. Secondary DB: 'Databasename', File: 'D:\SQLTRANLOG\Databasename\Databasename_20150128131510.trn'
2015-01-28 18:49:14.20 The restore operation was successful. Secondary Database: 'Databasename', Number of log backup files restored: 1
2015-01-28 18:49:14.20 Deleting old log backup files. Primary Database: 'Databasename'
2015-01-28 18:49:14.20 The restore operation was successful. Secondary ID: '41768b41-6728-4aa3-8662-f543fd6bd65f'
2015-01-28 18:49:14.21 ----- END OF TRANSACTION LOG RESTORE     -----

4th Restore Job
================

2015-01-28 18:52:39.18 ----- START OF TRANSACTION LOG RESTORE   -----
2015-01-28 18:52:39.24 Starting transaction log restore. Secondary ID: '41768b41-6728-4aa3-8662-f543fd6bd65f'
2015-01-28 18:52:39.24 Retrieving restore settings. Secondary ID: '41768b41-6728-4aa3-8662-f543fd6bd65f'

Message
2015-01-28 18:52:39.25 Retrieved common restore settings. Primary Server: 'Servername', Primary Database: 'Databasename', Backup Destination Directory: 'D:\SQLTRANLOG\Databasename', File Retention Period: 4320 minute(s)
2015-01-28 18:52:39.25 Retrieved database restore settings. Secondary Database: 'Databasename', Restore Delay: 0, Restore All: True, Restore Mode: Standby, Disconnect Users: True, Last Restored File: D:\SQLTRANLOG\Databasename\Databasename_20150128131510.trn, Block Size: Not Specified, Buffer Count: Not Specified, Max Transfer Size: Not Specified
2015-01-28 18:52:39.31 Disconnecting users. Secondary DB: 'Databasename'

015-01-28 18:52:41.41 *** Error: Could not apply log backup file 'D:\SQLTRANLOG\Databasename\Databasename_20150128132214.trn' to secondary database 'Databasename'.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.41 *** Error: An error occurred while processing the log for database 'Databasename'.  If possible, restore from backup. If a backup is not available, it might be necessary to rebuild the log.
An error occurred during recovery, preventing the database 'Databasename' (5:0) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support.
RESTORE LOG is terminating abnormally.
Processed 0 pages for database 'Databasename', file 'Databasename' on file 1.
Processed 1 pages for database 'Databasename', file 'Databasename_log' on file 1.(.Net SqlClient Data Provider) ***
2015-01-28 18:52:41.41 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 Skipping log backup file 'D:\SQLTRANLOG\Databasename\Databasename_20150128132214.trn' for secondary database 'Databasename' because the file could not be verified.
2015-01-28 18:52:41.43 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 *** Error: An error occurred restoring the database access mode.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteScalar requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 *** Error: An error occurred restoring the database access mode.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteScalar requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 Deleting old log backup files. Primary Database: 'Databasename'
2015-01-28 18:52:41.43 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 The restore operation completed with errors. Secondary ID: '41768b41-6728-4aa3-8662-f543fd6bd65f'
2015-01-28 18:52:41.43 *** Error: Could not log history/error message.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.43 *** Error: Could not cleanup history.(Microsoft.SqlServer.Management.LogShipping) ***
2015-01-28 18:52:41.43 *** Error: ExecuteNonQuery requires an open and available Connection. The connection's current state is closed.(System.Data) ***
2015-01-28 18:52:41.44 ----- END OF TRANSACTION LOG RESTORE     -----

Message
Executed as user: Domainname\Username. The step failed.

I tried restoring the log manually and I could restore it

Processed 0 pages for database 'Database_live', file 'Database_Live' on file 1.
Processed 1 pages for database 'Database_live', file 'Database_Live_log' on file 1.
RESTORE LOG successfully processed 1 pages in 0.005 seconds (0.390 MB/sec).

Monitor whether you still get the error for other logs that will follow.

Also check whether there is any issue with the disks where the ldf file resides, you could check with system team and ask them to do proper check on the file s

Dear Ashwin,

The other restore jobs are also failing. However If i try to restore individual log files its getting restored. There is no issues with the disk.

Hi Sanjay,

What the version of your SQL Server?

If you are running SQL Server 2008 R2, please apply Microsoft SQL Server 2008 R2 SP3.

If you are running SQL Server 2012, please use one of the following workarounds to resolve the issue.

Move the transaction log file at the destination to a drive that has "Bytes per Physical Sector" set as 512 bytes.

Note: The Standby file can still be located on the drive that has "Bytes per Physical Sector" set as 4096 bytes.

Restore the log backups without using the standby option. Instead of the STANDBY option, use the WITH NORECOVERY option during the restore operation.

For more details, please review the following KB article:

Restore Log with Standby Mode on an Advanced Format disk may cause a 9004 error in SQL Server 2008 R2 or SQL Server 2012: http://support.microsoft.com/kb/2987585



Thanks,
Lydia

Hello Lydia,

I am using SQL 2012. from the KB i saw that there is a hotfix for SQL 2008. Any idea if there is an hotfix for 2012 also.? As i need to have the DB in the read mode available as it will be used by my reporting server as well.

Note:- I also have an instance of SQL 2008 on the same server & log shipping for the SQL 2008 on the same server & same drive works perfectly fine.

Hi,

What is the SQL Version on Primary & Secondary servers?

HI,

We are using SQL 2012 at both ends wit

Hi Sanjay,

Have you checked the "Bytes per Physical Sector" of the drive where transaction log file locates?

As described in the above KB article, to resolve the issue, you can move the transaction log file at the destination to a drive that has "Bytes per Physical Sector" set as 512 bytes.


Thanks,
Lydia Zhang

Hi,

Below is the output on the Destination sql server where trans logs are getting copied.

Free Clusters  :                  0x000000000189f2c1
Total Reserved :                  0x0000000000000000
Bytes Per Sector  :               512
Bytes Per Cluster :               4096
Bytes Per FileRecord Segment    : 1024
Clusters Per FileRecord Segment : 0

However I tried restoring the log file from another machine as well which had below output but from there also it has failed.

Number Sectors :                  0x0000000009dbe7ff
Total Clusters :                  0x00000000013b7cff
Free Clusters  :                  0x0000000000fec22a
Total Reserved :                  0x0000000000000000
Bytes Per Sector  :               512
Bytes Per Physical Sector :    512
Bytes Per Cluster :               4096
Bytes Per FileRecord Segment    : 1024
Clusters Per FileRecord Segment : 0
Mft Valid Data Length :           0x0000000001840000

How about using WITH NORECOVERY option ? fail as well? If so, raise Microsoft support, maybe it is a bug. 

With NORecovery it works fine. But i need the database in Readonly mode & hence I need Standby Option

Option set as With NORecovery works fine. But it fails if i try to setup a log shipping in Standby / Readonly Mode.