Add profiling instructions for advprofiler

21 files changed, 145 insertions, 14 deletions

diff --git a/advtrains/atc.lua b/advtrains/atc.lua
index fa9f097..32f8ffe 100644
--- a/advtrains/atc.lua
+++ b/advtrains/atc.lua
@@ -298,22 +298,29 @@ eval_conditional = function(command, arrow, speed)
 end
 
 function atc.execute_atc_command(id, train)
+	advtrains.profiler:enter("atc_execute")
+
 	--strip whitespaces
 	local command=string.match(train.atc_command, "^%s*(.*)$")
 	
 	
 	if string.match(command, "^%s*$") then
 		train.atc_command=nil
+		advtrains.profiler:leave("atc_execute")
 		return
 	end
 
 	train.atc_command = eval_conditional(command, train.atc_arrow, train.velocity)
 	
-	if not train.atc_command then return end
+	if not train.atc_command then
+		advtrains.profiler:leave("atc_execute")
+		return
+	end
 	command=string.match(train.atc_command, "^%s*(.*)$")
 	
 	if string.match(command, "^%s*$") then
 		train.atc_command=nil
+		advtrains.profiler:leave("atc_execute")
 		return
 	end
 	
@@ -322,9 +329,8 @@ function atc.execute_atc_command(id, train)
 		if match then
 			local patlen=func(id, train, match)
 			
-			atprint("Executing: "..string.sub(command, 1, patlen))
-			
 			train.atc_command=string.sub(command, patlen+1)
+			advtrains.profiler:leave("atc_execute")
 			if train.atc_delay<=0 and not train.atc_wait_finish then
 				--continue (recursive, cmds shouldn't get too long, and it's a end-recursion.)
 				atc.execute_atc_command(id, train)
@@ -332,6 +338,7 @@ function atc.execute_atc_command(id, train)
 			return
 		end
 	end
+	advtrains.profiler:leave("atc_execute")
 	atwarn(sid(id), attrans("ATC command parse error: Unknown command: @1", command))
 	atc.train_reset_command(train, true)
 end
diff --git a/advtrains/depends.txt b/advtrains/depends.txt
index 1815e54..99e1c47 100644
--- a/advtrains/depends.txt
+++ b/advtrains/depends.txt
@@ -1,3 +1,4 @@
 default
 mesecons?
-digtron?
\ No newline at end of file
+digtron?
+advprofiler?
\ No newline at end of file
diff --git a/advtrains/helpers.lua b/advtrains/helpers.lua
index e04991e..2b24ff7 100644
--- a/advtrains/helpers.lua
+++ b/advtrains/helpers.lua
@@ -307,6 +307,8 @@ function advtrains.get_adjacent_rail(this_posnr, this_conns_p, conn_idx, drives_
 		return nil

 	end

 	

+	advtrains.profiler:enter("get_adjacent_rail")

+	

 	local conn = this_conns[conn_idx]

 	local conn_y = conn.y or 0

 	local adj_pos = advtrains.dirCoordSet(this_pos, conn.c);

@@ -322,10 +324,12 @@ function advtrains.get_adjacent_rail(this_posnr, this_conns_p, conn_idx, drives_
 		conn_y = conn_y + 1

 		nextnode_ok, nextconns, nextrail_y=advtrains.get_rail_info_at(adj_pos, drives_on)

 		if not nextnode_ok then

+			advtrains.profiler:leave("get_adjacent_rail")

 			return nil

 		end

 	end

 	local adj_connid = advtrains.conn_matches_to({c=conn.c, y=conn_y}, nextconns)

+	advtrains.profiler:leave("get_adjacent_rail")

 	if adj_connid then

 		return adj_pos, adj_connid, conn_idx, nextrail_y, nextconns

 	end

diff --git a/advtrains/init.lua b/advtrains/init.lua
index c5604fd..0111b9c 100644
--- a/advtrains/init.lua
+++ b/advtrains/init.lua
@@ -19,6 +19,17 @@ AT_CMAX = 16
 
 advtrains = {trains={}, player_to_train_mapping={}}
 
+-- Profiler boilerplate
+if advprofiler then
+	advtrains.profiler = advprofiler.new_profiler("advtrains")
+else
+	advtrains.profiler = {
+		count=function() end,
+		enter=function() end,
+		leave=function() end,
+	}
+end
+
 --pcall
 local no_action=false
 
diff --git a/advtrains/lzb.lua b/advtrains/lzb.lua
index 6cbf4ab..660efa8 100644
--- a/advtrains/lzb.lua
+++ b/advtrains/lzb.lua
@@ -47,6 +47,7 @@ end
 
 
 local function look_ahead(id, train)
+	advtrains.profiler:enter("lzb_look_ahead")
 	
 	local acc = advtrains.get_acceleration(train, 1)
 	local vel = train.velocity
@@ -80,6 +81,8 @@ local function look_ahead(id, train)
 	
 	lzb.trav = trav
 	
+	advtrains.profiler:leave("lzb_look_ahead")
+	
 end
 
 --[[
@@ -91,6 +94,8 @@ s = v0 * -------  +  - * | ------- |    =  -----------
 ]]
 
 local function apply_control(id, train)
+	advtrains.profiler:enter("lzb_apply_control")
+	
 	local lzb = train.lzb
 	
 	local i = 1
@@ -129,6 +134,7 @@ local function apply_control(id, train)
 				-- Gotcha! Braking...
 				train.ctrl.lzb = 1
 				--train.debug = train.debug .. "BRAKE!!!"
+				advtrains.profiler:leave("lzb_apply_control")
 				return
 			end
 			
@@ -136,17 +142,20 @@ local function apply_control(id, train)
 			if i <= train.index and v0>1 then
 				-- roll control
 				train.ctrl.lzb = 2
+				advtrains.profiler:leave("lzb_apply_control")
 				return
 			end
 			i = advtrains.path_get_index_by_offset(train, i, -params.ZONE_HOLD)
 			if i <= train.index and v0>1 then
 				-- hold speed
 				train.ctrl.lzb = 3
+				advtrains.profiler:leave("lzb_apply_control")
 				return
 			end
 		end
 	end
 	train.ctrl.lzb = nil
+	advtrains.profiler:leave("lzb_apply_control")
 end
 
 local function invalidate(train)
diff --git a/advtrains/nodedb.lua b/advtrains/nodedb.lua
index 37dc3f7..e3f5022 100644
--- a/advtrains/nodedb.lua
+++ b/advtrains/nodedb.lua
@@ -123,6 +123,7 @@ function ndb.get_node(pos)
 	return n
 end
 function ndb.get_node_raw(pos)
+	advtrains.profiler:count("ndb_get_node")
 	local cid=ndbget(pos.x, pos.y, pos.z)
 	if cid then
 		local nodeid = ndb_nodeids[u14b(cid)]
@@ -135,6 +136,7 @@ end
 
 
 function ndb.swap_node(pos, node, no_inval)
+	advtrains.profiler:count("ndb_swap_node")
 	if minetest.get_node_or_nil(pos) then
 		minetest.swap_node(pos, node)
 	end
diff --git a/advtrains/path.lua b/advtrains/path.lua
index 825e59b..1e224e4 100644
--- a/advtrains/path.lua
+++ b/advtrains/path.lua
@@ -156,6 +156,9 @@ function advtrains.path_get(train, index)
 	if index ~= atfloor(index) then
 		error("For train "..train.id..": Called path_get() but index="..index.." is not a round number")
 	end
+	
+	advtrains.profiler:enter("path_get")
+	
 	local pef = train.path_ext_f
 	while index > pef do
 		local pos = train.path[pef]
@@ -224,6 +227,8 @@ function advtrains.path_get(train, index)
 		train.path_req_f = index
 	end
 	
+	advtrains.profiler:leave("path_get")
+	
 	return train.path[index], (index<=train.path_trk_f and index>=train.path_trk_b)
 	
 end
@@ -257,6 +262,8 @@ function advtrains.path_get_adjacent(train, index)
 end
 
 function advtrains.path_get_index_by_offset(train, index, offset)
+	advtrains.profiler:enter("path_get_index_by_offset")
+
 	local off = offset
 	local idx = atfloor(index)
 	-- go down to floor. Calculate required path_dist
@@ -286,6 +293,8 @@ function advtrains.path_get_index_by_offset(train, index, offset)
 	-- we should now be on the floor of the index we actually want.
 	-- give them the rest!
 	
+	advtrains.profiler:leave("path_get_index_by_offset")
+	
 	return idx + (off / train.path_dist[idx])
 end
 
diff --git a/advtrains/trainlogic.lua b/advtrains/trainlogic.lua
index bc24feb..75a1e2e 100644
--- a/advtrains/trainlogic.lua
+++ b/advtrains/trainlogic.lua
@@ -77,7 +77,8 @@ advtrains.mainloop_trainlogic=function(dtime)
 	   to occupation tables (b)
 	5. make trains do other stuff (c)
 	]]--
-	local t=os.clock()
+	
+	advtrains.profiler:enter("train_steps")
 	
 	for k,v in pairs(advtrains.trains) do
 		advtrains.atprint_context_tid=k
@@ -96,12 +97,12 @@ advtrains.mainloop_trainlogic=function(dtime)
 		advtrains.train_step_c(k, v, dtime)
 	end
 	
+	advtrains.profiler:leave("train_steps")
+	
 	advtrains.lock_path_inval = false
 	
 	advtrains.atprint_context_tid=nil
 	
-	atprintbm("trainsteps", t)
-	endstep()
 end
 
 function advtrains.tp_player_to_train(player)
@@ -239,6 +240,8 @@ function advtrains.train_ensure_init(id, train)
 		return nil
 	end
 	
+	advtrains.profiler:enter("train_ensure_init")
+	
 	train.dirty = true
 	if train.no_step then return nil end
 
@@ -258,6 +261,7 @@ function advtrains.train_ensure_init(id, train)
 		if not train.last_pos then
 			atlog("Train",id,": Restoring path failed, no last_pos set! Train will be disabled. You can try to fix the issue in the save file.")
 			train.no_step = true
+			advtrains.profiler:leave("train_ensure_init")
 			return nil
 		end
 		if not train.last_connid then
@@ -280,12 +284,14 @@ function advtrains.train_ensure_init(id, train)
 		if result==false then
 			atlog("Train",id,": Restoring path failed, node at",train.last_pos,"is gone! Train will be disabled. You can try to place a rail at this position and restart the server.")
 			train.no_step = true
+			advtrains.profiler:leave("train_ensure_init")
 			return nil
 		elseif result==nil then
 			if not train.wait_for_path then
 				atlog("Train",id,": Can't initialize: Waiting for the (yet unloaded) node at",train.last_pos," to be loaded.")
 			end
 			train.wait_for_path = true
+			advtrains.profiler:leave("train_ensure_init")
 			return false
 		end
 		-- by now, we should have a working initial path
@@ -301,11 +307,15 @@ function advtrains.train_ensure_init(id, train)
 	end
 	
 	train.dirty = false -- TODO einbauen!
+	
+	advtrains.profiler:leave("train_ensure_init")
+	
 	return true
 end
 
 function advtrains.train_step_b(id, train, dtime)
 	if train.no_step or train.wait_for_path or not train.path then return end
+	advtrains.profiler:enter("train_step_b")
 	
 	-- in this code, we check variables such as path_trk_? and path_dist. We need to ensure that the path is known for the whole 'Train' zone
 	advtrains.path_get(train, atfloor(train.index + 2))
@@ -483,12 +493,16 @@ function advtrains.train_step_b(id, train, dtime)
 	train.index=train.index+distance
 	
 	recalc_end_index(train)
+	
+	advtrains.profiler:leave("train_step_b")
 
 end
 
 function advtrains.train_step_c(id, train, dtime)
 	if train.no_step or train.wait_for_path or not train.path then return end
 	
+	advtrains.profiler:enter("train_step_c")
+	
 	-- all location/extent-critical actions have been done.
 	-- calculate the new occupation window
 	run_callbacks_update(id, train)
@@ -583,6 +597,7 @@ function advtrains.train_step_c(id, train, dtime)
 			end
 		end
 	end
+	advtrains.profiler:leave("train_step_c")
 end
 
 -- Default occupation callbacks for node callbacks
@@ -1122,11 +1137,13 @@ function advtrains.invalidate_all_paths(pos)
 end
 function advtrains.invalidate_path(id)
 	--atdebug("Path invalidate:",id)
+	advtrains.profiler:enter("invalidate_path")
 	local v=advtrains.trains[id]
 	if not v then return end
 	advtrains.path_invalidate(v)
 	advtrains.couple_invalidate(v)
 	v.dirty = true
+	advtrains.profiler:leave("invalidate_path")
 end
 
 --not blocking trains group
diff --git a/advtrains/wagons.lua b/advtrains/wagons.lua
index 040c1e4..ffe5180 100644
--- a/advtrains/wagons.lua
+++ b/advtrains/wagons.lua
@@ -242,12 +242,14 @@ function wagon:on_step(dtime)
 	return advtrains.pcall(function()

 		if not self:ensure_init() then return end

 		

-		local t=os.clock()

+		advtrains.profiler:enter("wagon_step")

+		

 		local pos = self.object:getpos()

 		local data = advtrains.wagons[self.id]

 		

 		if not pos then

 			--atdebug("["..self.id.."][fatal] missing position (object:getpos() returned nil)")

+			advtrains.profiler:leave("wagon_step")

 			return

 		end

 		

@@ -375,9 +377,11 @@ function wagon:on_step(dtime)
 		if not train.path or train.no_step then

 			self.object:setvelocity({x=0, y=0, z=0})

 			self.object:setacceleration({x=0, y=0, z=0})

+			advtrains.profiler:leave("wagon_step")

 			return

 		end

 		if not data.pos_in_train then

+			advtrains.profiler:leave("wagon_step")

 			return

 		end

 		

@@ -538,7 +542,9 @@ function wagon:on_step(dtime)
 		self.old_velocity = train.velocity

 		self.old_acceleration_vector=accelerationvec

 		self.old_yaw=yaw

-		atprintbm("wagon step", t)

+		

+		advtrains.profiler:leave("wagon_step")

+		

 	end)

 end

 

diff --git a/advtrains_interlocking/depends.txt b/advtrains_interlocking/depends.txt
index 6f00bf6..960989c 100644
--- a/advtrains_interlocking/depends.txt
+++ b/advtrains_interlocking/depends.txt
@@ -1 +1,2 @@
-advtrains
\ No newline at end of file
+advtrains
+advprofiler?
\ No newline at end of file
diff --git a/advtrains_interlocking/init.lua b/advtrains_interlocking/init.lua
index a2f5882..0cdea8e 100644
--- a/advtrains_interlocking/init.lua
+++ b/advtrains_interlocking/init.lua
@@ -9,6 +9,16 @@ function advtrains.interlocking.sigd_equal(sigd, cmp)
 	return vector.equals(sigd.p, cmp.p) and sigd.s==cmp.s
 end
 
+-- Profiler boilerplate
+if advprofiler then
+	advtrains.interlocking.profiler = advprofiler.new_profiler("advtrains_interlocking")
+else
+	advtrains.interlocking.profiler = {
+		count=function() end,
+		enter=function() end,
+		leave=function() end,
+	}
+end
 
 local modpath = minetest.get_modpath(minetest.get_current_modname()) .. DIR_DELIM
 
diff --git a/advtrains_interlocking/routesetting.lua b/advtrains_interlocking/routesetting.lua
index 7c4d14c..7b52902 100644
--- a/advtrains_interlocking/routesetting.lua
+++ b/advtrains_interlocking/routesetting.lua
@@ -224,6 +224,7 @@ end
 -- note that this does not clear the routesetting status from the entry signal,
 -- only from the ts's
 function ilrs.cancel_route_from(sigd)
+	advtrains.interlocking.profiler:enter("cancel_route_from")
 	-- we start at the tc designated by signal
 	local c_sigd = sigd
 	local c_tcbs, c_ts_id, c_ts, c_rseg, c_lckp
@@ -232,6 +233,7 @@ function ilrs.cancel_route_from(sigd)
 		c_tcbs = ildb.get_tcbs(c_sigd)
 		if not c_tcbs then
 			atwarn("Failed to cancel route, no TCBS at",c_sigd)
+			advtrains.interlocking.profiler:leave("cancel_route_from")
 			return false
 		end
 		
@@ -248,6 +250,7 @@ function ilrs.cancel_route_from(sigd)
 		c_ts_id = c_tcbs.ts_id
 		if not c_tcbs then
 			atwarn("Failed to cancel route, end of interlocking at",c_sigd)
+			advtrains.interlocking.profiler:leave("cancel_route_from")
 			return false
 		end
 		c_ts = ildb.get_ts(c_ts_id)
@@ -256,6 +259,7 @@ function ilrs.cancel_route_from(sigd)
 			or not c_ts.route
 			or not sigd_equal(c_ts.route.entry, c_sigd) then
 			--atdebug("cancel_route_from: abort (eoi/no route):")
+			advtrains.interlocking.profiler:leave("cancel_route_from")
 			return false
 		end
 		
@@ -271,6 +275,7 @@ function ilrs.cancel_route_from(sigd)
 		minetest.after(0, advtrains.interlocking.route.update_waiting, "ts", c_ts_id)
 	end
 	--atdebug("cancel_route_from: done (no final sigd)")
+	advtrains.interlocking.profiler:leave("cancel_route_from")
 	return true
 end
 
@@ -303,7 +308,9 @@ function ilrs.update_route(sigd, tcbs, newrte, cancel)
 		end
 		if newrte then tcbs.routeset = newrte end
 		--atdebug("Setting:",tcbs.routeset)
+		advtrains.interlocking.profiler:enter("set_route")
 		local succ, rsn, cbts, cblk = ilrs.set_route(sigd, tcbs.routes[tcbs.routeset])
+		advtrains.interlocking.profiler:leave("set_route")
 		if not succ then
 			tcbs.route_rsn = rsn
 			--atdebug("Routesetting failed:",rsn)
diff --git a/advtrains_interlocking/train_sections.lua b/advtrains_interlocking/train_sections.lua
index 757f36a..5e5945a 100644
--- a/advtrains_interlocking/train_sections.lua
+++ b/advtrains_interlocking/train_sections.lua
@@ -62,6 +62,7 @@ local function itkremove(tbl, ikey, com)
 end
 
 local function setsection(tid, train, ts_id, ts, sigd)
+	advtrains.interlocking.profiler:enter("train_setsection")
 	-- train
 	if not train.il_sections then train.il_sections = {} end
 	if not itkexist(train.il_sections, "ts_id", ts_id) then
@@ -106,9 +107,11 @@ local function setsection(tid, train, ts_id, ts, sigd)
 	if tcbs.signal then
 		advtrains.interlocking.route.update_route(sigd, tcbs)
 	end
+	advtrains.interlocking.profiler:leave("train_setsection")
 end
 
 local function freesection(tid, train, ts_id, ts)
+	advtrains.interlocking.profiler:enter("train_freesection")
 	-- train
 	if not train.il_sections then train.il_sections = {} end
 	itkremove(train.il_sections, "ts_id", ts_id)
@@ -129,6 +132,7 @@ local function freesection(tid, train, ts_id, ts)
 	-- This must be delayed, because this code is executed in-between a train step
 	-- TODO use luaautomation timers?
 	minetest.after(0, advtrains.interlocking.route.update_waiting, "ts", ts_id)
+	advtrains.interlocking.profiler:leave("train_freesection")
 end
 
 
diff --git a/advtrains_line_automation/depends.txt b/advtrains_line_automation/depends.txt
index 53500ee..0f69091 100644
--- a/advtrains_line_automation/depends.txt
+++ b/advtrains_line_automation/depends.txt
@@ -1,2 +1,3 @@
 advtrains_interlocking
-advtrains_train_track
\ No newline at end of file
+advtrains_train_track
+advprofiler?
\ No newline at end of file
diff --git a/advtrains_line_automation/init.lua b/advtrains_line_automation/init.lua
index 7b758bc..2275f49 100644
--- a/advtrains_line_automation/init.lua
+++ b/advtrains_line_automation/init.lua
@@ -15,6 +15,16 @@ advtrains.lines = {
 	stops = {},
 }
 
+if advprofiler then
+	advtrains.lines.profiler = advprofiler.new_profiler("advtrains_lines")
+else
+	advtrains.lines.profiler = {
+		count=function() end,
+		enter=function() end,
+		leave=function() end,
+	}
+end
+
 
 local modpath = minetest.get_modpath(minetest.get_current_modname()) .. DIR_DELIM
 
diff --git a/advtrains_line_automation/scheduler.lua b/advtrains_line_automation/scheduler.lua
index 8afaa55..27cb528 100644
--- a/advtrains_line_automation/scheduler.lua
+++ b/advtrains_line_automation/scheduler.lua
@@ -48,6 +48,7 @@ function sched.save()
 end
 
 function sched.run()
+	advtrains.lines.profiler:enter("scheduler_run")
 	local ctime = ln.rwt.get_time()
 	local cnt = 0
 	local ucn, elem
@@ -57,7 +58,9 @@ function sched.run()
 			table.remove(queue, 1)
 			if callbacks[elem.e] then
 				-- run it
+				advtrains.lines.profiler:enter("scheduler_run_single_schedule")
 				callbacks[elem.e](elem.d)
+				advtrains.lines.profiler:leave("scheduler_run_single_schedule")
 			else
 				atwarn("[lines][scheduler] No callback to handle schedule",elem)
 			end
@@ -70,6 +73,7 @@ function sched.run()
 			break
 		end
 	end
+	advtrains.lines.profiler:leave("scheduler_run")
 end
 
 -- Enqueue a new scheduled item to be executed at "rwtime"
@@ -79,6 +83,7 @@ end
 --    used to prevent expotentially growing "scheduler bombs"
 -- unitlim: Custom override for UNITS_THRESH (see there)
 function sched.enqueue(rwtime, handler, evtdata, unitid, unitlim)
+	advtrains.lines.profiler:enter("scheduler_enqueue")
 	local qtime = ln.rwt.to_secs(rwtime)
 	assert(type(handler)=="string")
 	assert(type(unitid)=="string")
@@ -91,6 +96,7 @@ function sched.enqueue(rwtime, handler, evtdata, unitid, unitlim)
 	local ulim=(unitlim or UNITS_THRESH)
 	if ucn >= ulim then
 		atlog("[lines][scheduler] discarding enqueue for",handler,"(limit",ulim,") because unit",unitid,"has already",ucn,"schedules enqueued")
+		advtrains.lines.profiler:leave("scheduler_enqueue")
 		return false
 	end
 	
@@ -104,6 +110,7 @@ function sched.enqueue(rwtime, handler, evtdata, unitid, unitlim)
 					u=unitid,
 				})
 			units_cnt[unitid] = ucn + 1
+			advtrains.lines.profiler:leave("scheduler_enqueue")
 			return true
 		end
 		cnt = cnt+1
diff --git a/advtrains_luaautomation/active_common.lua b/advtrains_luaautomation/active_common.lua
index c17c6e9..4337122 100644
--- a/advtrains_luaautomation/active_common.lua
+++ b/advtrains_luaautomation/active_common.lua
@@ -114,6 +114,8 @@ function ac.run_in_env(pos, evtdata, customfct_p)
 		return false
 	end
 	
+	atlatc.profiler:enter("ac_run_in_env")
+	
 	local customfct=customfct_p or {}
 	-- add interrupt function
 	customfct.interrupt=function(t, imesg)
@@ -152,6 +154,7 @@ function ac.run_in_env(pos, evtdata, customfct_p)
 	if meta then
 		meta:set_string("formspec", ac.getform(pos, meta))
 	end
+	atlatc.profiler:leave("ac_run_in_env")
 end
 
 function ac.on_digiline_receive(pos, node, channel, msg)
diff --git a/advtrains_luaautomation/depends.txt b/advtrains_luaautomation/depends.txt
index d5523e1..ced5087 100644
--- a/advtrains_luaautomation/depends.txt
+++ b/advtrains_luaautomation/depends.txt
@@ -1,4 +1,5 @@
 advtrains
 advtrains_interlocking?
 advtrains_line_automation?
-mesecons_switch?
\ No newline at end of file
+mesecons_switch?
+advprofiler?
\ No newline at end of file
diff --git a/advtrains_luaautomation/environment.lua b/advtrains_luaautomation/environment.lua
index 3e7787b..5276a99 100644
--- a/advtrains_luaautomation/environment.lua
+++ b/advtrains_luaautomation/environment.lua
@@ -265,6 +265,7 @@ local proxy_env={}
 
 -- returns: true, fenv if successful; nil, error if error 
 function env_proto:execute_code(localenv, code, evtdata, customfct)
+	atlatc.profiler:enter("env_execute_code")
 	local metatbl ={
 		__index = function(t, i)
 			if i=="S" then
@@ -291,6 +292,7 @@ function env_proto:execute_code(localenv, code, evtdata, customfct)
 	setmetatable(proxy_env, metatbl)
 	local fun, err=loadstring(code)
 	if not fun then
+		atlatc.profiler:leave("env_execute_code")
 		return false, err
 	end
 	
@@ -299,10 +301,12 @@ function env_proto:execute_code(localenv, code, evtdata, customfct)
 	if succ then
 		data=localenv
 	end
+	atlatc.profiler:leave("env_execute_code")
 	return succ, data
 end
 
 function env_proto:run_initcode()
+	atlatc.profiler:enter("env_run_initcode")
 	if self.init_code and self.init_code~="" then
 		local old_fdata=self.fdata
 		self.fdata = {}
@@ -317,6 +321,7 @@ function env_proto:run_initcode()
 			end
 		end
 	end
+	atlatc.profiler:leave("env_run_initcode")
 end
 function env_proto:run_stepcode()
 	if self.step_code and self.step_code~="" then
diff --git a/advtrains_luaautomation/init.lua b/advtrains_luaautomation/init.lua
index 75cf30a..643823b 100644
--- a/advtrains_luaautomation/init.lua
+++ b/advtrains_luaautomation/init.lua
@@ -9,11 +9,23 @@ else
     atltrans = function(s,a,...)a={a,...}return s:gsub("@(%d+)",function(n)return a[tonumber(n)]end)end
 end
 
+atlatc = { envs = {}}
+
+-- Profiler boilerplate
+if advprofiler then
+	atlatc.profiler = advprofiler.new_profiler("atlatc")
+else
+	atlatc.profiler = {
+		count=function() end,
+		enter=function() end,
+		leave=function() end,
+	}
+end
+
+
 --Privilege
 --Only trusted players should be enabled to build stuff which can break the server.
 
-atlatc = { envs = {}}
-
 minetest.register_privilege("atlatc", { description = "Player can place and modify LUA ATC components. Grant with care! Allows to execute bad LUA code.", give_to_singleplayer = false, default= false })
 
 --assertt helper. error if a variable is not of a type
diff --git a/advtrains_luaautomation/interrupt.lua b/advtrains_luaautomation/interrupt.lua
index 525c3b4..3f7aba4 100644
--- a/advtrains_luaautomation/interrupt.lua
+++ b/advtrains_luaautomation/interrupt.lua
@@ -22,6 +22,7 @@ function iq.add(t, pos, evtdata)
 end
 
 function iq.mainloop(dtime)
+	atlatc.profiler:enter("iq_mainloop")
 	timer=timer + math.min(dtime, 0.2)
 	for i=1,#queue do
 		local qe=queue[i]
@@ -33,7 +34,9 @@ function iq.mainloop(dtime)
 			local node=advtrains.ndb.get_node(pos)
 			local ndef=minetest.registered_nodes[node.name]
 			if ndef and ndef.luaautomation and ndef.luaautomation.fire_event then
+				atlatc.profiler:enter("iq_run_single_event")
 				ndef.luaautomation.fire_event(pos, evtdata)
+				atlatc.profiler:leave("iq_run_single_event")
 			else
 				atwarn("[atlatc][interrupt] Couldn't run event",evtdata.type,"on",pos,", something wrong with the node",node)
 			end
@@ -41,6 +44,7 @@ function iq.mainloop(dtime)
 			i=i-1
 		end
 	end
+	atlatc.profiler:leave("iq_mainloop")
 end