From 5965e4a9deac0786c73935be17f1cfbea7dcf714 Mon Sep 17 00:00:00 2001 From: sapier Date: Wed, 13 Aug 2014 22:32:32 +0200 Subject: [PATCH] Fix large steps caused by uninterruptable spawn seed initialization within activation Update version number to 0.0.8 --- api.lua | 2 +- init.lua | 6 +-- internal.lua | 90 ++++++++++++++++++++++++++++++++++++++------- spawn_seed.lua | 52 +++++++++++++++++++++----- spawndef_checks.lua | 10 ++--- testmod/init.lua | 24 ++++++------ 6 files changed, 140 insertions(+), 44 deletions(-) diff --git a/api.lua b/api.lua index d2f5dfe..a9f6d5d 100644 --- a/api.lua +++ b/api.lua @@ -25,7 +25,7 @@ function adv_spawning.register(spawner_name,spawning_def) end adv_spawning.spawner_definitions[spawner_name] = spawning_def - print("ADV_SPAWNING: registering spawner \"" .. spawner_name .. "\"") + adv_spawning.dbg_log(0, "registering spawner \"" .. spawner_name .. "\"") return true else return false diff --git a/init.lua b/init.lua index 457fdd0..e136f82 100644 --- a/init.lua +++ b/init.lua @@ -8,10 +8,10 @@ -- ------------------------------------------------------------------------------- -local version = "0.0.7" +local version = "0.0.8" if adv_spawning ~= nil then - core.log("error","MOD: adv_spawning requires adv_spawning variable to be available") + core.log("error", "MOD: adv_spawning requires adv_spawning variable to be available") end -------------------------------------------------------------------------------- @@ -31,4 +31,4 @@ dofile (adv_modpath .. "/spawn_seed.lua") adv_spawning.initialize() -core.log("action","Advanced spawning mod version " .. version .. " loaded") +core.log("action", "Advanced spawning mod version " .. version .. " loaded") diff --git a/internal.lua b/internal.lua index 2406f0e..5af8b0d 100644 --- a/internal.lua +++ b/internal.lua @@ -63,6 +63,8 @@ function adv_spawning.initialize() adv_spawning.spawner_y_offset = 20 adv_spawning.max_spawning_frequency_hz = 5 adv_spawning.max_mapgen_tries_per_step = 3 + adv_spawning.spawner_warned = {} + adv_spawning.loglevel = 0 adv_spawning.active_range = minetest.setting_get("active_block_range") @@ -154,7 +156,9 @@ function adv_spawning.mapgen_hook(minp,maxp,blockseed) if x > minp.x and y > minp.y and z > minp.z then - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "mapgen_hook did use way too much time 1") + end minetest.add_entity({x=x,y=y,z=z},"adv_spawning:spawn_seed") adv_spawning.quota_enter(true) adv_spawning.log("info", "adv_spawning: adding spawner entity at " @@ -167,7 +171,9 @@ function adv_spawning.mapgen_hook(minp,maxp,blockseed) end adv_spawning.queue_mapgen_jobs(minp,maxp) - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "mapgen_hook did use way too much time 2") + end else assert("Mapgen hook could not be executed" == nil) end @@ -221,7 +227,9 @@ function adv_spawning.global_onstep(dtime) if adv_spawning.quota_enter() then adv_spawning.handle_mapgen_spawning() - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "globalstep took to long") + end end end @@ -233,25 +241,34 @@ end function adv_spawning.quota_enter(force) --ONLY enable this one if you're quite sure there aren't bugs in --assert(adv_spawning.quota_starttime == nil) - + local retval = false + if adv_spawning.quota_left <= 0 then + if force == true then - print("Quota: task is too important to skip do it anyway," .. - " quota already passed by: " .. - string.format("%.2f ms",adv_spawning.quota_left)) - else - if adv_spawning.quota_left * -2 > adv_spawning.quota_reload then - print("Quota: no time left: " .. + if adv_spawning.quota_left < -10 then + adv_spawning.dbg_log(1, "Quota: task is too important to skip do it anyway," .. + " quota already passed by: " .. + string.format("%.2f ms",adv_spawning.quota_left)) + end + retval = true + else + if adv_spawning.quota_left * -2 > adv_spawning.quota_reload then + adv_spawning.dbg_log(1, "Quota: no time left: " .. string.format("%.2f ms",adv_spawning.quota_left)) end - return false end + else + retval = true end -- print("+++++++++++++++++Quota enter+++++++++++++++++++++") -- print(debug.traceback()) -- print("+++++++++++++++++++++++++++++++++++++++++++++++++") - adv_spawning.quota_starttime = adv_spawning.gettime() - return true + if retval then + adv_spawning.quota_starttime = adv_spawning.gettime() + end + + return retval end -------------------------------------------------------------------------------- @@ -301,8 +318,15 @@ function adv_spawning.quota_leave() else adv_spawning.quota_left = adv_spawning.quota_left - time_passed end + + if (adv_spawning.quota_left < -adv_spawning.quota_reload) then + adv_spawning.dbg_log(1, "excessive overtime, quota remaining: " .. adv_spawning.quota_left) + return false + end + adv_spawning.quota_starttime = nil --print("-----------------Quota leave----------------------") + return true end -------------------------------------------------------------------------------- @@ -1296,7 +1320,6 @@ function adv_spawning.check_active_block(pos) end end - return false end @@ -1338,11 +1361,16 @@ function adv_spawning.handle_mapgen_spawning() tries < adv_spawning.max_mapgen_tries_per_step and (not adv_spawning.time_over(10)) )do + local single_spawn_check = adv_spawning.gettime() + local retval,permanent_error = adv_spawning.handlespawner(toprocess.spawner, {x=0,y=0,z=0}, toprocess.minp, toprocess.maxp, true) + + local delta = adv_spawning.gettime() - adv_spawning.quota_starttime + if retval then toprocess.spawntotal = toprocess.spawntotal -1 end @@ -1421,3 +1449,37 @@ function adv_spawning.dump_area(minp,maxp) print("") end end + +-------------------------------------------------------------------------------- +-- @function [parent=#adv_spawning] check_time +-- @param starttime time since when to check +-- @param checkid name of this check +-- +-- @return current time for next check +-------------------------------------------------------------------------------- +function adv_spawning.check_time(starttime, checkid) + local currenttime = adv_spawning.gettime() + local delta = currenttime - starttime + + if (delta > adv_spawning.quota_reload) then + if adv_spawning.spawner_warned[checkid] ~= true then + adv_spawning.dbg_log(1, "spawner " .. checkid .. + "\n\texceeded more then full reload time on init (" .. delta .. " ms)." .. + "\n\tFix it as it will cause major lag on mapgen!") + adv_spawning.spawner_warned[checkid] = true + end + end + + return currenttime +end + +-------------------------------------------------------------------------------- +-- @function [parent=#adv_spawning] dbg_log +-- @param loglevel level print it +-- @param message message to print +-------------------------------------------------------------------------------- +function adv_spawning.dbg_log(loglevel, message) + if (adv_spawning.loglevel >= loglevel ) then + core.log("action", "ADV_SPAWNING: " .. message) + end +end \ No newline at end of file diff --git a/spawn_seed.lua b/spawn_seed.lua index 9c12c00..cd79ac4 100644 --- a/spawn_seed.lua +++ b/spawn_seed.lua @@ -25,6 +25,11 @@ function adv_spawning.seed_step(self,dtime) if (self.mydtime < 1/adv_spawning.max_spawning_frequency_hz) then return end + + --check if we did finish initialization of our spawner list by now + if not adv_spawning.seed_scan_for_applyable_spawners(self) then + return + end if adv_spawning.quota_enter() then self.pending_spawners = {} @@ -39,12 +44,14 @@ function adv_spawning.seed_step(self,dtime) end local per_step_count = 0 + local key = nil while #self.pending_spawners > 0 and - per_step_count < adv_spawning.max_spawns_per_spawner do + per_step_count < adv_spawning.max_spawns_per_spawner and + adv_spawning.time_over(10) do local rand_spawner = math.random(1,#self.pending_spawners) - local key = self.pending_spawners[rand_spawner] + key = self.pending_spawners[rand_spawner] local tries = 1 @@ -63,7 +70,9 @@ function adv_spawning.seed_step(self,dtime) end --check quota again - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "spawner " .. key .. " did use way too much time") + end if not adv_spawning.quota_enter() then return end @@ -76,9 +85,11 @@ function adv_spawning.seed_step(self,dtime) end -- if (#self.pending_spawners > 0) then --- print("Handled " .. per_step_count .. " spawners, spawners left: " .. #self.pending_spawners) +-- adv_spawning.dbg_log(3, "Handled " .. per_step_count .. " spawners, spawners left: " .. #self.pending_spawners) -- end - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "spawner " .. key .. " did use way too much time") + end end end @@ -103,13 +114,14 @@ function adv_spawning.seed_activate(self) end adv_spawning.seed_validate_spawndata(self) - - adv_spawning.seed_scan_for_applyable_spawners(self) - + self.pending_spawners = {} + self.initialized_spawners = 0 self.activated = true - adv_spawning.quota_leave() + if not adv_spawning.quota_leave() then + adv_spawning.dbg_log(2, "on activate " .. self.name .. " did use way too much time") + end end end @@ -208,9 +220,27 @@ end -- @return true/false -------------------------------------------------------------------------------- function adv_spawning.seed_scan_for_applyable_spawners(self) + + if self.initialized_spawners >= #adv_spawning.spawner_definitions then + return true + end + + local runindex = 0 local pos = self.object:getpos() for key,value in pairs(adv_spawning.spawner_definitions) do + if not adv_spawning.quota_enter() then + return false + end + local starttime = adv_spawning.gettime() local continue = false + + if runindex >= self.initialized_spawners then + self.initialized_spawners = self.initialized_spawners + 1 + else + continue = true + end + + runindex = runindex + 1 --check if cyclic spawning is enabled if not continue and @@ -234,6 +264,7 @@ function adv_spawning.seed_scan_for_applyable_spawners(self) continue = true end end + starttime = adv_spawning.check_time(starttime, key .. " at spawn range check") --check for presence of environment if not continue then @@ -246,6 +277,7 @@ function adv_spawning.seed_scan_for_applyable_spawners(self) continue = false end end + starttime = adv_spawning.check_time(starttime, key .. " at environment check") if not continue then self.spawning_data[key] = value.spawn_interval * math.random() @@ -253,4 +285,6 @@ function adv_spawning.seed_scan_for_applyable_spawners(self) self.spawning_data[key] = nil end end + + return self.initialized_spawners == #adv_spawning.spawner_definitions end \ No newline at end of file diff --git a/spawndef_checks.lua b/spawndef_checks.lua index 9d684b5..9070f71 100644 --- a/spawndef_checks.lua +++ b/spawndef_checks.lua @@ -19,13 +19,13 @@ function adv_spawning.verify_check_entities_around(entities_around) for i=1,#entities_around,1 do if type(entities_around[i].distance) ~= "number" then - print("ADV_SPAWNING: missing distance in entities_around definition") + adv_spawning.dbg_log(0, "missing distance in entities_around definition") return false end if entities_around[i].type ~= "MIN" and entities_around[i].type ~= "MAX" then - print("ADV_SPAWNING: invalid type \"" .. + adv_spawning.dbg_log(0, "invalid type \"" .. dump(entities_around[i].type) .. "\" in entities_around definition") return false @@ -46,13 +46,13 @@ function adv_spawning.verify_check_nodes_around(nodes_around) for i=1,#nodes_around,1 do if type(nodes_around[i].distance) ~= "number" then - print("ADV_SPAWNING: missing distance in entities_around definition") + adv_spawning.dbg_log(0, "missing distance in entities_around definition") return false end if nodes_around[i].type ~= "MIN" and nodes_around[i].type ~= "MAX" then - print("ADV_SPAWNING: invalid type \"" .. + adv_spawning.dbg_log(0, "invalid type \"" .. dump(nodes_around[i].type) .. "\" in entities_around definition") return false @@ -60,7 +60,7 @@ function adv_spawning.verify_check_nodes_around(nodes_around) if nodes_around[i].name == nil or type(nodes_around[i].name) ~= "table" then - print("ADV_SPAWNING: invalid type of name \"" .. + adv_spawning.dbg_log(0, "invalid type of name \"" .. type(nodes_around[i].name) .. "\"" .. " Data: " .. dump(nodes_around[i].name) .. " in nodes_around definition") diff --git a/testmod/init.lua b/testmod/init.lua index d33af74..bd4aea5 100644 --- a/testmod/init.lua +++ b/testmod/init.lua @@ -133,22 +133,22 @@ adv_spawning.register("some_bogus_entity_4", }) -minetest.register_chatcommand("stats", +minetest.register_chatcommand("adv_stats", { params = "", - description = "show advanced spawning satistics" , + description = "print advanced spawning satistics to logfile" , func = function() local stats = adv_spawning.get_statistics() - print("Adv. Spawning stats:") - print("----------------------------------------") - print("Spawners added: " .. stats.session.spawners_created) - print("Spawnees added: " .. stats.session.entities_created) - print("") - print("Longest step: " .. stats.step.max) - print("") - print("Current load: " .. stats.load.cur) - print("Average load: " .. stats.load.avg) - print("Maximum load: " .. stats.load.max) + adv_spawning.dbg_log(0, "Adv. Spawning stats:") + adv_spawning.dbg_log(0, "----------------------------------------") + adv_spawning.dbg_log(0, "Spawners added: " .. stats.session.spawners_created) + adv_spawning.dbg_log(0, "Spawnees added: " .. stats.session.entities_created) + adv_spawning.dbg_log(0, "") + adv_spawning.dbg_log(0, "Longest step: " .. stats.step.max) + adv_spawning.dbg_log(0, "") + adv_spawning.dbg_log(0, "Current load: " .. stats.load.cur) + adv_spawning.dbg_log(0, "Average load: " .. stats.load.avg) + adv_spawning.dbg_log(0, "Maximum load: " .. stats.load.max) end }) \ No newline at end of file