Page 2 of 2

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Mon Jul 16, 2018 10:20
by bosapara
I had similar warning, found how to solve from this topic
About 3 days i seen warning every 2 secs: active block modifiers took
Problem was in tree mod, that used abm. Mod deleted, now nothing warnings.

Code: Select all

minetest.register_abm({
   nodenames = {"mochathicket:beech_sapling"},
   interval = 10,
   chance = 50,
   action = function(pos, node)
      local is_soil = minetest.registered_nodes[minetest.get_node({x=pos.x, y=pos.y-1, z=pos.z}).name].groups.soil
      if is_soil == nil or is_soil == 0 then return end
      print("A mocha blossom sapling grows into a tree at "..minetest.pos_to_string(pos))
      local vm = minetest.get_voxel_manip()
      local minp, maxp = vm:read_from_map({x=pos.x-16, y=pos.y, z=pos.z-16}, {x=pos.x+16, y=pos.y+16, z=pos.z+16})
      local a = VoxelArea:new{MinEdge=minp, MaxEdge=maxp}
      local data = vm:get_data()
      default.grow_tree(data, a, pos, math.random(1, 4) == 1, math.random(1,100000))
      vm:set_data(data)
      vm:write_to_map(data)
      vm:update_map()
   end
})

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Sat Sep 22, 2018 21:30
by Starbeamrainbowlabs
Yeah, I faced similar sorts of issues. Disabling the spawning of roots from the vines mod in particular solved the problem for me - the /profiler command was very helpful in tracking that one down.

If you face performance issues when doing map generation, adding more emerge threads might help. It's the num_emerge_threads setting in minetest.conf - I've set it to 4 - the number of CPU cores I have.

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Wed Feb 27, 2019 02:27
by Festus1965
I am definitely not happy with the (not) result of this discussion yet:

* Where is the Warning with more than 200ms generated ? code base
** what IS happening if abm uses more then 200 ms, just continue or stopped,
** when can the warning time be changed, say 300ms, or would it crash some thing else ?

So "active block modifiers" took longer than,
* does it mean all abm together ? or one of them ?

How to detect the right mod part with the abm as lag-check shows
* technic (7) - what machine is that, always same one or depending on loading ?
* or also moretrees (13) etc.

a abm is register like:

Code: Select all

minetest.register_abm({
   nodenames = {"mochathicket:beech_sapling"},
   interval = 10,
   chance = 50,
....
So here every 10 seconds it will run, but only every 50th time with success of doing it.
Wouldn't it be less cpu using if
* interval = 20, and change then 25, ... or
* interval = 100, and change = 5 ... as
as if I calculate right, would happen same often in the view of a 24hour lasting average, but with the advantage, if abm activates it has more sure some to do

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Wed Feb 27, 2019 08:31
by wziard
Festus1965 wrote: * Where is the Warning with more than 200ms generated ? code base
Ever heard of grep ?

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Wed Feb 27, 2019 09:09
by Linuxdirk

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Wed Feb 27, 2019 09:47
by Festus1965
wziard wrote:Ever heard of grep ?
I searched the codebase on github for "active block modifiers took" without a result, and that counts, not what I have on my SSD ...

It seams to be like a guessing game here ... but found the lines , so as from 1341

Code: Select all

if (m_active_block_modifier_interval.step(dtime, m_cache_abm_interval))
		do { // breakable
			if (m_active_block_interval_overload_skip > 0) {
				ScopeProfiler sp(g_profiler, "SEnv: ABM overload skips");
				m_active_block_interval_overload_skip--;
				break;
}
...
and from 1371

Code: Select all

u32 time_ms = timer.stop(true);
			u32 max_time_ms = 200;
			if (time_ms > max_time_ms) {
				warningstream<<"active block modifiers took "
					<<time_ms<<"ms (longer than "
					<<max_time_ms<<"ms)"<<std::endl;
				m_active_block_interval_overload_skip = (time_ms / max_time_ms) + 1;
}
I think to understand, that the set 200 can be changed,
that it bigger than 200, report AND set m_active_block_interval_overload_skip ... +1,
what results in line 1343 a positive and BREAK;
so answer would be, ABMs are finished at 200 even ready or not ...

but as the report shows "time_ms" needed time, it seams more to be it did all the ABMs ready, and just warned that took longer without a cut of, or cutted of after the last ABM reached the 200 border.

But for what is that warning then good ... when I need to code again to get an answer what ABMs used most time. Here we are back at lagcheck and how to find the right part in fe. technic number shown in the () ...

(If that game is meant only for coders no problem ...one problem less for me then)

edit:
as long the setting in conf "abm_interval" = 1 and so bigger than the maybe set "u32 max_time_ms" it should work.
most report about 250-270ms, some near 360 and very less even reach 550 ... mhhhh

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Thu Feb 28, 2019 09:04
by IhrFussel
Festus1965 wrote: But for what is that warning then good ... when I need to code again to get an answer what ABMs used most time. Here we are back at lagcheck and how to find the right part in fe. technic number shown in the () ...

(If that game is meant only for coders no problem ...one problem less for me then)

edit:
as long the setting in conf "abm_interval" = 1 and so bigger than the maybe set "u32 max_time_ms" it should work.
most report about 250-270ms, some near 360 and very less even reach 550 ... mhhhh
The warning simply tells you that your machine is not fast enough to process all running ABMs within the specified time (not sure why exactly 200ms but that's roughly 2x the default server step so makes sense I guess).

On my server I get those once every few hours and they usually never exceed 300ms, so you need to profile the ABMs with the mod profiler to see which ones lag the server the most. There is no need to edit the c++ source code to fix this.

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Thu Feb 28, 2019 11:46
by Festus1965
IhrFussel wrote:The warning simply tells you that your machine is not fast enough to process all running ABMs within the specified time (not sure why exactly 200ms but that's roughly 2x the default server step so makes sense I guess).
so
* that is still fast strong hardware, what mean more, mts cant be runned with more or much of bad using abm mods
* why mention server step, my one is "dedicated_server_step = 0.01" as for another reason
thought thar might be more important for abm

Code: Select all

#    Time in between active block management cycles
active_block_mgmt_interval = 1.5

#    Length of time between ABM execution cycles
abm_interval = 1.0
to make sure, abm is NOT managed before abm management is ready, so still had 1000 ms for all abm ?

but

Code: Select all

2019-03-01 08:28:51: WARNING[Server]: active block modifiers took 202ms (longer than 200ms)
2019-03-01 08:29:21: WARNING[Server]: active block modifiers took 204ms (longer than 200ms)
2019-03-01 08:29:58: WARNING[Server]: active block modifiers took 262ms (longer than 200ms)
2019-03-01 08:30:43: WARNING[Server]: active block modifiers took 212ms (longer than 200ms)
2019-03-01 08:30:58: WARNING[Server]: active block modifiers took 208ms (longer than 200ms)
2019-03-01 08:31:58: WARNING[Server]: active block modifiers took 203ms (longer than 200ms)
it happens every 30 seconds, where is that switch or what abm happen after 30 sec to overload ?

edit:
I found only 2 mod in moretrees abm set to "interval = 30" sec, one not activated homedecor and one sure not (as not in lagcheck) so I changed both of them to 45 and 50 sec.
so it is possible to nearby to calculate about the time diff off abm warning, to guess belonging abm using mod, set to that time interval ... (hope right thought).
But theese are less, most I have now one with 20 sec ... search later ...
-endedit-
IhrFussel wrote:... so you need to profile the ABMs with the mod profiler to see which ones lag the server the most.
moretrees !
* i guess also this most running rubber traps
rest mean animals and monsters off - then I have silence

Code: Select all

moretrees (2)             |       705 |         0 |    550292
moretrees (49)            |       661 |         0 |    805970
moretrees (15)            |       638 |         0 |    680649
technic (7)               |       586 |         0 |    935061
default (5)               |       294 |         0 |   1065610
nature_classic (2)        |       285 |         0 |     21919
moretrees (5)             |       222 |         0 |    398924
nature_classic (1)        |       187 |         0 |    712831
moretrees (28)            |       150 |         0 |     89912
mining_plus (1)           |       146 |         0 |     10233
moretrees (39)            |       133 |         0 |     30634
moreblocks (1)            |       112 |         0 |    537072
mobs_monster (4)          |       107 |         0 |      
as I even don't know how to fix the digit in () to a specified file/part of mod - thanks
and as long gamers don't complain it is ok - I was on Block Survival for 8 hours, compare as 25 gamer there, and lag there was up to 1.5 and the doors take there time to open. /home takes time, so far my servedr is still good at me, but need to keep it.

At the end then for what is the warning 200ms good then

Re: active block modifiers took 1015ms (longer than 200ms)

Posted: Mon Mar 04, 2019 04:19
by Festus1965
I just made a new build for the MTS inicluding LuaJit and changed the 200ms to 300ms,
MTS is running, some lag 0.19 now with
still without mobs-monsters and -animals I just got one warning exceed 300 at start,
since then NO ANY WARNING !
more data [Server] Minetest.one Thailand (5.0.0-rc2-1af248b) aktive

edit: and also after 7 hours just 3 lonely warnings, but about 7 during paul came in, so he was activating something at his position