3

The Configuration Primary DB SQL Server 2008 R2 SP3 Web Edition running in windows Server 2012 R2 x64 on a local RAID 10 SAS 10k disk array co-located in an enterprise grade datacentre Secondary DB SQL Server 2008 R2 SP3 Web Edition running in a Hyper-V windows Server 2012 R2 x64 VM using a QNAP NAS (iSCSI) RAID 10 SAS 10k disk array in our head office server room The two instances are connected via a dedicated hardware VPN over fibre connection

The problem Upon configuring a secondary log shipping for one of the databases (read only mode), it appears to work well for a day or two then randomly on one of the LS_Restore sql agent jobs the restore fails and the database is found to be in SUSPECT mode. See the SQL error log below. We have set it up and torn it down about 4 times and still the same happens each time...

After quite a bit of research based on the warnings about the tail of the log and the misaligned IO, I suspect the cause could be related to the fact the virtual disks created by Hyper-V at the destination (secondary log shipped DB) are using the new 4K native format whilst the disks on the source are using the more common 512E standard (see screen captures below). The bytes per physical sector and bytes per cluster are different!

Does this sound plausible or has anyone else had this issue and if so what did you do to resolve it?

UPDATE: found this KB which exactly describes my problem but it only applies to SP2 not SP3: https://support.microsoft.com/en-us/kb/2987585

SQL Log file

03/11/2016 22:00:07,spid57,Unknown,An error occurred while processing the log for database 'QfsFinancial'.  If possible<c/> restore from backup. If a backup is not available<c/> it might be necessary to rebuild the log.
03/11/2016 22:00:07,spid57,Unknown,Error: 9004<c/> Severity: 16<c/> State: 6.
03/11/2016 22:00:07,spid57,Unknown,There have been 16128 misaligned log IOs which required falling back to synchronous IO.  The current IO is on file E:\Databases\QFSFinancial\LOG\QfsFinancial_log.ldf.
03/11/2016 22:00:05,spid57,Unknown,The database 'QfsFinancial' is marked RESTORING and is in a state that does not allow recovery to be run.
03/11/2016 22:00:05,spid57,Unknown,Starting up database 'QfsFinancial'.
03/11/2016 22:00:05,Backup,Unknown,Log was restored. Database: QfsFinancial<c/> creation date(time): 2015/06/30(22:41:11)<c/> first LSN: 205383:118850:1<c/> last LSN: 205383:120116:1<c/> number of dump devices: 1<c/> device information: (FILE=1<c/> TYPE=DISK: {'E:\LogShippedLogs\QfsFinancial_20160311081500.trn'}). This is an informational message. No user action is required.
03/11/2016 22:00:05,spid57,Unknown,CHECKDB for database 'QfsFinancial' finished without errors on 2016-03-06 02:15:14.853 (local time). This is an informational message only; no user action is required.
03/11/2016 22:00:05,spid57,Unknown,Starting up database 'QfsFinancial'.
03/11/2016 22:00:04,spid57,Unknown,Recovery is writing a checkpoint in database 'QfsFinancial' (8). This is an informational message only. No user action is required.
03/11/2016 22:00:04,spid57,Unknown,The tail of the log for database QfsFinancial is being rewritten to match the new sector size of 4096 bytes.  2048 bytes at offset 62089216 in file E:\Databases\QFSFinancial\LOG\QfsFinancial_log.ldf will be written.
03/11/2016 22:00:04,spid57,Unknown,The database 'QfsFinancial' is marked RESTORING and is in a state that does not allow recovery to be run.
03/11/2016 22:00:04,spid57,Unknown,Starting up database 'QfsFinancial'.
03/11/2016 22:00:03,Backup,Unknown,Log was restored. Database: QfsFinancial<c/> creation date(time): 2015/06/30(22:41:11)<c/> first LSN: 205383:113524:1<c/> last LSN: 205383:118850:1<c/> number of dump devices: 1<c/> device information: (FILE=1<c/> TYPE=DISK: {'E:\LogShippedLogs\QfsFinancial_20160311080000.trn'}). This is an informational message. No user action is required.
03/11/2016 22:00:03,spid57,Unknown,CHECKDB for database 'QfsFinancial' finished without errors on 2016-03-06 02:15:14.853 (local time). This is an informational message only; no user action is required.
03/11/2016 22:00:03,spid57,Unknown,Starting up database 'QfsFinancial'.
03/11/2016 22:00:03,spid57,Unknown,Recovery completed for database QfsFinancial (database ID 8) in 1 second(s) (analysis 204 ms<c/> redo 0 ms<c/> undo 82 ms.) This is an informational message only. No user action is required.
03/11/2016 22:00:03,spid57,Unknown,Recovery is writing a checkpoint in database 'QfsFinancial' (8). This is an informational message only. No user action is required.
03/11/2016 22:00:02,spid57,Unknown,The tail of the log for database QfsFinancial is being rewritten to match the new sector size of 4096 bytes.  3072 bytes at offset 61441024 in file E:\Databases\QFSFinancial\LOG\QfsFinancial_log.ldf will be written.
03/11/2016 22:00:02,spid57,Unknown,The database 'QfsFinancial' is marked RESTORING and is in a state that does not allow recovery to be run.
03/11/2016 22:00:02,spid57,Unknown,Starting up database 'QfsFinancial'.
03/11/2016 22:00:00,spid57,Unknown,Setting database option SINGLE_USER to ON for database QfsFinancial.

Disk format on source server

Microsoft Windows [Version 6.3.9600]
(c) 2013 Microsoft Corporation. All rights reserved.

C:\Windows\system32>fsutil fsinfo ntfsinfo E:
NTFS Volume Serial Number :       0x58b83b05b83ae164
NTFS Version   :                  3.1
LFS Version    :                  2.0
Number Sectors :                  0x000000008bb83fff
Total Clusters :                  0x00000000117707ff
Free Clusters  :                  0x000000000117e33c
Total Reserved :                  0x0000000000000780
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 :           0x000000000b180000
Mft Start Lcn  :                  0x00000000000c0000
Mft2 Start Lcn :                  0x0000000000000002
Mft Zone Start :                  0x000000000482eb60
Mft Zone End   :                  0x0000000004830000
Resource Manager Identifier :     CC229DD7-1DBF-11E4-80B4-A0D3C1F1E137

C:\Windows\system32>

Disk format on destination server

Microsoft Windows [Version 6.3.9600]
(c) 2013 Microsoft Corporation. All rights reserved.

C:\Windows\system32>fsutil fsinfo ntfsinfo E:
NTFS Volume Serial Number :       0x827ec3877ec37289
NTFS Version   :                  3.1
LFS Version    :                  2.0
Number Sectors :                  0x00000000bb7fe7ff
Total Clusters :                  0x000000000176ffcf
Free Clusters  :                  0x0000000000a1e4f8
Total Reserved :                  0x0000000000000000
Bytes Per Sector  :               512
Bytes Per Physical Sector :       4096
Bytes Per Cluster :               65536
Bytes Per FileRecord Segment    : 1024
Clusters Per FileRecord Segment : 0
Mft Valid Data Length :           0x00000000000c0000
Mft Start Lcn  :                  0x000000000000c000
Mft2 Start Lcn :                  0x0000000000000001
Mft Zone Start :                  0x000000000000c000
Mft Zone End   :                  0x000000000000cca0
Resource Manager Identifier :     EE6D99B6-DC5D-11E5-80E2-00155D323B15

C:\Windows\system32>
2
  • 1
    The misaligned IOs, while not great, probably isn't the root cause. More info: blogs.msdn.microsoft.com/saponsqlserver/2014/10/01/… Mar 13, 2016 at 1:32
  • While the "error" is not fatal for actual restores (will have implications for restore and log performance due to misalignment), any error returned during a restore will stop the log shipping processes dead in its tracks. Fix your storage alignment to match between primary and secondary as recommended by the PSS link Sean listed. Mar 13, 2016 at 6:06

1 Answer 1

2

I have uninstalled SP3 and installed SP2 then the hotfix (KB2987585) I mention in my question and finally reinstalled SP3. So far so good - I will update once we have had a few successful days of log shipping.

It appears that the problem has been resolved as per my comment above. After rolling back to SP2 (with no SP2 CU's else the fix wouldn't install) and installing the KB2987585 hotfix and enabling the hotfix's associated trace flag then reapplying SP3 all my issues have gone away and it has been running smoothly for 5 days now with no warnings or the database going into SUSPECT mode.

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.