【MinecraftJE1.13~】/debugコマンドで負荷測定

※この記事の内容は18w03b時点の情報です。今後のアップデートで変更が加わる場合もありますのでご了承下さい。

どうも皆さん、クマです。

今回の記事は/debugコマンドについての解説記事です。

/debugコマンドを使うことによって、コマンド回路のどこに処理時間がかかっているのかなどを簡単に知ることが出来ます。

それでは本題に入ります。

使い方

ゲーム内ですること

1. 「/debug start」コマンドを実行
2. 1の後ある程度待つ
3. 「/debug stop」コマンドを実行

これで「(Minecraftの実行ディレクトリ)\debug」に実行結果のファイルが出力されます。

ファイルの内容

これは実際に実行した際の出力ファイルです。

---- Minecraft Profiler Results ----
// Now with extra numbers

Time span: 4899623822 ms
Tick span: 98 ticks
// This is approximately 20.00 ticks per second. It should be 20 ticks per second

--- BEGIN PROFILE DUMP ---

[00] levels - 94.06%/94.06%
[01] |   debug_test - 99.74%/93.82%
[02] |   |   tick - 99.33%/93.19%
[03] |   |   |   tickBlocks - 33.36%/31.09%
[04] |   |   |   |   pollingChunks - 97.38%/30.28%
[05] |   |   |   |   |   unspecified - 84.42%/25.56%
[05] |   |   |   |   |   tickChunk - 5.11%/1.55%
[05] |   |   |   |   |   tickBlocks - 2.81%/0.85%
[06] |   |   |   |   |   |   unspecified - 97.31%/0.83%
[06] |   |   |   |   |   |   randomTick - 2.69%/0.02%
[05] |   |   |   |   |   iceandsnow - 2.60%/0.79%
[05] |   |   |   |   |   getChunk - 2.22%/0.67%
[05] |   |   |   |   |   checkNextLight - 1.45%/0.44%
[05] |   |   |   |   |   thunder - 1.39%/0.42%
[04] |   |   |   |   playerCheckLight - 1.60%/0.50%
[05] |   |   |   |   |   unspecified - 50.81%/0.25%
[05] |   |   |   |   |   getBrightness - 48.34%/0.24%
[05] |   |   |   |   |   checkedPosition < toCheckCount - 0.85%/0.00%
[04] |   |   |   |   unspecified - 1.02%/0.32%
[03] |   |   |   mobSpawner - 33.32%/31.05%
[03] |   |   |   tickPending - 19.10%/17.80%
[04] |   |   |   |   ticking - 97.25%/17.31%
[05] |   |   |   |   |   execute as @e[type=armor_stand,name="execute store"] store result score @s Debug run scoreboard players get @s Debug - 63.50%/10.99%
[05] |   |   |   |   |   scoreboard players operation @e[type=armor_stand,name="scoreboard"] Debug = Debug Debug - 29.39%/5.09%
[05] |   |   |   |   |   unspecified - 7.11%/1.23%
[04] |   |   |   |   unspecified - 1.56%/0.28%
[04] |   |   |   |   cleaning - 1.19%/0.21%
[03] |   |   |   entities - 7.47%/6.96%
[04] |   |   |   |   regular - 86.42%/6.01%
[05] |   |   |   |   |   tick - 96.21%/5.79%
[06] |   |   |   |   |   |   travel - 62.13%/3.59%
[07] |   |   |   |   |   |   |   move - 73.69%/2.65%
[07] |   |   |   |   |   |   |   unspecified - 13.17%/0.47%
[07] |   |   |   |   |   |   |   rest - 13.14%/0.47%
[06] |   |   |   |   |   |   unspecified - 20.17%/1.17%
[06] |   |   |   |   |   |   entityBaseTick - 7.22%/0.42%
[07] |   |   |   |   |   |   |   unspecified - 92.74%/0.39%
[07] |   |   |   |   |   |   |   portal - 7.26%/0.03%
[06] |   |   |   |   |   |   livingEntityBaseTick - 5.50%/0.32%
[06] |   |   |   |   |   |   ai - 2.34%/0.14%
[07] |   |   |   |   |   |   |   unspecified - 81.17%/0.11%
[07] |   |   |   |   |   |   |   newAi - 18.83%/0.03%
[06] |   |   |   |   |   |   push - 1.28%/0.07%
[06] |   |   |   |   |   |   headTurn - 0.71%/0.04%
[06] |   |   |   |   |   |   rangeChecks - 0.40%/0.02%
[06] |   |   |   |   |   |   chunkCheck - 0.17%/0.01%
[06] |   |   |   |   |   |   jump - 0.08%/0.00%
[05] |   |   |   |   |   unspecified - 3.67%/0.22%
[05] |   |   |   |   |   remove - 0.12%/0.01%
[04] |   |   |   |   players - 7.72%/0.54%
[05] |   |   |   |   |   tick - 85.04%/0.46%
[06] |   |   |   |   |   |   unspecified - 96.59%/0.44%
[06] |   |   |   |   |   |   chunkCheck - 3.41%/0.02%
[05] |   |   |   |   |   unspecified - 14.58%/0.08%
[05] |   |   |   |   |   remove - 0.38%/0.00%
[04] |   |   |   |   unspecified - 4.60%/0.32%
[04] |   |   |   |   remove - 0.94%/0.07%
[04] |   |   |   |   pendingBlockEntities - 0.19%/0.01%
[04] |   |   |   |   global - 0.08%/0.01%
[04] |   |   |   |   blockEntities - 0.06%/0.00%
[03] |   |   |   chunkMap - 5.37%/5.01%
[03] |   |   |   unspecified - 1.20%/1.12%
[03] |   |   |   chunkSource - 0.11%/0.10%
[03] |   |   |   village - 0.05%/0.04%
[03] |   |   |   portalForcer - 0.02%/0.01%
[02] |   |   timeSync - 0.28%/0.26%
[02] |   |   unspecified - 0.20%/0.19%
[02] |   |   tracker - 0.19%/0.18%
[01] |   unspecified - 0.26%/0.24%
[00] connection - 4.79%/4.79%
[01] |   unspecified - 61.21%/2.93%
[01] |   travel - 29.76%/1.42%
[02] |   |   move - 65.94%/0.94%
[02] |   |   rest - 17.12%/0.24%
[02] |   |   unspecified - 16.94%/0.24%
[01] |   livingEntityBaseTick - 2.86%/0.14%
[01] |   entityBaseTick - 2.35%/0.11%
[02] |   |   unspecified - 76.63%/0.09%
[02] |   |   portal - 23.37%/0.03%
[01] |   ai - 1.91%/0.09%
[02] |   |   unspecified - 68.00%/0.06%
[02] |   |   newAi - 32.00%/0.03%
[01] |   push - 0.88%/0.04%
[01] |   headTurn - 0.85%/0.04%
[01] |   keepAlive - 0.10%/0.00%
[01] |   rangeChecks - 0.04%/0.00%
[01] |   jump - 0.03%/0.00%
[00] unspecified - 0.71%/0.71%
[00] commandFunctions - 0.19%/0.19%
[01] |   unspecified - 97.09%/0.19%
[01] |   minecraft:tick - 2.91%/0.01%
[00] jobs - 0.19%/0.19%
[01] |   unspecified - 79.53%/0.15%
[01] |   rest - 18.89%/0.04%
[01] |   move - 1.58%/0.00%
[00] snooper - 0.03%/0.03%
[00] tallying - 0.02%/0.02%
[00] tickables - 0.00%/0.00%
[00] players - 0.00%/0.00%
--- END PROFILE DUMP ---

上の「Time span」と「Tick span」は/debug startを実行してから/debug stopを実行するまでの時間を表しています。

なお、Time spanは単位がmsとなっていますが、正しくはpsのようです。(1pm=10^(-9)ms)

その下には各処理の占める時間の割合が表記されています。

左の角括弧内の数字は何代目の子かを表しています。

そして右の○.○○%/○.○○%がその処理が全体に占める処理時間の割合を表しています。

左側の%が同じ階層の処理の中で占める割合、右側の%が全ての処理の中で占める割合です。

上の例だと、

[05] | | | | | execute as @e[type=armor_stand,name="execute store"] store result score @s Debug run scoreboard players get @s Debug - 63.50%/10.99%
[05] | | | | | scoreboard players operation @e[type=armor_stand,name="scoreboard"] Debug = Debug Debug - 29.39%/5.09%

となっています。これからスコア代入時には負荷のことを考えると/executeより/scoreboardを使ったほうが良いとわかりますね。

1.13ではコマンド自体の動作も軽量化され、さらにどの処理が負荷になっているのかなども手軽に調べられるようになりました。

皆さんも/debugコマンドを使ったりして軽量化をしてみましょう！