Difference between revisions of "Debug Profiler"

From Forge Community Wiki
(Inital import from dokuwiki)
 
m (Some debugging)
Line 1: Line 1:
= Debug Profiler =<br /><br />Minecraft provides a Debug Profiler that can be used to find time consuming code. Specially considering things like TickEvents and Ticking TileEntities this can be very useful for modders and server owners that want to find a lag source.<br /><br />== Using the Debug Profiler ==<br /><br />The Debug Profiler is very simple to use. It requires two commands <code><nowiki>/debug start</nowiki></code>, which starts the profiling process, and <code><nowiki>/debug stop</nowiki></code>, which ends it. The important part here is that the more time you give it to collect the data the better the results will be. It is recommended to at least let it collect data for a minute.<br /><br /><br />Naturally, you can only profile code paths that are actually being reached. Entities and TileEntities that you want to profile must exist in the world to show up in the results.<br /><br /><br />After you’ve stopped the debugger it will create a new file, it can be found within the <code><nowiki>debug</nowiki></code> subdirectory in your run directory. The file name will be formatted with the date and time as <code><nowiki>profile-results-yyyy-mm-dd_hh.mi.ss.txt</nowiki></code>.<br /><br />== Reading a Profiling result ==<br /><br />At the top it first tells you how long in milliseconds it was running and how many ticks ran in that time.<br /><br />Below that, you will find information similar to the snippet below:<br /><br /><br /><code>[00] levels - 96.70%/96.70%<br />[01] | World Name - 99.76%/96.47%<br />[02] | | tick - 99.31%/95.81%<br />[03] | | | entities - 47.72%/45.72%<br />[04] | | | | regular - 98.32%/44.95%<br />[04] | | | | blockEntities - 0.90%/0.41%<br />[05] | | | | | unspecified - 64.26%/0.26%<br />[05] | | | | | minecraft:furnace - 33.35%/0.14%<br />[05] | | | | | minecraft:chest - 2.39%/0.01%</code><br /><br /><br />Here is a small explanation of what each part means<br />
+
Minecraft provides a Debug Profiler that can be used to find time consuming code. Specially considering things like TickEvents and Ticking TileEntities this can be very useful for modders and server owners that want to find a lag source.
{| class="wikitable" style="width: 850px;" data-mce-style="width: 850px;"
+
 
 +
== Using the Debug Profiler ==
 +
 
 +
The Debug Profiler is very simple to use. It requires two commands <code><nowiki>/debug start</nowiki></code>, which starts the profiling process, and <code><nowiki>/debug stop</nowiki></code>, which ends it. The important part here is that the more time you give it to collect the data the better the results will be. It is recommended to at least let it collect data for a minute.
 +
 
 +
<block tip>
 +
Naturally, you can only profile code paths that are actually being reached. Entities and TileEntities that you want to profile must exist in the world to show up in the results.
 +
</block>
 +
 
 +
After you’ve stopped the debugger it will create a new file, it can be found within the <code><nowiki>debug</nowiki></code> subdirectory in your run directory. The file name will be formatted with the date and time as <code><nowiki>profile-results-yyyy-mm-dd_hh.mi.ss.txt</nowiki></code>.
 +
 
 +
== Reading a Profiling result ==
 +
 
 +
At the top it first tells you how long in milliseconds it was running and how many ticks ran in that time.
 +
 
 +
Below that, you will find information similar to the snippet below:
 +
 
 +
<syntaxhighlight>
 +
[00] levels - 96.70%/96.70%
 +
[01] |   World Name - 99.76%/96.47%
 +
[02] |   |   tick - 99.31%/95.81%
 +
[03] |   |   |   entities - 47.72%/45.72%
 +
[04] |   |   |   |   regular - 98.32%/44.95%
 +
[04] |   |   |   |   blockEntities - 0.90%/0.41%
 +
[05] |   |   |   |   |   unspecified - 64.26%/0.26%
 +
[05] |   |   |   |   |   minecraft:furnace - 33.35%/0.14%
 +
[05] |   |   |   |   |   minecraft:chest - 2.39%/0.01%
 +
</syntaxhighlight>
 +
 
 +
Here is a small explanation of what each part means
 +
 
 +
{| class="wikitable sortable" border=1
 +
! [02]  !! tick  !! 99.31%  !! 95.81% 
 
|-
 
|-
| style="width: 188px;" data-mce-style="width: 188px;"|[02]<br />
+
| The Depth of the section  || The Name of the Section  || The percentage of time it took in relation to it’s parent. For Layer 0 it’s the percentage of the time a tick takes, while for Layer 1 it’s the percentage of the time its parent takes  || The second Percentage tells you how much Time it took from the entire tick.  
| style="width: 191px;" data-mce-style="width: 191px;"|tick<br />
 
| style="width: 237px;" data-mce-style="width: 237px;"|99.31%<br />
 
| style="width: 89px;" data-mce-style="width: 89px;"|95.81%<br />
 
 
|-
 
|-
| style="width: 188px;" data-mce-style="width: 188px;"|The Depth of the section<br />
 
| style="width: 191px;" data-mce-style="width: 191px;"|The Name of the Section<br />
 
| style="width: 237px;" data-mce-style="width: 237px;"|The percentage of time it took in relation to it’s parent. For Layer 0 it’s the percentage of the time a tick takes, while for Layer 1 it’s the percentage of the time its parent takes<br />
 
| style="width: 89px;" data-mce-style="width: 89px;"|The second Percentage tells you how much Time it took from the entire tick.<br />
 
 
|}
 
|}
<br />== Profiling your own code ==<br /><br />The Debug Profiler has basic support for <code><nowiki>Entity</nowiki></code> and <code><nowiki>TileEntity</nowiki></code>. If you would like to profile something else, you may need to manually create your sections like so:<br /><br /><code><br /> Profiler#startSection(yourSectionName : String);<br /> ''The code you want to profile<br /> Profiler#endSection();<br /></code><br /><br />You can obtain the the <code><nowiki>Profiler</nowiki></code> instance from a <code><nowiki>World</nowiki></code>, <code><nowiki>MinecraftServer</nowiki></code>, or <code><nowiki>Minecraft</nowiki></code> instance. Now you just need to search the File for your section name.
+
 
 +
== Profiling your own code ==
 +
 
 +
The Debug Profiler has basic support for <code><nowiki>Entity</nowiki></code> and <code><nowiki>TileEntity</nowiki></code>. If you would like to profile something else, you may need to manually create your sections like so:
 +
 
 +
<syntaxhighlight lang="Java">
 +
  Profiler#startSection(yourSectionName : String);
 +
  ''The code you want to profile
 +
  Profiler#endSection();
 +
</syntaxhighlight>
 +
 
 +
You can obtain the the <code><nowiki>Profiler</nowiki></code> instance from a <code><nowiki>World</nowiki></code>, <code><nowiki>MinecraftServer</nowiki></code>, or <code><nowiki>Minecraft</nowiki></code> instance. Now you just need to search the File for your section name.

Revision as of 13:29, 24 October 2020

Minecraft provides a Debug Profiler that can be used to find time consuming code. Specially considering things like TickEvents and Ticking TileEntities this can be very useful for modders and server owners that want to find a lag source.

Using the Debug Profiler

The Debug Profiler is very simple to use. It requires two commands /debug start, which starts the profiling process, and /debug stop, which ends it. The important part here is that the more time you give it to collect the data the better the results will be. It is recommended to at least let it collect data for a minute.

<block tip> Naturally, you can only profile code paths that are actually being reached. Entities and TileEntities that you want to profile must exist in the world to show up in the results. </block>

After you’ve stopped the debugger it will create a new file, it can be found within the debug subdirectory in your run directory. The file name will be formatted with the date and time as profile-results-yyyy-mm-dd_hh.mi.ss.txt.

Reading a Profiling result

At the top it first tells you how long in milliseconds it was running and how many ticks ran in that time.

Below that, you will find information similar to the snippet below:

[00] levels - 96.70%/96.70%
[01] |   World Name - 99.76%/96.47%
[02] |   |   tick - 99.31%/95.81%
[03] |   |   |   entities - 47.72%/45.72%
[04] |   |   |   |   regular - 98.32%/44.95%
[04] |   |   |   |   blockEntities - 0.90%/0.41%
[05] |   |   |   |   |   unspecified - 64.26%/0.26%
[05] |   |   |   |   |   minecraft:furnace - 33.35%/0.14%
[05] |   |   |   |   |   minecraft:chest - 2.39%/0.01%

Here is a small explanation of what each part means

[02] tick 99.31% 95.81%
The Depth of the section The Name of the Section The percentage of time it took in relation to it’s parent. For Layer 0 it’s the percentage of the time a tick takes, while for Layer 1 it’s the percentage of the time its parent takes The second Percentage tells you how much Time it took from the entire tick.

Profiling your own code

The Debug Profiler has basic support for Entity and TileEntity. If you would like to profile something else, you may need to manually create your sections like so:

Profiler#startSection(yourSectionName : String);
  ''The code you want to profile
  Profiler#endSection();

You can obtain the the Profiler instance from a World, MinecraftServer, or Minecraft instance. Now you just need to search the File for your section name.