add profiling debug prints

This commit is contained in:
binarycat 2023-12-17 14:57:06 -05:00
parent 8e30ee4113
commit 00359e7ae8
1 changed files with 17 additions and 3 deletions

View File

@ -195,10 +195,13 @@ end
-- - empty string means legacy MVPS, actual check depends on configuration -- - empty string means legacy MVPS, actual check depends on configuration
-- - "$unknown" is a sentinel for forcing the check -- - "$unknown" is a sentinel for forcing the check
function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sticky, player_name) function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sticky, player_name)
local time_start = minetest.get_us_time()
local nodes = mesecon.mvps_get_stack(pos, movedir, maximum, all_pull_sticky) local nodes = mesecon.mvps_get_stack(pos, movedir, maximum, all_pull_sticky)
local time_get_stack = minetest.get_us_time()
if not nodes then return end if not nodes then return end
local time_protection_check_start = minetest.get_us_time()
local protection_check_set = {} local protection_check_set = {}
if vector.equals(stackdir, movedir) then -- pushing if vector.equals(stackdir, movedir) then -- pushing
add_pos(protection_check_set, pos) add_pos(protection_check_set, pos)
@ -214,7 +217,9 @@ function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sti
if are_protected(protection_check_set, player_name) then if are_protected(protection_check_set, player_name) then
return false, "protected" return false, "protected"
end end
local time_protection_check_end = minetest.get_us_time()
local time_remove_nodes_start = minetest.get_us_time()
-- remove all nodes -- remove all nodes
for _, n in ipairs(nodes) do for _, n in ipairs(nodes) do
n.meta = minetest.get_meta(n.pos):to_table() n.meta = minetest.get_meta(n.pos):to_table()
@ -224,7 +229,7 @@ function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sti
end end
minetest.remove_node(n.pos) minetest.remove_node(n.pos)
end end
local time_remove_nodes_end = minetest.get_us_time()
local oldstack = mesecon.tablecopy(nodes) local oldstack = mesecon.tablecopy(nodes)
-- update mesecons for removed nodes ( has to be done after all nodes have been removed ) -- update mesecons for removed nodes ( has to be done after all nodes have been removed )
@ -232,6 +237,7 @@ function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sti
mesecon.on_dignode(n.pos, n.node) mesecon.on_dignode(n.pos, n.node)
end end
local time_set_nodes_start = minetest.get_us_time()
-- add nodes -- add nodes
for _, n in ipairs(nodes) do for _, n in ipairs(nodes) do
local np = vector.add(n.pos, movedir) local np = vector.add(n.pos, movedir)
@ -248,7 +254,9 @@ function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sti
minetest.get_node_timer(np):set(unpack(n.node_timer)) minetest.get_node_timer(np):set(unpack(n.node_timer))
end end
end end
local time_set_nodes_end = minetest.get_us_time()
local time_moved_nodes_start = minetest.get_us_time()
local moved_nodes = {} local moved_nodes = {}
for i in ipairs(nodes) do for i in ipairs(nodes) do
moved_nodes[i] = {} moved_nodes[i] = {}
@ -259,9 +267,15 @@ function mesecon.mvps_push_or_pull(pos, stackdir, movedir, maximum, all_pull_sti
moved_nodes[i].meta = nodes[i].meta moved_nodes[i].meta = nodes[i].meta
moved_nodes[i].node_timer = nodes[i].node_timer moved_nodes[i].node_timer = nodes[i].node_timer
end end
local time_moved_nodes_end = minetest.get_us_time()
on_mvps_move(moved_nodes) on_mvps_move(moved_nodes)
minetest.debug("get_stack time", time_get_stack - time_start)
minetest.debug("remove_nodes time", time_remove_nodes_end - time_remove_nodes_start)
minetest.debug("set_nodes time", time_set_nodes_end - time_set_nodes_start)
minetest.debug("moved_nodes time", time_moved_nodes_end - time_moved_nodes_start)
minetest.debug("full time", minetest.get_us_time() - time_start)
return true, nodes, oldstack return true, nodes, oldstack
end end