Better performance profiling

[CrosRoad95]

This idea was in my head for a long time, people uses "rescpu", popular resource to measure performance, but plain numer "10%" next to resource name does not tell the core of the cpu usage. Flag -g does not help too much in figuring out what cause server/client to degradate performance. Performance stats can tell you that some part of mta cause high cpu usage, but don't why, what is the excact source of the problem.

Almost everyone have a chrome or other chromium based browser which i used as a tool to display these information.
Idea is simple: make function that let you generate profile data to see them in chrome devtools:

( Based on image below ) With this amount of information, i can tell that "setElementData" in timer ( location can be seen in "summary" when i click on parent box ) cause the most cpu usage due "onElementDataChange" event, not by broadcasting.

It is very easy to use by mta developers, all you have to do is to put CPerformanceRecorder::Sample sample("name");, and everything is handled by you in background, you just set the name. There are also "FunctionSample" - to take a sample of mta native function, and "EventSample" for events. Optionaly you can use SetArg over sample to add custom content with important informations in "summary" tab.

In initial pr i want to add original timings, timers, events and setElementData function.

Example data you can test yourself by drag and dropping .json file onto "performance" tab in chrome devtools
result.zip

test code i used

Functions:
bool startRecordPerformance() - start performance recording
bool stopRecordPerformance() - stopping, pausing performance recording
bool clearPerformanceRecorder() - clearing samples buffer
bool isPerformanceRecording() - returns true when performance is recording
string getRecordedSamples() - returns string json kind with recorded samples

Test code ( 2 hours of running code below, ~300 executions did not cause any crash, memory leak. ):

assert(stopRecordPerformance() == false)
assert(isPerformanceRecording() == false)
assert(startRecordPerformance() == true)
assert(isPerformanceRecording() == true)
assert(startRecordPerformance() == false)

setTimer(function()
    setElementData(root, "asdf", math.random());
end,0,0)
for i=1,10 do
    setTimer(function()
        
    end,0,0)
end

setTimer(function()
    for i=1,5000000 do

    end
end,5000,1)

setTimer(function()
    assert(isPerformanceRecording() == true)
    assert(stopRecordPerformance() == true)
    assert(isPerformanceRecording() == false)
end,10000,1)

setTimer(function() -- should not be visible in profiler
    for i=1,5000000 do

    end
end,12500,1)

setTimer(function()
    assert(startRecordPerformance() == true)
    assert(isPerformanceRecording() == true)
end,15000,1)

setTimer(function()
    stopRecordPerformance()
    local data = getRecordedSamples()
    clearPerformanceRecorder()
    assert(getRecordedSamples() == "[]")
    local f = fileCreate("result.json");
    fileWrite(f, data)
    fileClose(f)
    setTimer(function()
        restartResource(getThisResource())
    end,500,1)
end, 20000, 1)

Memory usage:

Example generated data:

[Pirulax]

Nice.
I'd drop using hungarian notation tho, it's useless, makes your code uglier.

[Pirulax]

m_name

[Pirulax]

std::string category

[Pirulax]

m_startTime or something more descriptive

[Pirulax]

Also, not directly related to this PR, but I think there should be a special debug build of MTA, where all this debug stuff is enabled, because in the long run the profiler itself might cause performance issues.

[ArranTuna]

performancebrowser already shows you which functions in a resource use high CPU and what MTA functions (server side only) are using what. I don't understand why anyone would need any more. It would have been time better spent improving performance like the bug that causes GTA SA sounds to use a huge amount of FPS: #1067

[CrosRoad95]

Take for example this chunk of code:

setTimer(function()
    for i=1,1000000 do

    end
end,10000,1)

common case when some timer internal logic cause sudden cpu spike,
performance stats even with -d option, doesn't told me that even something is wrong in "xd" resource ( i took a screenshots every time values changed ) :

while my approach told me exactly where is the source of cpu spike:

[ArranTuna]

That's because there is no function name. I just tested it with a function name via runcode and it gave me:

function test()
    for i=1,10000000 do
		
    end
end
setTimer(test,1000,1)

[AlexTMjugador]

I think that, although a Chromium-based web browser is indeed pretty universal, depending on one to show this profile data is kind of awkward. I think that a browser-agnostic solution would be better, as after all web standards exist so Chrome doesn't become the new Internet Explorer. For example, I use Firefox as my daily web browser, and having to switch to another web browser just for this is, at least, inconvenient.

I suggest generating this profile information in a format that is compatible with profiler.firefox.com, a web application that works on all major web browsers that allows inspecting JSON profile data. I've just uploaded your example profile there, which you can see on this link, and it kinda works, so I'd say the generated profiles are in the right path at least.

Addressing @ArranTuna comments, performancebrowser is more focused on measuring the CPU usage of the Lua VM, memory usage and network usage, while this PR, as I understand it, instruments time-critical regions of MTA: SA source code to generate profile data, like CUnoccupiedVehicleSync::DoPulse. This allows detecting performance problems within MTA itself that are invisible to getPerformanceStats, and may provide insight on what exactly causes some scripting functions to be so slow, for instance.

[ArranTuna]

I've tested this PR and it's, interesting.

CLuaMain::PCall - is this lua scripts executing?

I did this: crun clearPerformanceRecorder() startRecordPerformance() setTimer(function() stopRecordPerformance() setClipboard(getRecordedSamples()) end, 5000, 1)

On play at a spawn:

With CIT scripts running in a busy area:

Even though I had FPS set to unlimited there are huge gaps in the chart, is this all the stuff that doesn't have a sample added or is it GTA SA code so can't have any sampling on the gaps?

I then did CIT scripts in a quiet area (I had 300 FPS instead of 100):

The miliseconds breakdown doesn't seem much different even though FPS was so much different so is that because GTA SA stuff which can't be sampled being what's causing the difference?

[patrikjuvonen]

Merge conflicts must be resolved.

Also like @Pirulax mentioned performance profiling should be enabled/compiled only for debug builds.

[CrosRoad95]

Merge conflicts must be resolved.

Also like @Pirulax mentioned performance profiling should be enabled/compiled only for debug builds.

with current knowlage, rather than enable it in debug mode only we might have a wrappers around some logics that measure performance

public class LuaFunctions : ILuaFunctions
{
  public setElementData(...) { ... }
}

public class LuaFunctionsWithProfiling : ILuaFunctions
{
private ILuaFunctions luaFunctions;
  public LuaFunctionsWithProfiling(ILuaFunctions luaFunctions)
  {
    
  }
  
  public setElementData(...) { 
    begin("function setElementData"));
    luaFunctions->setElementData(...);
    end("function setElementData"));
  }
}

public someLuaDefs{

  public static ILuaFunctions luaFunctions = nullptr;
  public static setElementData(string key, ...)
   {
luaFunctions ->setElementData(key,...)
  }
}

CCore::SetProfilingEnabled()
{
  someLuaDefs::luaFunctions = new LuaFunctionsWithProfiling (new LuaFunctions ())
}