|
|
| (4 intermediate revisions by 3 users not shown) |
| Line 1: |
Line 1: |
| − | The SourceMod profiler is a built-in tool for measuring the performance of SourceMod natives and plugins.
| + | SourceMod has built-in profiling support for plugins with integration into the game's "vprof" system. |
| | | | |
| − | It is currently an "alpha" addition. While it was tested to work, there may be cases where it breaks. Do not use it in a production environment -- it is intended as a tool for developers.
| + | See the "sm prof" command for more details. |
| − | | |
| − | =Introduction=
| |
| − | The SourceMod Profiler tracks "profilable items." These items are:
| |
| − | * Native calls from plugins.
| |
| − | * Callbacks into plugins.
| |
| − | * Internal function calls in plugins.
| |
| − | | |
| − | The following statistics are tracked for each item:
| |
| − | * Number calls.
| |
| − | * Total time spent in all calls.
| |
| − | * Minimum time spent in any call.
| |
| − | * Maximum time spent in any call.
| |
| − | | |
| − | These statistics can be used to gauge how well your plugin is performing. It can also be used to tweak and optimize your code where necessary.
| |
| − | | |
| − | =Usage=
| |
| − | ==Configuration==
| |
| − | The profiler can only be enabled in <tt>configs/plugin_settings.cfg</tt>. You can enable it on any number of plugins at a time. However, it is a good idea to only profile what you need.
| |
| − | | |
| − | The profiler can be configured with the "profile" option key in an "Options" section. The value should be a bits added up:
| |
| − | * 1 - Profile natives.
| |
| − | * 2 - Profile callbacks.
| |
| − | * 4 - Profile functions (implies 2).
| |
| − | | |
| − | Example for profiling "adminhelp":
| |
| − | <pre>
| |
| − | "*"
| |
| − | {
| |
| − | "pause" "no"
| |
| − | "lifetime" "mapsync"
| |
| − |
| |
| − | "Options"
| |
| − | {
| |
| − | "debug" "no"
| |
| − | "profile" "7"
| |
| − | }
| |
| − | }
| |
| − | </pre>
| |
| − | | |
| − | ==Getting Results==
| |
| − | You can use "sm profiler flush" in your console to dump and reset the profiler statistics. The output will be written to an XML file in your <tt>sourcemod/logs</tt> folder. For example: <tt>addons/sourcemod/logs/profile_1204422886.xml</tt> (note that a timestamp is included).
| |
| − | | |
| − | There is no way to stop the profiler entirely save from editing <tt>plugin_settings.cfg</tt>
| |
| − | | |
| − | | |
| − | =Interpreting Results=
| |
| − | [[image:Sm_profiler.PNG|thumb|right|300px|Profiler Screenshot]]
| |
| − | The easiest way to interpret the results is to use the <tt>profviewer.exe</tt> tool available on SourceMod's downloads page. It requires the [http://www.microsoft.com/downloads/details.aspx?FamilyID=0856EACB-4362-4B0D-8EDD-AAB15C5E04F5&displaylang=en .NET 2.0 Framework]. You can open profiler .xml files with this tool and sort the various result metrics (descending order only).
| |
| − | | |
| − | What do the results actually mean? All times are in seconds. The "min" and "max" times are single measurements. The "average" time is the total time spent divided by the number of calls. Function names are displayed as raw names for natives, or "a!b" for plugins, where "a" is the plugin filename and "b" is the function name.
| |
| − | | |
| − | It is important to note how the time values are actually computed. You may find the results to be deceiving otherwise. Take the following list of events:
| |
| − | *Core calls <tt>OnClientCommand</tt> in plugin <tt>a.smx</tt>
| |
| − | *<tt>a.smx!OnClientCommand</tt> calls <tt>a.smx!StrEqual</tt>
| |
| − | *<tt>a.smx!StrEqual</tt> calls <tt>strcmp()</tt>
| |
| − | | |
| − | SourceMod computes each item's time by adding in its children's time. For example, the time <tt>t(a.smx!OnClientCommand)</tt> will be equal to:
| |
| − | <pre>t(a.smx!OnClientCommand) + t(a.smx!StrEqual) + t(strcmp)</pre>
| |
| − | | |
| − | Likewise, the time of <tt>StrEqual</tt> will be equal to:
| |
| − | <pre>t(a.smx!StrEqual) + t(strcmp)</pre>
| |
| − | | |
| − | This has two major implications:
| |
| − | *'''You cannot profile recursive functions'''. The data will be nonsensical. Use <tt>profiler.inc</tt> for manually timing recursive calls.
| |
| − | *The time of re-entrant functions may be deceiving. For example, <tt>DisplayMenu()</tt> may appear very slow, but that's because it may fire dozens of callbacks. Similarly, the custom sorting natives' time will include their callbacks' time.
| |
| − | | |
| − | ''Note: The profile does not include its own operations when timing items. There is a small margin of error, however.''
| |
| − | | |
| − | In general, you should not go insane trying to optimize unless there is a good reason. For example, an <tt>OnGameFrame</tt> callback may be called 200 times per minute, and thus if its average time exceeds reasonable values (say, a dozen milliseconds) then you may want to consider optimizing it. However, if you see that a particular call to <tt>LoadTranslations()</tt> is taking 150ms, you shouldn't worry too much - that function only gets called on load.
| |
| − | | |
| − | Use your judgment when interpreting the results, and don't go crazy. If you need advice, post on the forums.
| |
| − | | |
| − | | |
| − | =File Format=
| |
| − | The file format is XML. The contents are fairly self-explanatory, as there are only three elements. Sample parsers are included in the SourceMod source code tree:
| |
| − | | |
| − | *<tt>tools/csharp</tt> - Source code for the profviewer.exe program. <tt>ProfReport.cs</tt> implements the parser.
| |
| − | *<tt>php/ProfFileParser.class.php</tt> - Source code for a PHP parser. Requires PHP5 and libexpat (XML) support.
| |
| | | | |
| | [[Category:SourceMod Development]] | | [[Category:SourceMod Development]] |
| | [[Category:SourceMod Scripting]] | | [[Category:SourceMod Scripting]] |
