Minecraft 伺服器卡頓排查:用 spark 找出延遲來自實體、漏斗還是外掛

摘要

Paper 內建的 spark 能記錄伺服器的時間都花在哪裡。當伺服器變卡,而 CPU 使用率與主控台的警告都看不出原因時,只要趁卡頓時錄製一份報告,就能從佔比最高的項目找出延遲來自實體、漏斗還是某個外掛。

文章目錄

Minecraft 伺服器變卡時,我們通常想知道是生物太多、漏斗太多,還是某個外掛拖慢了伺服器,但 CPU 使用率無法回答這個問題。spark 是 Minecraft 伺服器的效能分析工具,能記錄伺服器的時間都花在哪裡。只要趁卡頓時用它錄製一份報告,就能從佔比最高的項目看出延遲的來源。

本文的測試環境是 Windows 11、i7-12700、Java 25 與 Paper 26.3 的 build 240。Paper 從 1.21 起已內建 spark,不用另外安裝。如果伺服器還在用 Spigot,可以先把伺服器轉成 Paper。文中的負載都是我為了測試而製造的,製造方式寫在實測紀錄。

確認卡頓來自伺服器

覺得伺服器變卡時,先在伺服器視窗輸入 spark tps。伺服器每秒要更新世界 20 次,每次更新稱為一個 tick,因此每個 tick 要在 50 ms 內做完。TPS 是每秒實際完成的 tick 數,上限是 20。下圖是牛太多時的結果,TPS 約為 16.3,耗時的中位數也超過了 50 ms:

伺服器視窗的 spark tps 輸出,TPS 約 16.3,Tick durations 最近 10 秒的中位數是 60.8 ms,超過 50 ms

我們要看的是其中兩行。TPS 那行由左到右是最近 5 秒、10 秒、1 分鐘、5 分鐘與 15 分鐘的平均。如果數字前面有 *,代表實際值略高於 20,spark 只會顯示到 20,不需要處理。

Tick durations 那行是每個 tick 的耗時,四個數字依序是最短、中位數、第 95 百分位與最長,分號前是最近 10 秒,分號後是最近 1 分鐘。伺服器啟動後的 1 分鐘內會出現長達數秒的 tick,因此判斷時要看分號前的數字。

這兩行的數字對應的情況與處理方式如下:

spark tps 的結果 情況 處理方式
TPS 接近 20,最長耗時也低於 50 ms 伺服器的 tick 正常 卡頓不是 tick 造成的,不需要錄製報告
TPS 低於 20,中位數超過 50 ms 每個 tick 都做不完 錄製一般報告
TPS 低於 20,中位數正常,最長耗時遠超過 50 ms 平常正常,偶爾卡住 錄製只記錄慢 tick 的報告

CPU 使用率看不出這種卡頓。世界主要由 Server thread 這一條執行緒更新,而測試電腦有 20 條執行緒,一條跑滿也只佔約 5%,因此 TPS 掉到 16 左右時,spark 回報的伺服器程序 CPU 使用率只有約 6%。主控台的 Can't keep up 警告也一樣,我測試時即使 TPS 掉到 12.5,這個警告也沒有出現。

錄製 spark 報告

確認伺服器的 tick 有延遲後,就趁卡頓還在發生時錄製報告,因為問題過去後就錄不到原因。錄製時伺服器會照常運作,不用停機:

  1. 在伺服器視窗輸入 spark profiler start --timeout 60,開始錄製 60 秒。
  2. 錄製結束後,伺服器視窗會印出一個 https://spark.lucko.me/ 開頭的連結。
  3. 用瀏覽器開啟連結,就能看到報告。

伺服器在 Windows 上啟動時會印出 The async-profiler engine is not supported,這段訊息不用理會,spark 會改用內建的 Java 引擎。

如果伺服器平常正常,只是偶爾卡住,就改用下面的指令,只記錄超過 150 ms 的 tick:

1spark profiler start --timeout 60 --only-ticks-over 150

門檻要高於平常的 tick 耗時,並低於卡住時的耗時,可以參考 spark tps 顯示的最長耗時來調整。

伺服器印出連結時,報告已經上傳到 spark 的網站。隱私政策寫明報告會保存 90 天,而且任何拿到連結的人都能查看。報告內容包含作業系統、CPU、JVM 啟動參數、外掛清單、部分伺服器設定,以及執行指令者的名稱。把連結貼到公開的地方時,這些資訊也會跟著公開。

如果不想上傳報告,就輸入 spark profiler start 開始錄製,不加 --timeout。錄製約 60 秒後,再輸入 spark profiler stop --save-to-file,報告就會存到伺服器的 plugins/spark 資料夾。接著把這個 .sparkprofile 檔拖進 spark 網站首頁的方框,就能用同樣的畫面閱讀報告。我測試時,瀏覽器沒有送出上傳的請求。

判讀報告

打開報告後,最上方的 MSPT 就是每個 tick 的耗時,單位是毫秒,其中 med 是中位數。max 可能包含伺服器啟動時的長 tick,例如下圖的 5860,因此我們只要看 med:

spark 報告上方的數字,TPS 最近 1 分鐘為 16.79,MSPT 的中位數為 58.9,最長為 5860,CPU 為 6.49%

報告裡的百分比代表這段程式佔整份報告的時間比例。確認 med 後,往下捲到「Profiler」區塊,照下面的順序找出佔比最高的項目:

  1. 點一下 Server thread 展開。
  2. 逐層點開百分比接近 100% 的項目,直到 MinecraftServer.tickChildren(),中間約有九層。
  3. 點開 tickChildren(),看底下佔比最高的項目。如果是 ServerLevel.tick(),就再展開一層。

找到佔比最高的項目後,依下表對照延遲的來源:

佔比最高的項目 來源 處理方式
EntityTickList.forEach() 實體,例如動物與怪物 用指令找出數量最多的實體並減少
Level.tickBlockEntities() 方塊實體,例如漏斗 減少方塊實體的數量
CraftScheduler.mainThreadHeartbeat() 外掛的排程工作 更新或移除外掛

實體過多的報告

實體過多時,報告的時間會集中在 EntityTickList.forEach()。下圖是牛太多時的報告,這個項目佔了 91.94%,而 Level.tickBlockEntities() 只有 0.01%:

spark 報告展開到 ServerLevel.tick,EntityTickList.forEach 佔 91.94%,ServerChunkCache.tick 佔 7.77%,其他項目都低於 0.1%

報告不會列出實體的種類與位置,要查詢這些資訊時,可以用 Paper 的指令。在伺服器視窗輸入 paper entity list * minecraft:overworld,主世界每一種實體的數量都會列出來。下圖是放了 900 隻牛的世界:

paper entity list 的輸出,第一行是 Total Ticking 918,minecraft:cow 有 900 隻,遠多於其他實體

每一行的第一個數字是正在更新的實體數量。找到數量最多的種類後,再輸入 paper entity list minecraft:cow minecraft:overworld,並把 minecraft:cow 換成這個種類,伺服器就會依區塊列出數量,例如 49: 0, 0 代表區塊座標 0, 0 有 49 隻。區塊座標乘以 16 就是方塊座標,傳送到那裡後,就能減少牧場或生怪塔的數量。

如果要一次清除,可以輸入 kill @e[type=minecraft:cow]。這個指令會殺掉所有已載入的牛,而且無法復原,執行前要先備份世界。

漏斗過多的報告

漏斗過多時,報告的時間會集中在 Level.tickBlockEntities(),往下點開就會看到 HopperBlockEntity:

spark 報告展開到 HopperBlockEntity,Level.tickBlockEntities 佔 90.19%,往下的 HopperBlockEntity.pushItemsTick 佔 66.71%

報告只會列出方塊實體的類型,不會列出座標,因此我們要回到遊戲裡檢查漏斗集中的區域,再減少數量。

外掛造成延遲的報告

外掛佔用太多時間時,CraftScheduler.mainThreadHeartbeat() 底下會出現外掛自己的程式名稱。把游標移到最後一層,右邊也會顯示外掛的名稱。下圖的 SlowTick 是我寫的測試外掛:

spark 報告展開到 lab.SlowTick.scanHomes,佔 98.91%,游標移上去後右邊顯示 59336ms 與外掛名稱 SlowTick

伺服器有裝外掛時,報告上方的工具列會多一個「plugins」按鈕,按下去就能依外掛分開查看。找到造成延遲的外掛後,先更新到新版。如果問題還在,就停止伺服器,把這個外掛的 jar 檔移出 plugins 資料夾,再重新啟動。

偶發卡頓的報告

伺服器偶爾卡住時,要改看用 --only-ticks-over 150 錄製的報告。這份報告只會留下慢 tick,讀法和前面相同。下圖的測試外掛每隔一段時間就會卡住一次,佔比最高的項目就是造成卡頓的方法:

用 only-ticks-over 150 錄製的報告,lab.SlowTick.saveHomes 佔 99.82%,游標移上去後顯示外掛名稱 SlowTick

確認處理結果

處理完後等待 30 秒,再輸入一次 spark tps,並看 Tick durations 分號前的最近 10 秒。分號後的最近 1 分鐘還包含處理前的時間,數字會比較高。如果 TPS 回到 20、中位數低於 50 ms,就代表延遲已經解決。如果是偶爾卡住,就要等過原本會卡住的間隔,再看最長耗時有沒有回到 50 ms 以下。

實測紀錄

測試伺服器沒有玩家連線,每種情境都在新世界重新測試,用 forceload 載入 64 個區塊,負載維持約兩分鐘。這些負載遠超過一般伺服器的規模,數字只用來示範判讀報告的方式,不代表真實伺服器的表現。TPS 取 spark tps 最近 10 秒的數字,處理方式都是把負載全部移除。各情境的負載與結果如下:

情境 負載 次數 TPS 中位數 移除後的中位數
實體過多 8,000 隻牛 3 15~16.9 59~66 ms 1.5~1.6 ms
漏斗過多 196,608 個漏斗 2 12.5~16.8 59~78 ms 0.3~0.5 ms
外掛佔用 每個 tick 空轉 60 ms 1 16.5 60.6 ms 0.4 ms
偶發卡頓 每 100 個 tick 空轉 800 ms 1 18 0.4 ms 0.3 ms

沒有負載時,TPS 是 20,中位數是 0.6~1 ms。我把 server.properties 的 pause-when-empty-seconds 設成 -1,伺服器在沒有玩家時才不會暫停。Paper 會降低離玩家太遠的實體的更新頻率,因此我也把 spigot.yml 的 entity-activation-range 全部設成 0,讓牛群用玩家就在旁邊時的頻率更新。維持預設時,3,000 隻牛的中位數只有 3.4 ms,設成 0 後則會升到 16~28 ms。

總結

伺服器變卡時,先確認 tick 的耗時是否超過 50 ms,再趁卡頓時錄製一份報告,就能從佔比最高的項目找出延遲的來源。牛群、漏斗與測試外掛的報告都能分辨出各自的來源,移除這些負載後,中位數都回到 1.6 ms 以下。

接著可以做什麼

下一篇Minecraft gamerule 新舊名稱對照:keepInventory 等指令新版改名Games
Ted Liou

Ted Liou

現役軟體工程師,Unity、AI 技術開發經驗分享與諮詢。