Take the 2-minute tour ×
Database Administrators Stack Exchange is a question and answer site for database professionals who wish to improve their database skills and learn from others in the community. It's 100% free, no registration required.

We have two production SQL Servers running SQL Server 2005 SP4 with cumulative update 3. Both servers run on physical machines that are identical. DELL PowerEdge R815 with 4 x 12 core CPUs and 512GB (yes GB) of ram, with 10GB iSCSI SAN connected drives for all SQL databases and logs. OS is Microsoft Windows Server 2008 R2 Enterprise edition with all SP's and windows updates. OS drive is a RAID 5 array of 3 x 72GB 2.5" 15k SAS drives. SAN is a Dell EqualLogic 6510 with 48 x 10K SAS 3.5" drives, configured in RAID 50, sliced into various LUNs for the 2 SQL Servers, and also shared with an Exchange machine and several VMWare servers.

We have over 20 databases, 11 of which are mirrored with high availability using a witness server. The witness server is a lower powered machine running a SQL Server instance that is used for nothing other than providing witness services. The biggest mirrored database is 450GB and generates around 100-300 iops. Database Mirroring Monitor reports a current send rate around 100kb to 10mb per second, and a mirror commit overhead of (typically) 0 milliseconds. The mirror server has no problem keeping up with the principal.

We are consistently experiencing mirroring failovers. Sometimes a single database will failover, other times almost all databases will failover simultaneously. For instance, last night, we had 10 of 11 databases failover, the remaining database stayed accessible until I manually failed it over.

I have gone through several troubleshooting steps to attempt to identify the problem, but have so far not been able to resolve the issue:

1) The machine came with a Broadcom BCM5709C NetXtreme II 4 port Gigabit network adapter which we initially used as the primary network connection. We have since installed an Intel(R) PRO/1000 PT Dual Port Server Adapter on both machines to eliminate the NIC as the issue.

2) All databases have an automatic full backup nightly along with a log backup for databases involved in mirroring. Log file useage is monitored and rarely gets above 15% used. The log file for the main database is 125GB, consisting of 159 virtual log files that range in size from 511MB to 1GB. TempDB is on it's own LUN, and consists of 24 x 2GB files.

3) SQL Server log on the witness shows no errors other than: The mirroring connection to "TCP://SQL02.DOMAIN.INET:5022" has timed out for database "Data" after 30 seconds without a response. Check the service and network connections.

SQL Server log on the primary and secondary servers show messages relating to mirroring:

The mirroring connection to "TCP://SQL01.DOMAIN.INET:5022" has timed out for database "Data" after 30 seconds without a response. Check the service and network connections.

The mirrored database "Data" is changing roles from "PRINCIPAL" to "MIRROR" due to Role Syncronization. (Synchronization is misspelled here on purpose since that is precisely how the actual message is display.)

The mirrored database "Data" is changing roles from "PRINCIPAL" to "MIRROR" due to Failover.

The mirrored database "Data" is changing roles from "MIRROR" to "PRINCIPAL" due to Failover from partner.

The SQL Server services continue to run and network connections seem to stay up. We consistently have between 500 to 2500 sessions connected to each server (primarily robotic applications that connect to service broker queues on a single database).

4) TCP Chimney and RSS etc are disabled using NET SH syntax.

5) I have ran the SQL Server 2005 Best Practices Analyzer against both machines and find nothing other than the very occasional Application Event Log error 833, none of which are coincident with the failover events:

SQL Server has encountered 1 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [F:\Data.MDF] in database [Data] (9). The OS file handle is 0x00000000000010A0. The offset of the latest long I/O is: 0x000007d4b10000).

6) Occasionally we see "The client was unable to reuse a session with SPID XXX, which had been reset for connection pooling. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message." generated by both servers. There appears to be no "earlier" messages that indicate any issue.

7) Occasionally database mail writes an error to the Application event log:

Exception Type: Microsoft.SqlServer.Management.SqlIMail.Server.Common.BaseException Message: There was an error on the connection. Reason: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding., connection parameters: Server Name: MGSQL02, Database Name: msdb Data: System.Collections.ListDictionaryInternal TargetSite: Void OpenConnection(Microsoft.SqlServer.Management.Common.SqlConnectionInfo) HelpLink: NULL Source: DatabaseMailEngine

StackTrace Information at Microsoft.SqlServer.Management.SqlIMail.Server.DataAccess.ConnectionManager.OpenConnection(SqlConnectionInfo ci) at Microsoft.SqlServer.Management.SqlIMail.Server.DataAccess.DataAccessAdapter.OpenConnection(String dbServerName, String dbName, String userName, String password) at Microsoft.SqlServer.Management.SqlIMail.IMailProcess.QueueItemProcesser.ProcessQueueItems(String dbName, String dbServerName, Int32 lifetimeMinimumSec, LogLevel loggingLevel)

I believe the Timeouts are causing the failover; what could cause these timeouts? Obviously if there was an actual network issue such as a bad cable, or a bad switch, that might cause packet loss and therefore a timeout, however what other things could cause timeouts? Blocking? If MSDB, or some other system database had an I/O timeout could that cause the mirroring failover?

Thanks for any advice!

netsh interface tcp show global shows:

Receive-Side Scaling State          : disabled
Chimney Offload State               : disabled
NetDMA State                        : enabled
Direct Cache Acess (DCA)            : disabled
Receive Window Auto-Tuning Level    : disabled
Add-On Congestion Control Provider  : ctcp
ECN Capability                      : disabled
RFC 1323 Timestamps                 : disabled

netsh interface ipv4 show dynamicportrange tcp

Protocol tcp Dynamic Port Range

Start Port      : 1025
Number of Ports : 64510

SELECT name, value_in_use FROM sys.configurations

    Ad Hoc Distributed Queries               0         
    affinity I/O mask                        0         
    affinity mask                            0         
    affinity64 I/O mask                      0         
    affinity64 mask                          0         
    Agent XPs                                1         
    allow updates                            0         
    awe enabled                              0         
    blocked process threshold                5         
    c2 audit mode                            0         
    clr enabled                              1         
    common criteria compliance enabled       0         
    cost threshold for parallelism           4         
    cross db ownership chaining              0         
    cursor threshold                         -1        
    Database Mail XPs                        1         
    default full-text language               1033      
    default language                         0         
    default trace enabled                    1         
    disallow results from triggers           0         
    fill factor (%)                          0         
    ft crawl bandwidth (max)                 100       
    ft crawl bandwidth (min)                 0         
    ft notify bandwidth (max)                100       
    ft notify bandwidth (min)                0         
    index create memory (KB)                 0         
    in-doubt xact resolution                 0         
    lightweight pooling                      0         
    locks                                    0         
    max degree of parallelism                6         
    max full-text crawl range                4         
    max server memory (MB)                   393216    
    max text repl size (B)                   65536     
    max worker threads                       0         
    media retention                          0         
    min memory per query (KB)                2048      
    min server memory (MB)                   52427     
    nested triggers                          1         
    network packet size (B)                  1400      
    Ole Automation Procedures                1         
    open objects                             0         
    PH timeout (s)                           60        
    precompute rank                          0         
    priority boost                           0         
    query governor cost limit                0         
    query wait (s)                           -1        
    recovery interval (min)                  0         
    remote access                            1         
    remote admin connections                 0         
    remote login timeout (s)                 20        
    remote proc trans                        0         
    remote query timeout (s)                 600       
    Replication XPs                          0         
    scan for startup procs                   0         
    server trigger recursion                 1         
    set working set size                     0         
    show advanced options                    1         
    SMO and DMO XPs                          1         
    SQL Mail XPs                             0         
    transform noise words                    0         
    two digit year cutoff                    2049      
    user connections                         0         
    user options                             4216      
    Web Assistant Procedures                 0         
    xp_cmdshell                              1         

A while ago, I manually modified the mirroring_connection_timeout value for all mirrored databases to 30 seconds to attempt to remediate the problem; this has simply increased the amount of time between failover events. With the mirroring_connection_timeout setting set at the default of 10 seconds, we see a lot more failovers.

A comment had asked me to ensure IPSec is disabled, so I'm posting the contents of several netsh commands that display the IPSec configuration of the operating system:


C:\>netsh ipsec dynamic show all
No currently assigned Policy
Mainmode Policies not available.
Quickmode Policies not available.
Generic Mainmode Filters not available.
Specific Mainmode Filters not available.
Generic Quickmode Filters not available.
Specific Quickmode Filters not available.
IPsec MainMode Security Associations not available.
IPsec QuickMode Security Associations not available.

IPsec Configuration Parameters
------------------------------
StrongCRLCheck         : 1
IPsecexempt            : 3

IPsec Statistics
----------------
Active Assoc                : 0
Offload SAs                 : 0
Pending Key                 : 0
Key Adds                    : 0
Key Deletes                 : 0
ReKeys                      : 0
Active Tunnels              : 0
Bad SPI Pkts                : 0
Pkts not Decrypted          : 0
Pkts not Authenticated      : 0
Pkts with Replay Detection  : 0
Confidential Bytes Sent     : 0
Confidential Bytes Received : 0
Authenticated Bytes Sent    : 0
Authenticated Bytes Received: 0
Transport Bytes Sent        : 0
Transport Bytes Received    : 0
Bytes Sent In Tunnels       : 0
Bytes Received In Tunnels   : 0
Offloaded Bytes Sent        : 0
Offloaded Bytes Received    : 0

C:\>netsh ipsec static show all
ERR IPsec[05072] : No Policies in Policy Store




UPDATE: 2012-12-20

We've now moved our production systems onto SQL Server 2012. We've been running this since the morning of December 17th - so far no failovers. However, a couple of days is well within what we saw with the 2005-based systems.

In an effort to document the performance of our new systems, I've been looking at sys.dm_os_wait_stats more carefully; and noticed DBMIRROR_DBM_EVENT, which is an undocumented wait type. Graham Kent at Microsoft has an interesting article regarding troubleshooting unexpected failovers and this wait type. I shall recap his findings here:

The customer was experiencing a huge blocking chain built on a high volume OLTP database where all the head blockers were waiting on DBMIRROR_DBM_EVENT. Here is the sequence of events I went through:

  1. Review the blocking chain itself - ho help here as all we can see is that we're waiting on DBMIRROR_DBM_EVENT

  2. Review the source for the undocumented wait type. Obviously you can't do this outside of MS, but I can say that at the time of writing this wait type represents the wait used when the principal is waiting for the mirror to harden an LSN, meaning that the transaction it's part of cannot commit. This immediately points quite specifically to the problem that the principal cannot commit transactions as it's waiting on the mirror. Now we need to investigate why the mirror is not committing transactions or why the principal doesn't know whether it is.

  3. Review the msdb system tables

(a) Look at the [backupset] table to see if the size of the logs produced at the time of the problem are significantly higher then normal. If they were exceptionally large it may be that the mirror was flooded with transactions and could simply not keep up with the volume. This is why books online will tell you sometimes to disable mirroring if you need to do an exceptionally large logged operation such as an index rebuild. (reference for why this is at http://technet.microsoft.com/en-us/library/cc917681.aspx). Here i used the following TSQL

SELECT backup_set_id,backup_start_date,database_name,has_bulk_logged_data,backup_size / 1000
FROM [backupset]
where backup_start_date between '2011-01-05 14:00:00' and '2011-01-05 19:30:00'
go

select round((AVG(backup_size)/1000),0)
FROM [backupset]
where database_name = 'mydatabase'

(b) secondly I looked at the data in the tables [dbm_monitor_data]. The key here is to locate the timeframe in which we had a problem and then see if we were significant experiencing changes in any of the following:

log_flush_rate
send_queue_size
send_rate
redo_queue_size
redo_rate

These are all indicators similar to part (a) in that they might show a component or piece of architecture that wasn't responding. For example if the send_queue suddenly starts to grow but the re_do queue doesn't grow, then it would imply that the the principal cannot send the log records to the mirror so you'd want to look at connectivity maybe, or the service broker queues dealing with the actual transmissions.

In this particular scenario we noted that all the counters appeared to have strange values, in that there were log backups going on of normal sizes, but there were no status changes, 0 send queue, 0 redo queue, a flat send rate and a flat redo rate. This is very strange as it implies that the DBM Monitor could not record any values from anywhere over the problem period.

  1. Review the SQL Server error logs. In this case there were no errors or information messages whatsoever, but in other scenarios such as this, it’s very common for errors in the 1400 range to be reported, examples of which you can find in other places in my other mirroring blogs, such as this Error 1413 example

  2. Review the default trace files – in this scenario I was not provided the default traces, however they are fantastic sources of DBM problem information, as they record state change events on all the partners.This is documented here:

Database Mirroring State Change Event Class

This often gives you a great picture of scenarios such as when network connectivity failed between one or all of the partners and then what the state of the partnership became afterwards.

CONCLUSIONS:

In this particular scenario I’m currently missing 2 key points of data, but that apart I can still make a reasonable hypothesis on the above information. We certainly can say that the blocking was caused by the fact that DBM was enabled to the due the blockers all waiting on the DBMIRROR_DBM_EVENT wait type. Since we know we didn’t flood the mirror with a large logged operation and that this deployment normally runs happily in this mode, we can exclude unusual large operations. This means that we have 2 potential candidates at this stage:

  1. Hardware problems on the connectivity between some or all of the partners.

  2. CPU exhaustion on the mirror server – simply unable to keep up with redos – the CPU exhaustion could itself be from a process outside of SQL Server or outside of the this mirror partnership.

  3. A problem with the mirroring code itself (we’d really need some memory dumps to confirm this though).

Based upon experience I’d suspect 1 or 2, but I always keep an open mind about 3 as well, we’re trying to collect some more data now to look at this problem in more detail.

share|improve this question
    
Once we get a failover, we typically start seeing more and more frequent failovers until we switch all databases over to the secondary machine, and restart the primary. Typically then a week (or two, or so) will go by until the secondary (which is now serving all databases) will start failing over. The secondary will continue to failover databases more and more frequently until we manually failover all databases back to the primary and restart the secondary. Then everything is good again for a week or two. –  Max Vernon Aug 17 '12 at 17:45
    
It seems that restarting the SQL Server service (or restarting the entire machine) is the only way to ameliorate the failover frequency, and this only helps for a while. It's almost like there is a memory leak, or something. –  Max Vernon Aug 17 '12 at 17:46
    
Another thing to check would be IPSec. Often IPSec can delay or block the connection attempt. Disable IPSec to see if the timeouts stop. –  Robert L Davis Aug 27 '12 at 22:05
    
Are you talking about an IPSec setting in SQL Server? Or the operating system. More detail would be greatly appreciated! –  Max Vernon Aug 27 '12 at 22:12
    
I used netsh to inspect the IPSec environment on the machine (I assume that is what you meant, @RobertLDavis) I see nothing configured. I've added the output to my original question. –  Max Vernon Aug 28 '12 at 12:48
show 4 more comments

3 Answers

I've just read your entire post and it matches exactly with the symptoms we are seeing in our smaller environment. The only difference is that we are running SQL 2008 R2 on Windows 2008 R2 Standard. We have no errors on any of the switches and no errors from the network stack suggesting that the reason for the timeout is valid. The only common theme here is the operating system itself. In this environment's previous existence it was running SQL 2005 on Windows 2003 and it had virtually no fail-overs in any given period. We have also experienced the same thing as yourself when the server has been rebooted, the period of stability is about 2 weeks, then the failovers become more and more frequent. So this suggests to me that the issue is not related to the size of your environment, or ours for that matter. The common theme is the operating system. I am watching this space eagerly in case you are the answer to my prayers :)

share|improve this answer
    
We're leaning heavily towards the OS being the culprit. It's good to hear that someone else is having the same issue. I'm going to consider installing W2K3 on the secondary at some point soon. Will update this post with any changes! –  Max Vernon Sep 12 '12 at 14:47
    
I'll also update if we have any brainwaves here. –  Bijan Sep 12 '12 at 15:15
add comment

Can you check you sys.dm_os_schedulers ? Specifically, does work_queue_count deviates from 0 for any significant time? This would indicate worker starvation and would explain many of your symptoms.

share|improve this answer
    
I've added a table listing the server configuration. Max Worker Threads is set to 0, to allow the server to choose the appropriate value. sys.dm_os_schedulers shows no results for SELECT * FROM sys.dm_os_schedulers WHERE work_queue_count > 0; - should I be recording this every minute? –  Max Vernon Aug 14 '12 at 16:21
    
You should check it when fail overs occur. –  Remus Rusanu Aug 14 '12 at 17:58
    
The past several times failover has occurred, I've checked SELECT * FROM sys.dm_os_schedulers WHERE work_queue_count > 0; after receiving notification of the failover, no records are returned. –  Max Vernon Aug 30 '12 at 4:31
    
Now I can categorically say that SELECT * FROM sys.dm_os_schedulers WHERE work_queue_count > 0; is returning 0 results during a failover. We just had a failover and nothing shows up. –  Max Vernon Sep 8 '12 at 2:46
add comment

It sounds like you might be running out of TCP ports on the SQL Server. How many connections are you seeing to the server at a time?

Timeouts like that would definitely be causing the problem.

share|improve this answer
    
Thanks for the response. That is certainly an issue we identified as a potential cause of the problem. Windows Server 2003 has a limit out-of-the-box of 5,000 so-called "ephemeral" ports, however Windows Server 2008 R2 is configured to use 16,000 (I think) out of the box. Regardless we have configured both SQL Servers MaxUserPort setting to 65534 in HKLM\SYSTEM\CurrentControlSet\Services\Tcpip\Parameters. –  Max Vernon Aug 13 '12 at 21:28
    
I just checked both boxes: Principal has 1,387 ports in use, secondary has 682 in use right now. To check this I opened a cmd prompt and entered: netstat -n | find "TCP" /c –  Max Vernon Aug 13 '12 at 21:29
    
The next step that I'd probably take would be to fire up wireshark on the witness and the primary server and wait for the next timeout to see what is actually happening at the TCP level. –  mrdenny Aug 13 '12 at 21:49
    
mmmmm... Packet Capturing. Any idea how to decipher the tcp stream on port 5022 that is the mirroring transport? Without that info, Wireshark may not really tell me very much. I will try it and see what happens. Thanks for the help! –  Max Vernon Aug 13 '12 at 22:11
1  
show 8 more comments

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

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