Page 1 of 1
util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 2:37 am
by doktorstick
Howdy.
I would like a debugging API to help identify performance bottlenecks. For instance:
Code: Select all
t1 = util.timestamp()
do_order_n_cubed_operations()
print ("function took", util.timestamp() - t1, "nanoseconds")
Optimally, it would measure only the time my code spent running, but if it cannot be that isolated, anything is better than nothing. Thanks for the consideration.
Re: util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 2:54 am
by keyboardhack
This would be nice but someone will probably use it incorrectly by only processing entities for n miliseconds per tick which would break multiplayer. To prevent this maybe this function should only function when the game is started with
Re: util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 3:26 am
by Nexela
having access to os.time and os.clock would be nice. But as keyboardhack said the potential for abuse is there.
Re: util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 9:51 am
by Choumiko
if you use
in your script it writes to the factorio current log, with a timestamp (seconds.milliseconds since Factorio was started i think)
Re: util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 10:55 am
by prg
If millisecond accuracy is enough you can just use log() to create timestamped log entries, then do the diff in your head. You probably want to stay way under 16ms in your on_tick handler, but this might still be useful for testing if you repeat the same operation a thousand times or so.
If you want to get access to os.clock() and co., good news! Turns out the os and io libraries are included in the Factorio executable, they're just getting disabled at startup, as was discovered in
RE Series Part 1: A wild LUA appears !. We just need to disable the code that disables the libraries so we can use them on our own system for debugging. For this we can just NOP out a few bytes in LuaHelper::initLuaState(lua_State*). Look at the adresses that get passed to lua_setglobal() to find the strings "io" and "os", then replace the instructions for that call and the preceding lua_pushnil() with NOPs (0x90). In the 0.13.15 64bit Linux executable these would be 42 bytes starting at offset 0x14867d. Now you can do
Code: Select all
t0 = os.clock()
-- do stuff
print(os.clock()-t0)
Just don't forget to remove that code again in the mod you publish.
Re: util.timestamp() for performance debugging
Posted: Sat Aug 13, 2016 3:24 pm
by aubergine18
keyboardhack wrote:This would be nice but someone will probably use it incorrectly by only processing entities for n miliseconds per tick which would break multiplayer.
If that's the case then just disable or edit the offending mod? Having access to os.time etc would make it much easier for modders to find out which specific lines, loops, etc., are hogging the most CPU in their mods.
Re: util.timestamp() for performance debugging
Posted: Sun Aug 14, 2016 12:28 am
by Nexela
If that's the case then just disable or edit the offending mod?
Well the typical mod user probably won't know which mod is causing the foobar leading to desync posts on the forum leading to devs spending time finding the offending mod, leading to the eventual discontinuince of said OS stuff again.
But as prg pointed out as mod developlers we do have a way to access OS for internal testing so all is good in the world!
Re: util.timestamp() for performance debugging
Posted: Thu Sep 08, 2016 9:15 pm
by aubergine18
Just noticed a console command that could be quite useful if your code is exposed via remote interface:
Code: Select all
/measured-command game.player.print 'how much time does this take to run?'
The `/measured-command` is like `/c` but tracks and displays the time taken to complete the operation.
Re: util.timestamp() for performance debugging
Posted: Mon Mar 18, 2019 7:16 pm
by Boodals
Although this is (or was, if a moderator moves it) in Won't implement, and is pretty old, I created a way to get performance metrics for lua scripts (I have source access), which will be in the next version of 0.17.
LuaGameScript.create_profiler, returns a LuaProfiler, which can be used anywhere a localised string is used. You can't read the raw time values from lua. This means that it is totally desync safe.