Milliseconds time profiler for mods
Posted: Sun Dec 25, 2016 2:05 pm
Hello.
Factorio, with reason, doesn't provide access to the "os" object, less so to third party lua libraries. That makes it impossible to write a time profiler inside a mod.
I come up with a way to circunvect that. It's quite simple.
First, you have to add some instant logging capacity to your mod. I'm using stdlib.log (https://github.com/Afforess/Factorio-St ... er-example) for that. Be sure that you make debug=true when creating your log, like this:
Then, you create this lua file in the same directory LOGGER will be writing to. In my example, it would be "~/.factorio/script-output/logs/Your Mod Name":
Then you make sure to delete any existing copy of fancylog.log in that directory, and run the profiler from your terminal prompt, like this:
It will "hang", waiting fancylog.log to be created.
Next, you open factorio, load your modded game and let it run for as long as you want, do the actions you want to profile, etc. and exit the game (you don't have to save, if you don't want to).
Go back to the terminal where you are running the profiler and kill it with ctrl-C.
profile.log will look something like this:
The first column is the time, in integer milliseconds, since the last logged message. The second column is the tick number, as provided by stdlib.log and the third is your actual log messages.
This script uses the luasocket third party library, so we can get the time in milliseconds, as the default lua os.time() only gives precision in seconds.
The easiest way to get lua socket in a linux machine is run these commands in your pront:
That is it. Hope that will be useful to someone.
Factorio, with reason, doesn't provide access to the "os" object, less so to third party lua libraries. That makes it impossible to write a time profiler inside a mod.
I come up with a way to circunvect that. It's quite simple.
First, you have to add some instant logging capacity to your mod. I'm using stdlib.log (https://github.com/Afforess/Factorio-St ... er-example) for that. Be sure that you make debug=true when creating your log, like this:
Code: Select all
LOGGER = Logger.new("Your Mod Name", "fancylog", true, {log_ticks=true} )Code: Select all
require "socket"
local function getMS()
return socket.gettime() * 1000
end
local input
while not input do
input = io.open("fancylog.log")
end
io.output("profile.log")
local t1 = getMS()
while true do
while not input:read(0) do end
local t2 = getMS()
local dt = t2 - t1
local line = input:read("*line")
io.write(string.format("%12d: %s\n", dt, line))
io.flush()
t1 = t2
endCode: Select all
~/.factorio/script-output/logs/Your Mod Name $ lua profiler.luaNext, you open factorio, load your modded game and let it run for as long as you want, do the actions you want to profile, etc. and exit the game (you don't have to save, if you don't want to).
Go back to the terminal where you are running the profiler and kill it with ctrl-C.
profile.log will look something like this:
Code: Select all
1: 89:01:52.39: Configuration changed.
214: 89:01:52.39: Loading Registry
0: 89:01:52.39: Creating Registry
1: 89:01:52.39: Registered job table: 0x00007fd42c003cb0 with name Concreteer and priority 10
2756: 89:01:54.00: Check Tick
0: 89:01:54.00: Checking Udo Schmidt for Concreteer
7903: 89:01:54.00: Worked 16 times
4222: 89:01:56.00: Check Tick
0: 89:01:56.00: Checking Udo Schmidt for Concreteer
7658: 89:01:56.00: Worked 26 times
4064: 89:01:58.00: Check Tick
0: 89:01:58.00: Checking Udo Schmidt for Concreteer
8244: 89:01:58.00: Worked 32 times
This script uses the luasocket third party library, so we can get the time in milliseconds, as the default lua os.time() only gives precision in seconds.
The easiest way to get lua socket in a linux machine is run these commands in your pront:
Code: Select all
sudo apt-get install luarocks
sudo luarocks install luasocket