主页 / dba / 问题 / 237633
Accepted
Frederik Vanderhaegen
Asked: 2019-05-09 01:25:55 +0800 CST

手动 AG 故障转移后超出最大工作线程

  • 772

我们有两个 SQL Server 2016 SP2 CU6 Enterprise 在物理硬件（32 核）上运行，其中一个 AG 包含 5 个 db。二级不可读。今天我们进行了计划中的手动故障转移，因此我们可以在另一台服务器上进行维护工作。我们在没有重负载的时候进行了故障转移。

故障转移是通过 SSMS 的 GUI 执行的，没有出现任何错误。但几分钟后，我们接到了很多用户无法登录的电话。我们第一次尝试进行故障排除是与 SSMS 建立连接，但这给出了我们无法连接的错误，我不记得确切的错误消息。

接下来我们查看了记事本中的错误日志文件，就像 SQL Server 引擎挂了一样。故障转移后没有新条目添加到日志中。

由于问题的紧迫性，我们在主服务器上重新启动了 SQL Server 服务，问题就消失了。
我们本可以尝试建立 DAC 连接以查看问题所在，但目标是尽快使服务器恢复联机。

在那之后一切都重新上线，我们开始分析日志文件。
在旧主节点的错误日志中，我们发现了几个错误 35278。故障转移时没有长时间运行的事务正在运行。

接下来是 AlwaysON_health 事件文件，这里的条目在故障转移后刚刚停止。

接下来我们看一下*_*_SQLDIAG_*_*.xel文件。在这里我们很幸运。

我们注意到的第一件事是：

<queryProcessing maxWorkers="960" workersCreated="1064"
 workersIdle="23" tasksCompletedWithinInterval="19" pendingTasks="34"
 oldestPendingTaskWaitingTime="1316776"

出于某种原因，超过了工作人员的最大数量，这可以解释为什么没有人可以连接。

这是待处理的任务：

<pendingTasks><br>
   <entryPoint name="Process Command" count="14" /><br>
   <entryPoint name="SNI New Connection" count="2" /><br>
   <entryPoint name="SNI Accept Done" count="3" /><br>
   <entryPoint moduleName="sqlmin.dll" imageBase="0x7ff827e80000" size="0x251e000" address="0x7ff8286622e0" count="6" /><br>
   <entryPoint moduleName="sqlmin.dll" imageBase="0x7ff827e80000" size="0x251e000" address="0x7ff8292b1190" count="2" /><br>
   <entryPoint moduleName="sqldk.dll" imageBase="0x7ff827120000" size="0x4c9000" address="0x7ff827125e60" count="7" />  <br>
</pendingTasks>

该文件中还有几个被阻止的进程。他们都有一个 waitresource 像DATABASE: 5:5, DATABASE: 5:15, DATABASE: 5:26, ...
所有这些进程都有lastbatchstarted并lastbatchcompleted设置为 1900-01-01。等待时间等于故障转移发生的时间。
在我们的监控中，我们看到总共有 950 个被阻止的进程。

这是一个阻塞进程报告的示例：

<blocked-process-report monitorLoop="0">
 <blocked-process>
  <process id="process13f08032ca8" taskpriority="0" logused="10000" waitresource="DATABASE: 5:3 " waittime="1334205" schedulerid="4" kpid="11752" status="suspended" spid="95" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host2021" hostpid="14196" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack />
   <inputbuf>
   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process status="suspended" waitresource="DATABASE: 5:3 " waittime="1335893" spid="70" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host1" hostpid="1324" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack />
   <inputbuf>
   </inputbuf>
  </process>
 </blocking-process>
</blocked-process-report>
<blocked-process-report monitorLoop="0">
 <blocked-process>
  <process id="process13f08033848" taskpriority="0" logused="10000" waitresource="DATABASE: 5:3 " waittime="1335893" schedulerid="4" kpid="12004" status="suspended" spid="70" sbid="0" ecid="0" priority="0" trancount="0" lastbatchstarted="1900-01-01T00:00:00" lastbatchcompleted="1900-01-01T00:00:00" lastattention="1900-01-01T00:00:00" clientapp="our_app" hostname="host1" hostpid="1324" loginname="user1" isolationlevel="read committed (2)" xactid="0" currentdb="1" currentdbname="master" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack />
   <inputbuf>
   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process status="background" waittime="1139955" spid="141" sbid="0" ecid="0" priority="0" trancount="0">
   <executionStack />
   <inputbuf>
   </inputbuf>
  </process>
 </blocking-process>
</blocked-process-report>



其中一个阻塞进程以 user 身份执行SA并具有 command UNKNOWN TOKEN。此last_wait_type会话的时间PARALLEL_REDO_WORKER_WAIT_WORK与last_request_start_time我们进行故障转移的时间相同。
我没想到会在主节点上找到这种等待类型。
说不PARALLEL_REDO_WORKER_WAIT_WORK应该在初选上预期是否正确？

同样在我们的监控中，我们发现了大约 1000 个会话，这些会话的状态SLEEPING为last_request_start_time01/01/1900。
这似乎一点也不正常。

有人可以解释那些待处理的任务是什么吗？
我对根本原因的猜测是 1000 个具有状态的会话SLEEPING，它们都使用了一个工人。这导致了挂起的任务，并且由于阻塞过程，没有工作人员可以做任何工作。这导致某处的故障转移卡住了。
这可能是正确的吗？

availability-groups sql-server-2016

2 个回答

  1. Best Answer

    由于问题的紧迫性，我们在主服务器上重新启动了 SQL Server 服务，问题就消失了。

    由于没有完成任何调查或数据收集，因此很难确切地说当时发生了什么。

    出于某种原因，超过了工作人员的最大数量，这可以解释为什么没有人可以连接。

    是的，出于某种原因，我们没有任何数据围绕这个原因 :( 看起来服务器有 32 个处理器，这应该足以处理可用性组中的 5 个数据库。还有更多我们要么不做的事情'不知道或者你不解释。

    说不PARALLEL_REDO_WORKER_WAIT_WORK应该在初选上预期是否正确？

    由于我们不知道这个的数据库上下文，所以不可能说。我会说，如果只有一个可用性组并且此实例是主要实例，那么不，就不会发生这种情况。但是，如果还有其他我们不知道的可用性组并且这是次要的，那么是的，这是预期的。同样，我们没有所有信息。这也假设在任何数据库上都没有需要排空的重做队列——同样，我们不知道或没有该信息。

    有人可以解释那些待处理的任务是什么吗？

    Process Commands正在尝试在连接上执行某些操作。SNI*正在建立新的联系。

    还有一个阻塞进程，在检查我们的监控后，这个进程以用户身份执行，SA并且有命令UNKNOWN TOKEN。

    它阻止了多少会话？它挡住了什么？等等。同样，缺乏信息，所以不能说它是否是什么。

    同样在我们的监控中，我们发现大约 1000 个会话的状态为 SLEEPING 并且 last_request_start_time 为 01/01/1900。这似乎一点也不正常。

    他们是从哪里来的？他们上次跑的是什么？如果您有一个可读的辅助副本并且有人想要运行一堆报告或查询，这可能是正常的。再次，需要更多信息。

    这可能是正确的吗？

    它可能是。显然，您用完了工作线程，因为没有足够的数据，所以不知道发生这种情况的方式和原因。

    在我们的监控中，我们看到总共有 950 个被阻止的进程。

    这是你的根本问题。看起来clientapp="our_app"已经连接（全部在 master 中）并且正在对数据库进行某种类型的查询。似乎数据库还没有完成重做（因此是等待类型）并且您的所有会话都相互备份。

    • 6

  2. 我们在我们的环境中多次遇到最大工作线程问题，唯一的原因是阻塞。因为您没有记录任何阻止会话来引导我们找到根本原因。此外，您可以设置调度延迟大于 5 秒的 sql 代理阻塞警报，并附加作业以捕获阻塞数据。我们有高度 oltp 环境和主表上的单阻塞在不到 1 分钟的时间内将工作线程增加到 1000。我们已将工作线程增加到 5000 以获得足够的时间来调查和终止阻塞会话，因为我们不想重新启动服务。

    我们发现了触发器，长时间运行的查询的罪魁祸首，它们在主要使用的表上持有表锁定并增加阻塞会话，并且在某个点 sql 变得无响应。在这种情况下，要么采取 DAC 会话并终止头部阻塞会话，要么重新启动 sql 服务。

    尽管由于多种原因，Microsoft 建议不要设置最大工作线程。首先设置阻塞警报并修复查询以避免此类问题。

    • 0

相关问题