一次.net code中的placeholder導致的高cpu診斷

dotnet程式故障診斷發表於2023-03-18

背景

最近一位朋友找到我，讓我幫看他們的一個aspnet core service無端cpu高的問題。從描述上看，這個service之前沒有出現過cpu高的情況，最近也沒有改過實際的什麼code。很奇怪了，會有什麼變化導致cpu上去了呢？

分析

由於比較容易復現 (據說一啟動service，cpu就上去了)，我便讓那位朋友在cpu高的時候直接手動把.net程式dump了一下。於是就開始用windbg分析了一次.net code中的placeholder導致的高cpu診斷

先看一下案發時程式中的執行緒情況，畢竟它們是讓程式動起來的源泉哈。大部分執行緒都執行到如下類似位置（下面的callstack是虛擬化的，因為為了朋友的隱私，code已經虛擬化）：

 

這裡可以看出有約38/2=19個執行緒執行到Services.CronJob+d__1.MoveNext這個位置。我又問了那位朋友，當時的執行環境是大約20個cpu core。真巧哈，幾乎所有cpu core都很有可能跑到了這個地方了。

注：上面如何知道有38/2個執行緒，而不是38個執行緒呢？這是因為一般來說，當某個函式正在被呼叫時，callstack中會顯示出兩次，如圖哈：

看到沒，在"current frame"下面顯示的上一層呼叫關係中會也顯示這個方法，此時它是callee哈。

那麼這個Services.CronJob+d__1.MoveNext是何方神聖呢，名字叫cpu killer更貼切吧??

跑題了，去看看這個方法的程式碼。注意到這個是compiler generated code，所以就先看看generated code長啥樣吧：

先利用上圖中透露出來的method的md地址，用!dumpmd看一下這個方法的資訊：

反編譯看一下：

天啦擼，這好像是async state machine code，沒事湊合看吧?仔細觀察那些標紅的位置後，我發現這裡面有些蹊蹺啊。如果schedules不是null的話，有兩種情況，這兩種情況最終都會到label_10的地方，在那裡，cpu可以得到休息；但如果schedules是null的話，會不會一直以同步的方式高速迴圈在while裡？我在所有threads的stack上找尋，找不到有型別為List<string>的instance被stack引用著，所以很有可能是這個原因了。

另外，從Services.CronJob+d__1.MoveNext這個名字看，這個closure應該是在user code class CronJob中生成的，我們去看看。用!dumpheap:

正好19個CronJob, 這和剛分析的有19個執行緒正高速執行吻合。因為心情不錯，所以再去看看CronJob的樣子吧：

 

 看起來這個CronJob是個long running的IHostedService，在迴圈中有的flow沒有讓thread休息導致cpu上來了。

後記

把這個結果告訴那位朋友後，朋友很快找到了對應的程式碼，簡化後的程式碼如下：
 1     protected override async Task ExecuteAsync(CancellationToken stoppingToken)
 2     {
 3         await InitializeJobAsync();
 4 ​
 5         while (!stoppingToken.IsCancellationRequested)
 6         {
 7             List<string>? schedules = PreferenceService.GetSchedules(Region);
 8             if (schedules == null)
 9             {
10 ​
11             }
12             else
13             {
14                 await ProcessJobAsync(schedules);
15                 await Task.Delay(TimeSpan.FromSeconds(10), stoppingToken);
16             }
17         }
18     }
很奇怪為什麼要在第8行寫個空的if block在那裡。那位朋友用git history發現，一個月前他的一個同事在這位朋友的程式碼里加了empty if block，而加之前的簡化程式碼大約是這樣的：
 1    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
 2     {
 3         await InitializeJobAsync();
 4 ​
 5         while (!stoppingToken.IsCancellationRequested)
 6         {
 7             List<string>? schedules = PreferenceService.GetSchedules(Region);
 8 ​
 9             await ProcessJobAsync(schedules);
10             await Task.Delay(TimeSpan.FromSeconds(10), stoppingToken);
11         }
12     }

於是原因便是，當時加了這個empty if block後，由於PreferenceService.GetSchedules總不是null，所以沒有進入問題flow；後來配置變了，返回了null，進入問題flow，問題flow又錯過了await Task.Delay()，所以悲劇發生。。

據這位朋友說，他的同事後來說:"這個empty if block當時是個placeholder。現在不用了，可以刪了" ……。。唉，刪是好刪，不過在發現root cause之前可是讓這位朋友背了不少時間的鍋哈

總結

無論在自己的程式碼還是別人的程式碼里加placeholder，一定要謹慎新增這種empty block。加對了頂多稍影響效能和可讀性，加不對就是給別人或自己或專案組添堵了。並且這種bug只在特定條件下被觸發，更難根據程式碼的版本歷史排除出故障，而適合用底層診斷技術分析。

相關文章