Difference between revisions of "Debug Profiler"

From Forge Community Wiki
(Inital import from dokuwiki)
 
(Update debug profiler to 1.17, come back later to address new profiling information)
 
(5 intermediate revisions by 3 users not shown)
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 />
+
{{Under construction}}
{| class="wikitable" style="width: 850px;" data-mce-style="width: 850px;"
+
 
 +
Minecraft provides a Debug Profiler that provides system data, current game settings, JVM data, level data, and sided tick information to find time consuming code. Considering things like TickEvents and ticking BlockEntities, 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. The keybind <code>F3 + L</code> can be used to start the profiler. After 10 seconds, the profiler will automatically stop; however, it can be stopped earlier by pressing the keybind again.
 +
 
 +
{{Tip/Important| The <code>/debug</code> still runs; however, no data will be dumped to any location.}}
 +
 
 +
{{Tip|You can only profile code paths that are actually being reached. Entities and Block Entities that you want to profile must exist in the level to show up in the results.}}
 +
 
 +
After the debugger has stopped, it will create a new zip within the <code>debug/profiling</code> subdirectory in your run directory. The file name will be formatted with the date and time as <code>yyyy-mm-dd_hh_mi_ss-WorldName-VersionNumber.zip</code>.
 +
 
 +
== Reading a Profiling result ==
 +
 
 +
Within each sided folder (<code>client</code> and <code>server</code>), you will find a <code>profiling.txt</code> file containing the result data. 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] |   Level 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"
 +
! [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>Entity</code> and <code>BlockEntity</code>. If you would like to profile something else, you may need to manually create your sections like so:
 +
 
 +
<syntaxhighlight lang="java">
 +
profiler.startSection("<a custom section name>");
 +
// The code you want to profile
 +
profiler.endSection(); // OR profier.endStartSection("<new section name>");
 +
</syntaxhighlight>
 +
 
 +
You can obtain the the <code>ProfilerFiller</code> instance from a <code>Level</code>, <code>MinecraftServer</code>, or <code>Minecraft</code> instance. Now you just need to search the file for your section name.
 +
 
 +
 
 +
[[Category:Beginner Topics]]

Latest revision as of 22:26, 29 July 2021

This page is under construction.

This page is incomplete, and needs more work. Feel free to edit and improve this page!

Minecraft provides a Debug Profiler that provides system data, current game settings, JVM data, level data, and sided tick information to find time consuming code. Considering things like TickEvents and ticking BlockEntities, 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. The keybind F3 + L can be used to start the profiler. After 10 seconds, the profiler will automatically stop; however, it can be stopped earlier by pressing the keybind again.

Important

The /debug still runs; however, no data will be dumped to any location.
You can only profile code paths that are actually being reached. Entities and Block Entities that you want to profile must exist in the level to show up in the results.

After the debugger has stopped, it will create a new zip within the debug/profiling subdirectory in your run directory. The file name will be formatted with the date and time as yyyy-mm-dd_hh_mi_ss-WorldName-VersionNumber.zip.

Reading a Profiling result

Within each sided folder (client and server), you will find a profiling.txt file containing the result data. 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] |   Level 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 BlockEntity. If you would like to profile something else, you may need to manually create your sections like so:

profiler.startSection("<a custom section name>");
// The code you want to profile
profiler.endSection(); // OR profier.endStartSection("<new section name>");

You can obtain the the ProfilerFiller instance from a Level, MinecraftServer, or Minecraft instance. Now you just need to search the file for your section name.