Add profiling instructions for advprofiler

9 files changed, 75 insertions, 9 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