SQL Server Cluster Installation Failed

Question

I need help trying to solve this as I've spent tons of time trying to figure this out but have had no luck. I created a VMWare Workstation test environment and I have been trying to install SQL Cluster on one of my Nodes.

From the looks of it, it looks like it's a storage configuration problem but at this point I have no idea what else I could do and there isn't much online about it. Please look at the log and any input would be appreciated.

2016-03-06 19:02:50.76 Server      Microsoft SQL Server 2014 - 12.0.2000.8 (X64) 
    Feb 20 2014 20:04:26 
    Copyright (c) Microsoft Corporation
    Enterprise Edition (64-bit) on Windows NT 6.3 <X64> (Build 9600: ) (Hypervisor)

2016-03-06 19:02:50.76 Server      UTC adjustment: -8:00
2016-03-06 19:02:50.76 Server      (c) Microsoft Corporation.
2016-03-06 19:02:50.76 Server      All rights reserved.
2016-03-06 19:02:50.76 Server      Server process ID is 1860.
2016-03-06 19:02:50.76 Server      System Manufacturer: 'VMware, Inc.', System Model: 'VMware Virtual Platform'.
2016-03-06 19:02:50.76 Server      Authentication mode is WINDOWS-ONLY.
2016-03-06 19:02:50.76 Server      Logging SQL Server messages in file 'M:\MSSQL12.SQLCLUST14INS1\MSSQL\Log\ERRORLOG'.
2016-03-06 19:02:50.76 Server      The service account is 'UVIT\administrator'. This is an informational message; no user action is required.
2016-03-06 19:02:50.76 Server      Registry startup parameters: 
     -d M:\MSSQL12.SQLCLUST14INS1\MSSQL\DATA\master.mdf
     -e M:\MSSQL12.SQLCLUST14INS1\MSSQL\Log\ERRORLOG
     -l M:\MSSQL12.SQLCLUST14INS1\MSSQL\DATA\mastlog.ldf
2016-03-06 19:02:50.76 Server      Command Line Startup Parameters:
     -s "SQLCLUST14INS1"
2016-03-06 19:02:51.02 Server      SQL Server detected 1 sockets with 1 cores per socket and 1 logical processors per socket, 1 total logical processors; using 1 logical processors based on SQL Server licensing. This is an informational message; no user action is required.
2016-03-06 19:02:51.02 Server      SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.
2016-03-06 19:02:51.02 Server      Detected 2047 MB of RAM. This is an informational message; no user action is required.
2016-03-06 19:02:51.02 Server      Using conventional memory in the memory manager.
2016-03-06 19:02:51.07 Server      Default collation: SQL_Latin1_General_CP1_CI_AS (us_english 1033)
2016-03-06 19:02:51.17 Server      Query Store settings initialized with enabled = 1, 
2016-03-06 19:02:51.18 Server      This instance of SQL Server last reported using a process ID of 1696 at 3/2/2016 12:33:34 PM (local) 3/2/2016 8:33:34 PM (UTC). This is an informational message only; no user action is required.
2016-03-06 19:02:51.18 Server      The maximum number of dedicated administrator connections for this instance is '1'
2016-03-06 19:02:51.18 Server      Node configuration: node 0: CPU mask: 0x0000000000000001:0 Active CPU mask: 0x0000000000000001:0. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required.
2016-03-06 19:02:51.18 Server      Using dynamic lock allocation.  Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node.  This is an informational message only.  No user action is required.
2016-03-06 19:02:51.20 Server      CLR version v4.0.30319 loaded.
2016-03-06 19:02:51.44 spid8s      Starting up database 'master'.
2016-03-06 19:02:51.47 spid8s      There have been 256 misaligned log IOs which required falling back to synchronous IO.  The current IO is on file M:\MSSQL12.SQLCLUST14INS1\MSSQL\DATA\master.mdf.
2016-03-06 19:02:51.48 spid8s      Unable to create stack dump file due to stack shortage (ex_terminator - Last chance exception handling)
2016-03-06 19:02:51.48 spid8s      Stack Signature for the dump is 0x0000000000000000
2016-03-06 19:02:51.51 spid8s      [INFO]          Identity             Begin               End |        State                  Result     Error  Speculate   Prepared LazyCommit   ReadOnly |      Transaction         Database          ThreadId |   ReadSet  WriteSet   ScanSet Savepoint LogSizeRq | CommitDep TotalComm       Dependent 0       Dependent 1       Dependent 2       Dependent 3       Dependent 4       Dependent 5       Dependent 6       Dependent 7 |            Area  Location |
2016-03-06 19:02:51.57 Server      Software Usage Metrics is enabled.
2016-03-06 19:02:52.74 spid8s      External dump process return code 0x20000001.
External dump process returned no errors.

Answer 1

I wanted to respond with my fix to the issue just incase anyone is doing a test environment with VMWorkstation/FreeNas. So it looks like my issue was in the formatting of the physical drive on my PC. I had done the above and while everything matched to SQL best practices I still received the error. It was until I scrapped everything and formatted the physical drive on my pc that I was assigning to the FreeNas that everything seemed to work. Til this day I don't completely 100% understand it but since I did that, installed with zero issues.

My Scenario looked like this: Physical SSD on PC -> VMWare HDD Image -> FreeNas -> SQLNodes Shared Storage Physical SSD was formatted with 512 512 4096 1024 while when on FreeNas shared storage it was 512 4096 64k 1024. This scenario didn't work.

Once I set my Physical SSD to 512 512 64k 1024 and Shared Storage to 512 4096 64k 1024. It worked on first try with zero issues.

Again this to me makes no sense at least don't understand it 100% but it works now. At first I was going crazy with the formatting the storage within the VMs/FreeNas that I tried multiple combinations and nothing worked until I did this.

Answer 2

If your question is about the log entry:

There have been 256 misaligned log IOs which required falling back to synchronous IO...

...you should read the following MSDN article by Cameron - MSFT SAP Program Manager:

Message misaligned log IOs which required falling back to synchronous IO in SQL Server Error Log

...and the linked references there.

From that article:

Some flash based devices like Fusion-io and new large capacity disks such as 4TB SATA disks are commonly using Native 4K format. The new disk format can lead to warnings in the SQL Server errorlog when log records are written in 512 or 512E format and restored on 4k Native format.

SQL Server detects the physical disk sector size and aligns transaction log internal boundaries to match (either 512 or 4096 bytes). Error message 9012 is generated when SQL Server detects that log entries have been written assuming a different sector size.

You can check the disk sector size using:

fsutil fsinfo ntfsinfo <drive letter>

Disk containing SQL Server files should be formatted 64K at the Windows NTFS layer.

Answer 3

I'm afraid we'll all have separate solutions, but I wanted to describe the resolution for a specific environment.

SQL Server 2016 Failover Cluster, using FreeNAS 9.3, exposed via a file iSCSI extent. The physical drives constituting the mirror ZFS pool are 512E. Using the default FreeNAS settings, Windows reported the sector size as 512/4096. Upon installation, we received:

There have been 25958400 misaligned log IOs which required falling back to synchronous IO.

We changed the extent's logical block size to 4096, then receiving "There have been 256 misaligned log IOs which required falling back to synchronous IO." consistently.

To resolve:

• I re-created the ZFS pool with ashift=9 (512B).
  • I don't believe this is necessary, but by default FreeNAS 9.x creates the pool at 4096B. Technically the backing drives have 512B sectors.
  • If your zpool command doesn't accept '-o ashift=9', you can control this via "sysctl -w zfs.vfs.max_auto_ashift".
• I re-created the iSCSI extent using a logical block size of 512B.
• Lastly, I disabled physical block size reporting so that the physical block size was also reported as 512B.