魔法师小曹儿 發表於 2025-4-21 12:39:00

记一次 .NET某旅行社酒店管理系统 卡死分析

<h2 id="一背景">一：背景</h2>
<h3 id="1-讲故事">1. 讲故事</h3>
<p>年初有位朋友找到我，说他们的管理系统不响应了，让我帮忙看下到底咋回事? 手上也有dump，那就来分析吧。</p>
<h2 id="二为什么没有响应">二：为什么没有响应</h2>
<h3 id="1-线程池队列有积压吗">1. 线程池队列有积压吗？</h3>
<p>朋友的系统是一个web系统，那web系统的无响应我们首先要关注的就是 <code>线程池</code>，使用 <code>!sos tpq</code> 命令，参考输出如下：</p>
<pre><code class="language-C#">
0:000&gt; !sos tpq
global work item queue________________________________
0x00000004010774C0 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT&lt;Microsoft.AspNetCore.Hosting.HostingApplication+Context&gt;
0x0000000401077808 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT&lt;Microsoft.AspNetCore.Hosting.HostingApplication+Context&gt;
....
0x000000030239DD78 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT&lt;Microsoft.AspNetCore.Hosting.HostingApplication+Context&gt;
0x000000030239E0C0 Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT&lt;Microsoft.AspNetCore.Hosting.HostingApplication+Context&gt;

local per thread work items_____________________________________
0x0000000100A46410 System.Threading.Tasks.Task&lt;System.Threading.Tasks.Task&gt;
...
0x000000010133F8C0 System.Threading.Tasks.Task&lt;System.Threading.Tasks.Task&gt;

    2 WorkMicrosoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext+&lt;&gt;c.&lt;WaitOnTasks&gt;b__123_1
    4 WorkMicrosoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext+&lt;&gt;c.&lt;WaitOnTasks&gt;b__123_0
266 WorkMicrosoft.AspNetCore.SignalR.HubConnectionContext.AbortConnection
----
272

</code></pre>
<p>从卦中可以看到确实存在线程池积压的情况，那为什么会有积压呢？条件反射告诉我，是不是因为锁的原因，使用 <code>!syncblk</code> 观察。</p>
<pre><code class="language-C#">
0:000&gt; !syncblk
Index         SyncBlock MonitorHeld Recursion Owning Thread Info          SyncBlock Owner
-----------------------------
Total         468
CCW             0
RCW             0
ComClassFactory 0
Free            120

</code></pre>
<p>从卦中看和锁没半毛钱关系，那就只能深入各个消费线程，看看这些线程为什么这么不给力。。。。</p>
<h3 id="2-线程都在干什么">2. 线程都在干什么</h3>
<p>要想观察各个线程都在做什么，可以用 <code>~*e !clrstack</code> 观察各个线程调用栈，输出的调用栈太长，但仔细观察之后，发现很多线程都停留在 <code>TryGetConnnection</code> 上，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202504/214741-20250421123903154-2017577288.png" alt="" loading="lazy"></p>
<p>从卦中可以看到大概有143个线程卡在 TryGetConnection 上，不知道 Connection 为啥取不到了，接下来观察问题代码，简化后如下：</p>
<pre><code class="language-C#">
      private bool TryGetConnection(DbConnection owningObject, uint waitForMultipleObjectsTimeout, bool allowCreate, bool onlyOneCheckConnection, DbConnectionOptions userOptions, out DbConnectionInternal connection)
      {
            DbConnectionInternal dbConnectionInternal = null;
            Transaction transaction = null;

            if (HasTransactionAffinity)
            {
                dbConnectionInternal = GetFromTransactedPool(out transaction);
            }
            if (dbConnectionInternal == null)
            {
                Interlocked.Increment(ref _waitCount);
                do
                {
                  num = WaitHandle.WaitAny(_waitHandles.GetHandles(allowCreate), (int)waitForMultipleObjectsTimeout);

                } while (dbConnectionInternal == null);
            }
      }

      private DbConnectionInternal GetFromTransactedPool(out Transaction transaction)
      {
            transaction = ADP.GetCurrentTransaction();
            DbConnectionInternal dbConnectionInternal = null;
            if (null != transaction &amp;&amp; _transactedConnectionPool != null)
            {
                dbConnectionInternal = _transactedConnectionPool.GetTransactedObject(transaction);
                //....
            }
            return dbConnectionInternal;
      }
      
       internal DbConnectionInternal GetTransactedObject(Transaction transaction)
      {
            lock (_transactedCxns)
            {
                flag = _transactedCxns.TryGetValue(transaction, out value);
            }
            if (flag)
            {
                lock (value)
                {
                  int num = value.Count - 1;
                  if (0 &lt;= num)
                  {
                        dbConnectionInternal = value;
                        value.RemoveAt(num);
                  }
                }
            }
            return dbConnectionInternal;
      }

</code></pre>
<p>从卦中源码看是 <code>_transactedCxns</code> 返回 null 所致，看样子是_transactedCxns中的Conenction耗尽，接下来使用 <code>!dso</code> 从 DbConnectionPool 字段中去挖，输出如下：</p>
<pre><code class="language-C#">
0:298&gt; !dso
OS Thread Id: 0x42c0 (298)
          SP/REG         Object Name
    0005c087d020   0003ffc79528 Microsoft.Data.ProviderBase.DbConnectionPool

0:298&gt; !do 0003ffc79528
Name:      Microsoft.Data.ProviderBase.DbConnectionPool
MethodTable: 000007fe8dd714c8
EEClass:   000007fe8dd65438
Tracked Type: false
Size:      176(0xb0) bytes
File:      D:\APP\EnergyDotNet\runtimes\win\lib\net6.0\Microsoft.Data.SqlClient.dll
Fields:
            MT    Field   Offset               Type VT   Attr            Value Name
000007fe8dd7137040001a7       8c         System.Int321 instance                1 _state
...
000007fe8cd994b040001ad       94         System.Int321 instance            143 _waitCount
000007fe8e012c6840001b4       78 ...tedConnectionPool0 instance 00000003ffc7a3e8 _transactedConnectionPool
...
000007fe8cd994b040001b6       9c         System.Int321 instance            100 _totalObjects
...

0:298&gt; !DumpObj /d 00000003ffc7a520
Name:      System.Collections.Generic.Dictionary`2[,]
MethodTable: 000007fe8e0146a0
EEClass:   000007fe8cd8af30
Tracked Type: false
Size:      80(0x50) bytes
File:      C:\Program Files\dotnet\shared\Microsoft.NETCore.App\6.0.22\System.Private.CoreLib.dll
Fields:
            MT    Field   Offset               Type VT   Attr            Value Name
000007fe8cda84804002065      8       System.Int32[]0 instance 0000000000000000 _buckets
000007fe8e3255d84002066       10 ...ivate.CoreLib]][]0 instance 0000000000000000 _entries
000007fe8cd9ca084002067       30      System.UInt641 instance                0 _fastModMultiplier
000007fe8cd994b04002068       38         System.Int321 instance                0 _count
000007fe8cd994b04002069       3c         System.Int321 instance                0 _freeList
000007fe8cd994b0400206a       40         System.Int321 instance                0 _freeCount
000007fe8cd994b0400206b       44         System.Int321 instance                0 _version
000007fe8cdb7900400206c       18 ...Private.CoreLib]]0 instance 0000000000000000 _comparer
000007fe8da70c90400206d       20 ...Private.CoreLib]]0 instance 0000000000000000 _keys
000007fe8d2a1c60400206e       28 ...Private.CoreLib]]0 instance 0000000000000000 _values

</code></pre>
<p>从上面的卦中数据可知三点信息：</p>
<ol>
<li><code> 100 _totalObjects</code> 当前的线程池存着100个Connection。</li>
<li><code>0 _count</code> 当前100个Connection全部耗尽。</li>
<li><code>143 _waitCount</code> 表示当前有 143 个线程在获取 Connection 上进行等待。</li>
</ol>
<h3 id="3-池中之物都去了哪里">3. 池中之物都去了哪里</h3>
<p>要想找到这个答案，继续观察线程栈，比如搜索TDS传输层方法 <code>Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByte</code> ，可以看到刚好是 100 个，上层大多是 <code>xxxx.GetRoomNosInDltParams</code> 方法，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202504/214741-20250421123903159-1862198006.png" alt="" loading="lazy"></p>
<p>挖掘各个线程栈，大概都是下面的sql，格式化如下：</p>
<pre><code class="language-sql">
SELECT ,
      ,
      ,
      ,
      ,
      ,
      ,
      ,
      
FROM
WHERE ((((((( IN (673,674)) AND( &gt; @SellPrice1 ))
      AND ( &gt;= @CheckInDate2 ))
      AND ( &lt;= @CheckInDate3 ))
      AND ( &lt;=@constant5))
      AND ( =@constant7))
      AND NOT ( LIKE @MethodConst8+'%') )

</code></pre>
<p>反编译源码发现有一个 useCached 字段形同虚设，导致每次都是从 数据库 读取，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202504/214741-20250421123903168-2111049332.png" alt="" loading="lazy"><br>
<img src="https://img2024.cnblogs.com/blog/214741/202504/214741-20250421123903161-1316954417.png" alt="" loading="lazy"></p>
<p>到这里基本上就能推测出来的，程序的卡死主要是 Connection 耗尽，优化建议如下：</p>
<ol>
<li>SQL 加上 nolock，避免锁问题。</li>
<li>GetRoomNosInDltParams 方法尽量使用缓存。</li>
<li>观察数据库层的锁和负载情况。</li>
<li>设置更大的数据库连接池。</li>
</ol>
<h2 id="三总结">三：总结</h2>
<p>这次卡死的生产事故，是大量数据库的慢请求导致SDK侧的数据库连接池(100)耗尽所致，如果有数据库侧的监控工具，我想一眼就能找到答案。<br>
<img src="https://images.cnblogs.com/cnblogs_com/huangxincheng/345039/o_210929020104最新消息优惠促销公众号关注二维码.jpg" width="700" height="300" alt="图片名称" align="center"></p><br><br>
来源：https://www.cnblogs.com/huangxincheng/p/18838356
頁: [1]
查看完整版本: 记一次 .NET某旅行社酒店管理系统 卡死分析