Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OTS Statistics by kondra for TFS 1.6+ #4874

Open
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

gesior
Copy link
Contributor

@gesior gesior commented Dec 14, 2024

It's well known 'OTS stats' system with LIMITED FUNCTIONALITY FOR TFS 1.6+:
It does not track C++ functions executed by dispatcher as it's not possible on 1.6+ ( #4306 (comment) ).
To track usage by C++ functions, you have to add AutoStat to each function you want to track. More about it at end of this PR.

It tracks all Lua function calls and SQL queries.
It generates files lua.log and sql.log in stats/ that looks like:

[14/12/2024 02:19:43] Players online: 0
 Time (ms)     Calls     Rel usage %    Real usage % Description
         0        70       41.44366%        0.00420% data/npc/scripts/default.lua:onThink
         0        30       19.20608%        0.00195% data/npc/scripts/runes.lua:onThink
         0        10       11.75076%        0.00119% data/npc/scripts/bank.lua:onThink
         0        10       10.38807%        0.00105% data/npc/scripts/The Oracle.lua:onThink
         0        10        9.37099%        0.00095% data/npc/scripts/promotion.lua:onThink

Report interval is configurable in config.lua.

It also reports slow/very slow function calls in files lua_slow.log and sql_slow.log. Ex. startup.lua onStartup event execution time is higher than 10 ms, it's reported as slow in lua_slow.log:

[14/12/2024 02:19:23] Execution time: 14 ms - data/globalevents/scripts/startup.lua:onStartup - 

SQL took over 10 ms, it's reported as slow:

[29/01/2023 16:06:07] Execution time: 24 ms - TRUNCATE TABLE `towns` - TRUNCATE TABLE `towns`

Slow/very slow time is configurable in config.lua

There are also special.log, special_slow.log and special_very_slow.log, which report your custom statistics. Ex. to report decay time of items, in game.cpp under:

void Game::internalDecayItem(Item* item)
{

add:

AutoStat stat("internalDecayItem", std::to_string(item->getID()));

String internalDecayItem will be used for total CPU usage report. Second parameter (item ID) will be reported in slow and very_slow logs. In this case, it would say which item ID decayed over 10 ms (single item decay time, not all items with this item ID).
Most of OTSes pass player name as second parameter. It let them track which player generated 'slow' actions - lagged OTS.

@Codinablack
Copy link
Contributor

There are plenty of profiling tools already available. Even if someone wanted both instrumentation and sampling, there are still plenty of FOSS softwares out there that have whole teams of people who study this field of programming working on them. I think adding this to TFS would be a mistake, it's not needed, and for many like myself, not wanted. If I wanted to profile a TFS server, I certainly wouldn't use this code, I would get a professional grade profiler to do the job.

Adding this system is adding un-needed, un-necessary, and un-asked for bloat to the code base, even with the #ifdef's, the core part of the code is added (stats.cpp/stats.h) whether or not it's enabled. Even if this system does an "ok" job, there are still plenty of FOSS profilers and paid profilers out there that would undoubtedly do a much better job, and still allows users the freedom to decide if they want to profile by sampling, or profile by instrumentation.

It's just my opinion on the matter.

@Tofame
Copy link
Contributor

Tofame commented Dec 15, 2024

This will be difference between having something or having nothing at all.

I cannot even imagine devs downloading or paying for 3rd party profilers (obviously first a person would have to learn how to use and attach them to the engine (like its gonna happen xd))... all while there is ready&&free commmit that can do it for them.

Simple, free, and all work already done by Gesior/Kondrah. 100% needs to be merged.

@ArturKnopik
Copy link
Contributor

I think it's a useful piece of code, it allows developer to catch weak points at the development stage. I agree with @Tofame about 3rd party profilers.

@Codinablack
Copy link
Contributor

Codinablack commented Dec 16, 2024

I cannot even imagine devs downloading or paying for 3rd party profilers (obviously first a person would have to learn how to use and attach them to the engine (like its gonna happen xd))...

Well, if the user doesn't have the ability or time to learn how to setup a profiler, then what are they actually gaining from even using one in the first place? I mean seriously, the people who can't figure out how to attach a profiler to a process, aren't going to know what to do with the data they are getting!

Besides they don't need to download or pay, both Windows and Linux come stock with profilers. Visual studio has profiler built into it , and linux has various tools at its disposal as stock (depends on which ones for which distro). Both windows and linux users can use Jetbrains Rider for free, which also has a profiler.

At any rate, I obviously highly disagree with the thought that this needs merged. This "limited" version isn't even worth its overhead. While I will agree it's beneficial to have detailed data about used resources, I think this "limited" instrumentation is just a bloat that would be in the way for a real instrumentation job.
Besides, sampling is highly effective, we should not be taking the instrumentation route automatically for the end users... that kind of decision for extreme measures should always be their own choice.

@gesior
Copy link
Contributor Author

gesior commented Dec 16, 2024

I mean seriously, the people who can't figure out how to attach a profiler to a process, aren't going to know what to do with the data they are getting!

I tuned a bit first post stats to some values you may get on real OTS with bugged Lua script:

[14/12/2024 02:19:43] Players online: 5
 Time (ms)     Calls     Rel usage %    Real usage % Description
         9517       10      90.37099%        90.00951% data/npc/scripts/promotion.lua:onThink
         423        70       4.144366%        4.20123% data/npc/scripts/default.lua:onThink
         192        30       1.920608%        1.95123% data/npc/scripts/runes.lua:onThink
         175        10       1.175076%        1.19123% data/npc/scripts/bank.lua:onThink
         123        10       1.038807%        1.05123% data/npc/scripts/The Oracle.lua:onThink

[14/12/2024 02:19:39] Execution time: 9011 ms - data/npc/scripts/promotion.lua:onThink - 

Do you need to know how to setup profiler to read which Lua script is a problem?

If someone still doesn't get it, there is a tutorial: https://otland.net/threads/how-to-read-ots-statistics-logs.283722/

@Codinablack
Copy link
Contributor

I mean seriously, the people who can't figure out how to attach a profiler to a process, aren't going to know what to do with the data they are getting!

I tuned a bit first post stats to some values you may get on real OTS with bugged Lua script:

[14/12/2024 02:19:43] Players online: 5
 Time (ms)     Calls     Rel usage %    Real usage % Description
         9517       10      90.37099%        90.00951% data/npc/scripts/promotion.lua:onThink
         423        70       4.144366%        4.20123% data/npc/scripts/default.lua:onThink
         192        30       1.920608%        1.95123% data/npc/scripts/runes.lua:onThink
         175        10       1.175076%        1.19123% data/npc/scripts/bank.lua:onThink
         123        10       1.038807%        1.05123% data/npc/scripts/The Oracle.lua:onThink

[14/12/2024 02:19:39] Execution time: 9011 ms - data/npc/scripts/promotion.lua:onThink - 

Do you need to know how to setup profiler to read which Lua script is a problem?

Yes, because the kondra "stats" system is a profiler.
The log that you are using to see which script is a problem, its generated from your profiler (in this case the kondra stats) through a method known as "instrumentation"... Your way of doing it requires intrusive code into the codebase to find the lua script.

I prefer to just simply push the play/run button in my favorite IDE (both Rider and VS come with this feature built in) and launch my server through the IDE rather than add code to my server, and still get the relevant information I need via "sampling" instead of "instrumentation"... both will indicate the high usage of CPU from the process "onThink", and so ultimately both will get the job done, but with my way, I don't have a choice forced upon me.

@kojimhojo
Copy link

kojimhojo commented Dec 17, 2024

I prefer to just simply push the play/run button in my favorite IDE (both Rider and VS come with this feature built in) and launch my server through the IDE rather than add code to my server,

Off-topic related to OTS stats-profiler (source of this discussion):
@Codinablack
I wanted to make this recommendation to you on Discord, but you disappeared from OTA. Maybe it would be a good idea to add a tutorial video (I remember seeing you make one about Premake compilation) to your wiki or devdocs on how to "just simply push the play/run button in the IDE" for your Blacktek project (not how to interpret it, just how to do it)

(of course only if you have time.)

That could also be useful to this repo and the entire community.

@ArturKnopik
Copy link
Contributor

I prefer to just simply push the play/run button in my favorite IDE (both Rider and VS come with this feature built in) and launch my server through the IDE rather than add code to my server,

Off-topic: @Codinablack I wanted to make this recommendation to you on Discord, but you disappeared from OTA. Maybe it would be a good idea to add a tutorial video (I remember seeing you make one about Premake compilation) to your wiki or devdocs on how to "just simply push the play/run button in the IDE" for your Blacktek project

please, use his repo to talk about his project... open issue or something

@Codinablack
Copy link
Contributor

Off-topic related to OTS stats-profiler (source of this discussion): @Codinablack I wanted to make this recommendation to you on Discord, but you disappeared from OTA. Maybe it would be a good idea to add a tutorial video (I remember seeing you make one about Premake compilation) to your wiki or devdocs on how to "just simply push the play/run button in the IDE" for your Blacktek project (not how to interpret it, just how to do it)

(of course only if you have time.)

That could also be useful to this repo and the entire community.

I have to agree with @ArturKnopik this is not the place for that discussion, just reach out to me on discord or otland if you need to talk with me.

When I said "my server" I was speaking in a general context of an end user for TFS. As a user of TFS, I would rather have my server ran through my choice of profiler, than for the devs to just add a "limited" instrumentation job.

@Tofame
Copy link
Contributor

Tofame commented Dec 17, 2024

The amount of shit, unoptimized code will only increase, because of GPT overuse (abuse). OTland resources tab is full of GPT generated scripts that are terrible.

A step has to be taken, a code that simply generates logs for you without doing much work is very good.

You can then do whatever, analyse by yourself or even send those logs.txt to someone knowledgable, pay.him/her and he/she will fix parts of code that will be needed without a need to send that person full sources/exe to run and profile.

You forget about users of TFS/Canary, that are not developers (majority). A lot of amateurs that dont know what they are doing, if explained by a bit in documentation will learn to make use of it and improve their OTs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants