• There is NO official Otland's Discord server and NO official Otland's server list. The Otland's Staff does not manage any Discord server or server list. Moderators or administrator of any Discord server or server lists have NO connection to the Otland's Staff. Do not get scammed!

Feature [TFS 1.4] OTS statistics (C++/Lua/SQL) by kondra

Gesior.pl

Mega Noob&LOL 2012
Senator
Joined
Sep 18, 2007
Messages
2,955
Solutions
98
Reaction score
3,351
Location
Poland
GitHub
gesior
I've got permission from kondra (otclient@************) to release this code. He only requested to leave information about author kondra (otclient@otclient ovh) in commit message.

Code is too long to post it here. Commit with all required changes for TFS 1.4:

How to read logs: How to read OTS Statistics logs (https://otland.net/threads/how-to-read-ots-statistics-logs.283722/)

It's well known 'OTS stats' system. It tracks all dispatcher thread tasks, Lua function calls and SQL queries.
It generates files dispatcher.log, lua.log and sql.log in data/logs/stats that look like:
Code:
[29/01/2023 16:08:37]
Thread: 1 Cpu usage: 0.628848% Idle: 99.6671% Other: -0.295933% Players online: 0
 Time (ms)     Calls     Rel usage %    Real usage % Description
       167       120       88.80196%        0.55843% std::bind(&Game::checkDecay, this)
        20       300       10.83945%        0.06816% std::bind(&Game::checkCreatures, this, (index + 1) % EVENT_CREATURECOUNT)
         0        12        0.30616%        0.00193% std::bind(&Game::updateWorldTime, this)
Report interval is configurable in config.lua.

It also reports slow/very slow function calls in files dispatcher_slow.log, lua_slow.log and sql_slow.log.
Ex. server start takes over 50 ms, it's reported as very slow dispatcher_very_slow.log:
Code:
[29/01/2023 16:06:07] Execution time: 466 ms - std::bind(mainLoader, argc, argv, &serviceManager) - main
Lua startup.lua executes over 10 ms, it's reported as slow:
Code:
[29/01/2023 16:06:07] Execution time: 35 ms - data/globalevents/scripts/startup.lua:onStartup -
SQL took over 10 ms, it's reported as slow:
Code:
[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:
C++:
void Game::internalDecayItem(Item* item)
{
add:
C++:
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 OTSes pass player name as second parameter. It let them track which player generated 'slow' actions - lagged OTS.

EDIT:
I've added OTS statistics to someone's TFS 0.4 (attached ZIP). I do not recommend using this engine. It's some random 10 years old 0.4, not engine of popular OTS.
There is a .git, so you can view changes I've made.
Converting OTS stats code to 0.4 format takes too much time. I've just replaced all dispatcher/scheduler 0.4 code with 1.4 code.
 

Attachments

  • tfs_0.4_ots_stats.zip
    1.8 MB · Views: 105 · VirusTotal
Last edited:
thank you kondrah.
the only dev that has brought ots forward since 5 years
gesior is a man too.
A lot of people published new features on TFS github MR/Issues (ex. cast systems), but they were never merged.
Features I've published:
 
Great contribution!!

Btw, I am interested on new decay system
A lot of people published new features on TFS github MR/Issues (ex. cast systems), but they were never merged.
Features I've published:
 
Great contribution!!

Btw, I am interested on new decay system
Reuploaded it:
It's based on some 2019 TFS version that does not compile anymore, but I've tested it in 2019 and everything worked fine.
 
Thanks kongra and gesior. It's sad to see that such interesting things are not merged...

About OTS Statistics, is it good to use it in a reproduction environment, would it affect the progress of the server in any way?
 
A lot of people published new features on TFS github MR/Issues (ex. cast systems), but they were never merged.
Features I've published:

ive known binary items. my friend ots uses it. should 100% be merfged since years back. but instead tfs devs focuses on making client 12x for 0 reason. very sad direction tfs went in last years :(

how u play cam files on otcv8? just open them? :O
 
About OTS Statistics, is it good to use it in a reproduction environment, would it affect the progress of the server in any way?
I've worked for many servers from top 50 of otservlist, 90% of them use this system all time, no matter, if they have 200 or 2000 online.
That's why I've asked kondra about releasing it. If 90% of popular servers already got it, who will buy it for 300$? There is no more customers for his premium code.
Maybe someday he will decide to release cam system, cast system and multithread pathfinding (@kondra ?? :) ).

I haven't benchmarked it yet, but I expect it to use around 1% of CPU on 'dispatcher thread' (pass function name with each 'task'), plus around 1% of CPU on 'stats thread' (save stats in file .log, count calls/total CPU time).

Right now it can be disabled by compiling without STATS_ENABLED definition (it's kondra's code), but I would remove that and make it always compile with stats. It's just too useful. Especially for newbies that install some random Lua scripts from forum and then don't know why their server lags. With OTS stats they could just post stats.zip with their stats and experienced programmers would find reason in seconds.

On Kasteria.pl we found some dumb Lua functions that wasted a lot of CPU using OTS stats.
Ex. getPlayesOnline() (list of players) with 2500 online took 0.1 second. 0.1 sec lag on OTS, to pass list of 2500 IDs from C++ to Lua!
getPlayerByName(name) defined in Lua (getCreatureByName(name), then check isPlayer(cid), not in C++, which made engine loop over 50k monsters, to check, if player who bought item in premium shop is online (shop.lua script).
Both problems are fixed in TFS 1.x, but if you are running 0.4, OTX2 or some other old engine, you may have these bugs.

20 lines of code to change in C++ and we saved around 10% CPU + removed lags on 'new edition start'.

Before we installed stats, I though that it's lagging on start, because 2000 players run around on rook, many of them see 100+ other players on screen and server just can't handle that much data.
With stats I found that lagging script was "first level/skill on server" (onAdvance), which broadcasted "Xxx made level/skill XX first on server". There was nothing except getPlayersOnline() to broadcast message that could use that CPU. That way I found what is lagging OTS.

In newest version of kondra's code (that I've posted), there is AutoStat feature, that let you track any C++ function/block of code (it uses C++ constructor/destructor to start/end measurement) CPU usage/number of calls.
For new server, I would add it in every single C++ function in luascripts.cpp, to track usage of each Lua function.

how u play cam files on otcv8? just open them? :O
This feature of OTCv8 has no module to manage/load/play cams, so it looks bad ('login window' stays open, while you play cam etc.) in OTC, but it works.
You got to create directory records, put .cam there (generated by server), open Terminal (CTRL+T) and type ( otcv8-dev/1098.lua at 44de2773b08b6d498130eeba7fbe57a05d08759a · OTCv8/otcv8-dev (https://github.com/OTCv8/otcv8-dev/blob/44de2773b08b6d498130eeba7fbe57a05d08759a/tests/1098.lua#L5-L7) ):
Code:
        g_game.setClientVersion(1098)
        g_game.setProtocolVersion(g_game.getClientProtocolVersion(1098))
        g_game.playRecord("1098.cam")
I've noticed one bug in newest OTCv8. It ignores that setClientVersion function, you got to set that protocol in 'login window' too (window with login/password to login to OTS).

OTCv8 may also record .cam when you login to game using it. To enable this feature you got to pass 1 more parameter to loginWorld ( otcv8-dev/game.h at 0006f81ae695447a6e690f3e2648379f27e7586d · OTCv8/otcv8-dev (https://github.com/OTCv8/otcv8-dev/blob/0006f81ae695447a6e690f3e2648379f27e7586d/src/client/game.h#L172) ).
Replace ( otcv8-dev/characterlist.lua at 44de2773b08b6d498130eeba7fbe57a05d08759a · OTCv8/otcv8-dev (https://github.com/OTCv8/otcv8-dev/blob/44de2773b08b6d498130eeba7fbe57a05d08759a/modules/client_entergame/characterlist.lua#L33) ):
Lua:
g_game.loginWorld(G.account, G.password, charInfo.worldName, charInfo.worldHost, charInfo.worldPort, charInfo.characterName, G.authenticatorToken, G.sessionKey)
with:
Lua:
g_game.loginWorld(G.account, G.password, charInfo.worldName, charInfo.worldHost, charInfo.worldPort, charInfo.characterName, G.authenticatorToken, G.sessionKey, os.time() .. '.cam')
 
Last edited:
there is much many conflicts adding this "binary items/depot items save [works], cache items of offline players in OTS RAM + save items to database in second thread "
can somebody do this for me?
 
there is much many conflicts adding this "binary items/depot items save [works], cache items of offline players in OTS RAM + save items to database in second thread "
can somebody do this for me?
Do it by yourself.

The people even having free code released wants to have everything served on a silver tray, atleast do some effort by yourself.
 
It's good that now many people that had no clue on how to measure performance of code before can have at least something.
Thanks for sharing the code so it can at least serve as an inspiration for more benchmarks in our community.


However, it's oddly weird to see programmers not knowing CPP has an extensive list of profilers that can even attach to running applications and do this analysis without having to actually compile something in your sources. Back in my time we used perf but nowadays there way better alternatives:
Video analyzing perf report graph + finetuning cpp parameters:

1) Poor Man's Profiler (https://poormansprofiler.org/) - since all you still uses gdb in prod either way
2) Gprof (this one works quite similar, by adding code on top and recompiling, but it's 100x better in its statistics)
3) Valgrind / Callgrind
4) Oprofile
and today I also saw there's a new name in town that loooks quite interesting:
5) Orbit
 
I think you can't read.
I get that your English is not top notch, but to a point where you have hard time understanding own statements?
You said that its a good feature for server in production, BUT you would still use profiler instead of this feature.
 
I get that your English is not top notch, but to a point where you have hard time understanding own statements?
You said that its a good feature for server in production, BUT you would still use profiler instead of this feature.
It's just overall common sense profile applications while developing them and not in prod situation, there's very few examples I can think of that you would need to have 200 players online and not just 2. Even the examples explained by gesior can be reproducible without a single player online.
 
It's just overall common sense profile applications while developing them and not in prod situation, there's very few examples I can think of that you would need to have 200 players online and not just 2. Even the examples explained by gesior can be reproducible without a single player online.
Plenty of scripts can have significant difference in execution based on number of players, like based on different inputs. Also gathering stats of server usage in production is a very common thing. That's how you are able to optimize everything, because you have data from real situations, not virtual/forced/predictions in development.
 
Back
Top