3

A server that is part of a SQL 2017 Always on availability group (BAG) I have noticed an increase of these messages. I understand these are messages that appear in the log as standard since 2012 (trace flag prior to 2012) but over the last 2 days they are appearing every few minutes, there are no backups running or maintenance jobs at these times

The server is acting as the secondary non readable fail over partner and the primary server is not exhibiting the same behavior.

09/04/2020 10:52:24,spid82s,Unknown,FlushCache: cleaned up 2303 bufs with 1881 writes in 81090 ms (avoided 11 new dirty bufs) for db 7:0 09/04/2020 10:52:07,spid52s,Unknown,last target outstanding: 2 avgWriteLatency 86 09/04/2020 10:52:07,spid52s,Unknown,average writes per second: 17.70 writes/sec average throughput: 0.19 MB/sec I/O saturation: 13073 context switches 15434

There is also a warning in the system error log about disk issue, seconds after this the availability group failed over ever since the FlushCache messages have increased.

enter image description here

Has anyone experienced anything similar or have any advice, my sysadmin is also looking at the SAN and VMware estate.

Had a sudden thought could these be caused by autogrowth activities?

Improve this question
4

Switch to indirect checkpoints (generally, set recovery interval time to 60 seconds, at least for user databases).

I wrote about this issue here and here, and you should read those posts in full before making the change, though it’s pretty much a no-brainer IMHO.

The impact in our environment was drastic and immediate, and it was simple to prove the change was responsible. Every database with the symptom went from 30-60 second checkpoints, and errorlogs full of these messages, to sub-second checkpoints and no more errorlog entries.

There are probably mitigation techniques for your workload, too, for example see this post by Itzik Ben-Gan but making checkpoints more efficient is a quicker and easier path. Your storage and VM folks aren’t off the hook, though; there is definitely a disk issue they need to address (but I disagree that these FlushCache messages were the root cause of any failover; more likely they are just a different victim/symptom).

Improve this answer
1
  • Thanks Aaron, appreciate the advice. Agreed with regards to the failover – Stockburn Sep 4 '20 at 3:31
3

Check with your storage admin if there's any firmware updates recently or your storage subsystem needs a newer firmware update. I've seen this messages on SQL environment multiple times and one thing you can look at is the storage layer configuration (this is the common cause). Also, one thing to monitor your disk performance using perfmon. disk counters you need to focus on: avg disk sec/Read, avg disk sec/Write, avg disk sec/Transfer.

You can check the following link you can look below:

  1. How It Works: When is the FlushCache message added to SQL Server Error Log?
  2. https://techcommunity.microsoft.com/t5/sql-server-support/how-it-works-when-is-the-flushcache-message-added-to-sql-server/ba-p/317038

When I say storage layer, check the following: HBA/CNA, Fibre Cable, FC Switch, Ports, Storage controller, Software (MPIO drivers) - all of its configuration

Finally, I'd high recommend to always check and investigate warnings/errors message on your event logs. DO NOT let it pass because this kind of messages have long term consequences down the road.

Improve this answer
4
  • Thanks mate will dig into it – Stockburn Sep 4 '20 at 3:29
  • I can't add comment on Aaron's answer (low rep) but I would disagree changing the target recovery time to 60 to address this issue. Changing this setting will suppress the Flushcache IO messages on SQL Server Error Log. This is from my experience. You need to address the issue which is probably the IO subsystem. – Dan Co Sep 4 '20 at 3:36
  • Dan, if you read the posts you’ll see that the setting also materially reduced the time and work checkpoints were spending, which definitely could be making I/O issues worse. I validated this using extended events which measured the resources consumed by checkpoint events before and after the change. It’s an easy thing to change, quick to confirm, what’s the harm? The worse thing that happens is you have no more error messages in the log. Whether you change it or not, there’s still an additional disk issue to address, which I mentioned in my answer as well. So not sure what you disagree with. – Aaron Bertrand Sep 4 '20 at 4:23
  • i disagree that recovery time is the 1st thing to change(i know you didnt say this but someone reading your answer will assume this is the permanent fix) and this will just mask the msgs. my exp seeing this msg x times on large db, changing the recovery time did not help us address the underlying issue (we tried).After some config change on our storage we see big big improvement on our IO and the msgs are gone. Sure, you can argue that this config is recommended and easy to implement but personally I'd look at diff angle by fixing the underlying cause longterm. Your experience maybe different. – Dan Co Sep 4 '20 at 6:47

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.