alway on辅助节点备份日志失败

Question

已以用户 domain\administrator 的身份执行。 已为数据库 'K3DBConfiger2020343517986'，文件 'SqlServer_MC_20120727193627_Log' (位于文件 1 上)处理了 2253 页。 [SQLSTATE 01000] (消息 4035)  BACKUP LOG 成功处理了 2253 页，花费 0.078 秒(225.610 MB/秒)。 [SQLSTATE 01000] (消息 3014)  已为数据库 'test'，文件 'SqlServer_BC_20120727194252_Log' (位于文件 1 上)处理了 3767747 页。 [SQLSTATE 01000] (消息 4035)  辅助副本上数据库“test”的日志备份失败，因为无法在主数据库上提交新的备份信息。请在承载当前主副本的服务器实例的 SQL Server 错误日志中查看数据库状态。如果主数据库正在参与该可用性组，请重试该操作。 [SQLSTATE 42000] (错误 35296)  BACKUP LOG 正在异常终止。 [SQLSTATE 42000] (错误 3013).  该步骤失败。

我在主节点上找到以下日志信息：

源        spid40s

消息
Error: 35250, Severity: 16, State: 13.
源        spid40s

消息
The connection to the primary replica is not active.  The command cannot be processed.

源        spid40s

消息
Error: 35250, Severity: 16, State: 13.

源        spid40s

消息
The connection to the primary replica is not active.  The command cannot be processed.

源        spid86

消息
Autogrow of file 'SqlServer_BC_20120727194252_Log' in database 'test' took 101263 milliseconds.  Consider using ALTER DATABASE to set a smaller FILEGROWTH for this file.

后面这些日志不知道是否相关：

源        spid59

消息
Autogrow of file 'SqlServer_BC_20120727194252_Log' in database 'test' took 108931 milliseconds.  Consider using ALTER DATABASE to set a smaller FILEGROWTH for this file.

源        spid72

消息
Autogrow of file 'SqlServer_BC_20120727194252_Log' in database 'test' took 120244 milliseconds.  Consider using ALTER DATABASE to set a smaller FILEGROWTH for this file.

源        spid13s

消息
FlushCache: cleaned up 20348 bufs with 2521 writes in 121199 ms (avoided 7392 new dirty bufs) for db 8:0

源        spid13s

消息
average writes per second:  20.80 writes/sec
            average throughput:   1.30 MB/sec, I/O saturation: 1050, context switches 2195

源        spid13s

消息
last target outstanding: 4200, avgWriteLatency 0
因为这个任务是每两小时执行一次，基本上每天都会有相同报错，等我看到报错手动执行任务时又成功了。

Answer 1

Sounds like connection issue between two servers in the group, did you check sync status of this group?

Answer 2

问题就在这里

通常当我收到警报时，我打开always on的控制面板看到整个高可用组是正常的

所有实例和数据库都是绿色状态的。

Answer 3

你好，

请问SQL Server版本。

另外您的备份作业是使用维护计划创建的吗

---

""SQL Server related"" forum will be migrated to a new home on Microsoft Q&A SQL Server!
We invite you to post new questions in the "SQL Server related" forum’s new home on Microsoft Q&A SQL Server !
For more information, please refer to the sticky post.

Answer 4

数据库版本：Microsoft SQL Server 2014 - 12.0.2000.8 (X64)

执行的计划任务，语句很简单

declare @n int

select @n=sys.fn_hadr_backup_is_preferred_replica ( 'test' )

if @N=1    ----判断是否为辅助节点（1），辅助节点执行存储过程，主节点退出；

begin

BACKUP LOG test TO DISK='NUL:'

end
else if @N<>1
begin
print '非辅助节点'
end

Answer 5

你好，

既然调用了sys.fn_hadr_backup_is_preferred_replica 函数，那么请问此AG的Backup Preferences和Backup Replica Priorities设置。

尝试在备份作业中不调用此函数，直接在辅助副本上进行备份，是否有问题。

如果是两个节点的可用性组，不如直接调用 sys.fn_hadr_is_primary_replica来判断是否是辅助副本。

---

Answer 6

我觉得和函数没多大区别，我只有两个节点；备份首选项是首选辅助副本，优先级相同都是50；

在这种情况下sys.fn_hadr_backup_is_preferred_replica 和sys.fn_hadr_is_primary_replica应该是没什么区别的，always on辅助副本就是首选备份副本；

另外我觉得和调用函数关系也不大，我前端挂的是IIS应用，有客户端反馈会出现卡顿情况（根据客户端观察1-2分钟左右就自动恢复正常了），我推测卡顿时always on组是异常的，但我在故障转移群集中没找到错误日志，只有在数据库日志中找到上面的一些相关信息；

当我收到客户端卡顿的反馈时最直观的感受就是数据库节点实例可以通过SSMS正常连接但展开数据库时十分缓慢，如果我收到数据库报警邮件再去查看时因为时效性问题等我查看时，always on组已经是正常的了，我再次手动执行备份任务它就不报错了，所以到现在为止也没找到很好的方法去排查....

Answer 7

你好，

每次自动执行备份作业都会失败并报错吗？
注意到错误日志中的另一个关于日志文件增长的消息，此日志文件似乎持续增长。日志自动增长的时间是否能对应客户端卡顿的时间。

---

""SQL Server related"" forum will be migrated to a new home on Microsoft Q&A SQL Server!
We invite you to post new questions in the "SQL Server related" forum’s new home on Microsoft Q&A SQL Server !
For more information, please refer to the sticky post.

Answer 8

并不是每次都报错，但每天会有个1-2次，而且当我接受到错误通知检查时always on组是正常的；

而且我用的always on必须使用完整模式，在前端一直在用的情况下日志每小时增加10G也是正常的吧？

Answer 9

How often do you backup log?

Answer 10

因为日志增长的比较快，再加上偶尔会出现任务失败，所以我把备份频率设置为1小时一次，之前是4小时一次，但遇到备份失败就会撑爆磁盘，所以我加快了备份的频率；

Answer 11

Try backup log more often to reduce log backup time.

Answer 12

可以考虑先把 FILEGROWTH  设置小一点，默认这个通常是 10%，可以考虑设置成固定大小，比如64M

然后日志中有明确的信息：

The connection to the primary replica is not active.  The command cannot be processed.

可以看看群集日志中是否有对应时间点的异常信息（cluadmin.msc）

Answer 13

我现在已经是45分钟备份一次日志了，这已经足够频繁了吧，另外我不清楚频繁备份日志是否会对数据库有性能上的影响？

Answer 14

我当前的设置是这样的日志初始大小100G，自动增长为默认的10%，最大限制为200G，就使用过程来看自动增长设置没什么作用的，通常1小时会增长10G左右的日志，初始大小有100G，也就是每小时只会使用10%的日志空间，而这个时候我的日志备份就开始了，我通过频繁的备份日志确保它不会出现自动增长的情况；

日志的明确信息让我很迷惑，看日志至少在那一刻整个always on组是异常的，但我在群集日志中根本没找到相关的信息，我的群集日志上次报错还是9/17日，而这个日志是我发帖当日出现的。

Answer 15

We backup log every 30 minutes, even every 15 minutes for those busy dbs. Also use 100g connection between server and backup device, reason is to keep log backup as quick as possible to reduce impact.

Answer 16

我可以加快备份的频率，甚至10分钟也行，但这好像并不能解决根源问题；

为什么在备份的那段时间会有报错，提示always on组不可用呢？

Answer 17

就在今天的凌晨1点又出现了这样的报错！

所以我觉得单纯增加备份频率没有解决根源问题；

Answer 18

How long to backup the log? If db was busy and primary was unable to sync logs to replica because log backup was running on it, sql may report sync error.

Answer 19

为了减轻主节点压力，数据备份和日志备份全部放在辅助节点上处理的；

完整数据备份每天两次（AM1、PM7），每次1-3分钟左右；

日志备份每45分钟备份一次，持续时间在1-2分钟左右；

Answer 20

通常1小时会增长10G左右的日志，初始大小有100G，也就是每小时只会使用10%的日志空间

----- 按照你的设置，1100G的初始大小可以用10小时，每小时都有备份，那么日志文件不应该会出现增长的情况

你可以排查一下日志文件的使用情况。文件增长能救这建议改成固定大小，10%在文件大的时候是不适用的，比如你的文件有100G了，10%意味着一次要扩大10G

另外，你还需要锭是否确实存在服务器之间有断开的情况，建议你看群集日志或启动扩展事件 AlwaysOn_health

Answer 21

嗯，我把增长值设置为100mb了

AlwaysOn_health中只有这些信息

Answer 22

为了减轻主节点压力，数据备份和日志备份全部放在辅助节点上处理的；

完整数据备份每天两次（AM1、PM7），每次1-3分钟左右；

日志备份每45分钟备份一次，持续时间在1-2分钟左右；

It takes too long to backup log, our log backup lasts about 10 seconds. We had app issue previously due to long log backup duration.

Answer 23

那我应该怎么做呢？

always on架构加上前端一直在用，每小时就产生10Gb的日志，备份一次1-2分钟属于异常现象吗？

我应该再加快备份频率吗？

Answer 24

Try backup log every 15 minutes, and check throughput of backup device.

Answer 25

AlwaysOn_health 和群集事件日志（没看到你有回复说检查过这个）中都没有异常记录的话，你这个问题就有点怪了

Answer 26

已以用户 domain\administrator 的身份执行。 已为数据库 Configer'，文件 'SqlServer_MC__Log' (位于文件 1 上)处理了 597 页。 [SQLSTATE 01000] (消息 4035)  BACKUP LOG 成功处理了 597 页，花费 0.056 秒(83.217 MB/秒)。 [SQLSTATE 01000] (消息 3014)  已为数据库 'CLOUD'，文件 'SqlServer_BC_20120727194252_Log' (位于文件 1 上)处理了 730144 页。 [SQLSTATE 01000] (消息 4035)  BACKUP LOG 成功处理了 730144 页，花费 17.952 秒(317.749 MB/秒)。 [SQLSTATE 01000] (消息 3014).  该步骤成功。

频率改为15分钟每次，每次备份共耗时19秒左右，这吞吐量正常吗？

另外频繁的备份截断日志对数据库有什么影响吗？

Answer 27

Log backup only truncates committed transactions from log, no db impact. 

Answer 28

改为15分钟备份一次日志后，每次执行日志备份每个数据库在10S左右，整个任务执行完毕大概在39S左右，观察2个月没出现过always on群集不可用的情况，前端应用也不再频繁出现卡顿现象！已标记答案，多谢！

Answer 29

Happy SQLing!