4

Let me preface this post by saying that I am missing a few events from my trace, but I have since added them for the next time this occurs.

Lately we have been seeing weird spurts of HADR_SYNC_COMMIT wait types in our environment (~40k tran/s). Today's "incident" occurred at 4:58am:

enter image description here

enter image description here

Before continuing, I must add that we were doing ONLINE index maintenance on a large audit table (audit in the sense that an OLTP table trigger records to this audit table at a high volume) and that index rebuild was blocked itself for ~22 seconds. Clearly, that is playing a role in this particular instance, but I am not quite sure how it relates to HADR_SYNC_COMMIT. Additionally, we have been seeing this occur during the day when we do not do index maintenance.

Looking at the trace, here is what I see on the primary: enter image description here

enter image description here

enter image description here

...and everything on the secondary: enter image description here

...and finally back on the primary: enter image description here

A similar issue happened again 12/1/2023 around 4:11am and I believe I see what is happening. Unfortunately, I do not have extended events for this scenario, but I do have some logging that might paint a clearer picture. Starting at 2023-12-01 04:10:18.5430090, Ola's index maintenance recorded a start time for an Index on the database in question. Ola's reported a completion time of 2023-12-01 04:11:13.9431563, but I believe that the actual REBUILD WITH ONLINE = ON completed much sooner than that.

When reviewing DPA, I noticed that pagelatch_sh and pagelatch_ex waits spiked at 4:11:03-4:11:04am:

enter image description here

Immediately following those waits, that same query started seeing HADR_SYNC_COMMIT and those same wait completely fell off at 4:11:13-4:11:14am, which is exactly when Ola's reported the index finishing. My assumption is that the index REBUILD was committed at 4:11:03am (~45 seconds worth of work), which caused the unrelated INSERT queries that were in the same database to simply wait for all of those log blocks to harden on the secondary. As soon as the index completed, the remaining log blocks were hardened instantaneously as they were just tiny INSERTs.

5
  • For index rebuild windows I've found that using USE master ALTER DATABASE [MyDB] SET HADR SUSPEND before and SET HADR RESUME after maintenance speeds up the process considerably because ultimately the commits are synced asychronously "manually" this way :-))
    – wqw
    Commented Dec 2, 2023 at 14:35
  • This sounds like a horrendous idea in production. When you say "speeds up the process" what are you referring to? Those same log blocks have to be sent over to the replica. You would be significantly better off just changing the sync mode to async and letting replication continue as per usual.
    – Data Dill
    Commented Dec 3, 2023 at 18:43
  • Yes, setting AG to async mode instead of suspending HADR is an idea I might consider for our db maintenance procedures so that we don't get any HADR_SYNC_COMMIT waits on index/stat rebuilds. Wait, this sounds very much like a solution to your case too. Is this advice of yours not working for you?
    – wqw
    Commented Dec 4, 2023 at 7:50
  • No, that would negatively impact RPO. What is the point of using AG sync mode if you are manually setting it to async temporarily just for index maintenance?
    – Data Dill
    Commented Dec 4, 2023 at 21:25
  • The point of using sync mode remains the same for the rest of the day when no index maintenance is happening and our maintenance window can be as low as a few seconds for smaller DBs and often w/o any active users so there is no negative impact on RPO but YMMV and you can do whatever you like, I'm sharing what works for us but obviously not very wise thing to do here so I'll bow out of this conversation for now.
    – wqw
    Commented Dec 6, 2023 at 6:23

2 Answers 2

5

I wanted to say kudos for diving in and investigating using XE, that's definitely a correct step in the eventual solution. Having said that, it's unlikely we're going to be able to directly help in any meaningful way. Let me explain.

HAD_SYNC_COMMIT waits are almost like any other wait in that they are a wait type but they actually reset every ~3 seconds (implementation detail) which is where hadr_db_commit_mgr_harden_still_waiting comes in and it will fire for as many rounds of checking as is needed until the log block is marked hardened. Outside of the implementation details, everything else is like other waits and the same issues will occur - remember that SQL Server uses cooperative scheduling and if you get into the details is event driven, such that many events being signaled (such as a wait is completed and the task can move forward) can cause bursting convoy type issues (all threads are waiting, then all threads are "woken up" which causes a cpu/scheduling race, which then causes the convoy again).

When investigating these types of waits you'll unfortunately need a great deal of data including a packet capture of the local and remote hosts, XE for HADR, File/Disk, Scheduling, and ETW traces in Windows for Disk, Filter, CPU. It's a large amount of data and I'm not suggesting you do it here because the issue is sort of in the information you've given.

 I must add that we were doing ONLINE index maintenance on a large audit table [...]

Any large and long transactions (especially index related activities) aren't a very good fit for how Availability Groups are implemented. Offline index rebuilds are completed as a single behemoth transaction, ONLINE are better as they are smaller transactions at various points, but both operations can really drive CPU and IO - which isn't necessarily a bad thing. If your server has the performance ability to generate a large amount of log in a short period of time where generation is faster than network latency + disk latency, the database (and the instance) will not be able to keep up with the outstanding log generation to send to the other replicas. You'll start hitting sync commit waits on synchronous replicas (since it only applies to synchronous commit partners).

Availability Groups send data via log blocks, which are the smallest unit logical grouping of items at the log level and have a minimum size of 512 bytes (used to be 1 sector size, that has since changed given 4k, 8k, 16k, and even 32k sector sizes) and maximum of 60k, though their actual size depends on whether a commit ends the block or the block reaches the maximum size. The point of this is that the transaction itself is not the unit of transfer and multiple transactions from multiple different sessions can and will be intermingled throughout a log block. Thus if you're generating a large amount of log blocks and transactions are interwoven through those, any transactions committing will need the outstanding log block for its own transaction to be hardened before continuing on, which will likely be part of another log block which may also be much further down the line as things start to back up.

Another point of contention is the network, which again is an implementation detail as part of UCS in SQL Server. Outside of Distributed AGs in SQL Server 2022+ (which has some issues right now), a single connection is used to stream data over TCP to each replica. This means, even with a large bandwidth network you'll be limited by the latency as that will determine the rough number of outstanding requests which may or may not hit the throttling limit in SQL Server (this limit was raised in 2022). This means you'll never be able to seriously fill a large bandwidth pipe with a single instance of SQL Server using Availability Groups and that latency is much more important - thus a sync commit replica halfway around the world with a latency of 150ms is going to severely back up and large log generation workloads - i.e. index rebuilds.

I mentioned the need for scheduling and cpu data, this is due to the fact that the log generation happens, but that needs to be packaged up and sent across the network. This all happens asynchronously across a variety of threads and queues. If the instance is having cpu pressure on a single cpu, this could impact the packaging (compression, encryption, serialization, UCS information [boxcars], message information) and sending (send thread, receive thread) along with secondary replicas which are doing the same thing in the opposite order. This is especially true on readable secondary replicas where the read workload can hinder or otherwise bring down the ability of the AG to harden in a timely manner. Note that hardening requires a write to the disk (which is where the IO data comes in) and does not need to be redone.

This all is to say, when rebuilding indexes, this is expected and I wouldn't waste time delving into it further.

5
  • I would agree that this is almost certainly due to index rebuilds, but the primary concern and what prompted this post actually occurred a few weeks back where we had 3+ hours of HADR SYNC waits on a database during the workday (no index maintenance) for a single 60 second interval. In that same interval, 2 other databases had ~25 minutes of total HADR waits each. This significantly impacted production and so that is why I was trying to understand the movement better so that I am prepared the next time it happens. I appreciate your in-depth reply.
    – Data Dill
    Commented Dec 1, 2023 at 19:43
  • ~25 mins of sync commit waits in 60 seconds can be 25 spids blocked for 60 seconds, 50 spids blocked for 30, etc., and is not a good measure of the impact. If there are 1000 threads all waiting for 3 seconds (essentially a hiccup), it'd show as 50 minutes of wait time. There is more data to collect, again, such as if the database/replica was being flow controlled, what the scheduler queues looked like (total, runnable, etc.) at 5 second intervals, etc., as there can be many reasons why hadr_sync_commit waits aren't actually because of the AG. Commented Dec 1, 2023 at 20:14
  • This is why I stated there is a lot of data to collect in order to diagnose the problem, it's quite a bit of data and it all needs to be collected each time. Also if there is more than 1 instance of SQL Server on the server, it's all over in terms of getting anywhere. Commented Dec 1, 2023 at 20:18
  • Understood. Humor me for the sake of continuous learning (final question).. if you were tasked to create a high amount of HADR_SYNC_COMMIT waits just by using Query Stress and TSQL, what type of statements would you run? I'm running all types of CX REBUILDs with lots of small transactions, but I can't seem to generate a high amount of waits.
    – Data Dill
    Commented Dec 1, 2023 at 20:37
  • I'd so something simple, such as creating a table that is 1 page wide, char(8000), and then run the HADR endpoint through a different application, such as clumsy, to add in say 3 seconds of latency. Now make each thread insert 1 row (which will be an 8k page) and commit each time. Each commit will end the log block (and if you turn off group commit) thus giving you 1 thread = 1 log block = 1 3 second hadr sync commit. You can then vary whatever settings you need. Granted this forces the issue onto the network and not scheduling or oversubscription, but it's easy for testing. Commented Dec 1, 2023 at 21:03
3

As far as I can see, this is happening because your alwayson AG is synchronously redoing the index reconstruction on the secondary and this takes time. These waits describe exactly this situation.

If you are using a fast SSD disk as storage, you can simply not execute the index rebuild. For performance, simply update the statistics.

If you would like to explore this issue further, I suggest evaluating the extended events described here:

https://techcommunity.microsoft.com/t5/sql-server-blog/troubleshooting-high-hadr-sync-commit-wait-type-with-always-on/ba-p/385369

5
  • Correct me if I'm wrong, but REDO is performed asynchronously. Yes, the log blocks still have to be shipped to the secondary before everything is finalized (maybe that is what you mean?), but the actual REDO does not. Also worth pointing out that the secondary doesn't even receive the log block until 10 seconds AFTER it has been flushed to the primary.
    – Data Dill
    Commented Dec 1, 2023 at 11:43
  • @DataDill - I've recently been looking into these same wait types on Azure SQL database. I thought the same as you (that it would just have to wait for the log to harden) but did come across this article indicating that it does apply the changes to the data pages first too sqlshack.com/… Commented Dec 1, 2023 at 12:23
  • Are there readable secondaries with long queries? Did you check the waits on secondaries? Maybe the redo is waiting for locks...
    – MBuschi
    Commented Dec 1, 2023 at 12:24
  • 6
    Harden does not wait for redo, the article is incorrect. If you're seeing the secondary receive the log block 10 seconds late, investigate the network. Commented Dec 1, 2023 at 13:27
  • Added another situation with more logging/details from today's occurrence.
    – Data Dill
    Commented Dec 1, 2023 at 15:56

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

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