search

minetest / minetest

Minetest is an open source voxel game-creation platform with easy modding and game creation
https://www.minetest.net/
Other
10.71k stars 2.02k forks source link

Stall Glitch #4151

Closed tenplus1 closed 7 years ago

tenplus1 commented 8 years ago

It seems that after a few hours Xanadu server stalls and locks up, no errors are reported, no players can connect due to major increase in lag and server looks as if it's running fine but it simply stalls ?!?! A few other servers have been known to have this problem also with 0.4.14... I'll be downgrading to a previous 0.4.13 dev (4826) before this glitch appeared and the only information I can provide is that my last 3 builds were 4833, 4835 and 4836 when glitch appeared.

Fixer-007 commented 8 years ago

Extreme Survival Minetest server has the same symptoms since its start in Aug 2015 with -dev builds of that time, bug persisted across all further versions. It is notoriously bad for gameplay with people and admins rage quitting. Symptoms: It works good for 20000 sec (~6 hours) or so with good enough lag (playable), after that surges of really big lag appear (max_lag could be 3, but actual lag can be 1-60 sec and beyound), people starting timeout, after sometime it starts working again, but worse, after some time larger lag surge appear halting everything, people time out again, it lives more, maybe up to 30000 sec, where it just stops responding at all and people slowly timeout to 0 players on servers, it is still on server list but nobody will manage to connect to it, it is in a coma, only restart solves this. It is running on i7 notebook with windows 64 if I'm not mistaken. This is very irritating issue.

tenplus1 commented 8 years ago

Update: After using May 2nd build of minetest it stalled as well, then on the 18th April build which also stalled... Compared both minetest.conf files from server and backup with no changes... Why all of a sudden the OLD builds which worked fine on Xanadu are now stalling as well ??? Will clear cache and try again.

stujones11 commented 8 years ago

Why all of a sudden the OLD builds which worked fine on Xanadu are now stalling as well

That would suggest a mod problem to me, have you tried profiling?

tenplus1 commented 8 years ago

Nothing appears for a mod problem, but since switching server to 0.4.14 stable it seems to run ok at full load...

tenplus1 commented 8 years ago

Update no.2, Shinji was on server most of the day yesterday and stall glitch never appeared for the whole day... As soon as he logged off from play it happened within an hour ?!?! so today he's connected as a player and idling to see if it happens while connected.

tenplus1 commented 8 years ago

Update no.3, server ran for just over 9 hours using above method and then the stall bug totally lagged server, no commands worked, signing out and trying to re-connect wouldnt work as it just timed out.

tenplus1 commented 8 years ago

We ran Xanadu in verbose mode and notices 100's of these errors appear:

VERBOSE[ConnectionReceive]: con(5/1)WARNING: ACKed packet not in outgoing queue

VERBOSE[ConnectionSend]: con(5/1)RE-SENDING timed-out RELIABLE to 73.244.117.13(t/o=0.236): from_peer_id=1, channel=0, seqnum=3827

Fixer-007 commented 8 years ago

Bingo! ^^^ 3307 OldCoder have solutions for this it seems.

maikerumine commented 8 years ago

I can attest that this OldCoder build seems to have solved this issue, as far as it has been running on my servers. My record time of no major lag and no lockups: uptime 78898, max lag 0.3 19 players online. Wow. I am finally impressed.

DonBatman commented 8 years ago

Can you please tell RobbieF on irc channel#minetest-project. He has. Had some issues with this.

tenplus1 commented 8 years ago

Glad to hear maikerumine, just hoping for a new build containing the patch to appear soon.

Fixer-007 commented 8 years ago

Patch is here: http://minetest.org/netfix-0.4.14.zip If some one can compile minetest with it for @tenplus1, will be nice.

0-afflatus commented 8 years ago

I wonder if we should move the whole discussion from 3307 to here, as this seems to be the same issue. It would be really useful to test the patch on Xanadu as it hasn't fixed the problem for me, although it seems to improve lag.

tenplus1 commented 8 years ago

(21:28:01) tenplus1: could you add a failsafe to the engine that detects a stall or increased lag (can be set) then restarts or quits server (21:28:22) Calinou: is that even possible? (21:29:14) tenplus1: when pressing F5 it shows you server lag, so a setting (say 20 seconds) and a check to see if lag goes beyond this and then game quits (21:29:47) tenplus1: or a nicer way is to kick everyone off server and restart it... anything so long as it restarts (21:30:08) tenplus1: the way it stalls I cant do anything about it... I have to wait for Shinji to manually close game and restart script (21:30:43) tenplus1: it many not be the ideal solution, but it's a hail mary in keeping server up and active after stalling

johnnyjoy commented 8 years ago

Assuming the AsyncRunStep is still running you could touch a file each time, and setup a script kill and restart the server when the files mtime hasn't been updated in a umber of seconds. It's a total cludge, but it might get things going in the very short term.

0-afflatus commented 8 years ago

@tenplus1 I'm more and more convinced (having hung out on Xanadu recently) this is a duplicate of what we've been discussing in #3307 and I have been experiencing on the Grailtest server - what I'm not clear about is whether the loop condition is causing the lag or whether lag is causing the loop condition, I'm getting ABM warnings in the log along with resending reliable warnings. There are so many variables in this and so little useful error reporting, even if I run dbg, that it hard to tell whether the netfix patch is helping or not. I think it is, but it didn't fix the problem for me.

It would be really useful to be able to compare notes with Shinji and/or yourself, as one of the biggest obstacles to fixing this is knowing what is really causing this and therefore the general reproducibility of the problem. We're both running with highly modified code, so I'm thinking it should be relevant to discount the differences and focus on the similarities. While I'm fairly convinced this is an engine issue, I think it may be being made worse by mod-induced lag.

Wayward1 commented 8 years ago

Just another confirmation, if it matters: I'm currently experiencing this as well on one of two similar test servers set up at home. It couldn't have been more than a couple of hours after I started them both, and about ten minutes after I last joined them both. Neither was behaving out of the ordinary. I can connect to one, but the other fills my client's debug.txt with the aforementioned "RE-SENDING timed-out RELIABLE" error. I'll try the patch once I get home and report back with more info.

Also, it may be worth noting that it crashes my Android client, while only giving an error on my Windows tablet

tenplus1 commented 8 years ago

@0-afflatus - while cerain mods are optimized in Xanadu they thankfully reduce lag instead of causing it, 40 players at 0.4 lag isn't too bad... I've been bullet-proofing many mods that use metadata incase a corrupt node doesn't contain any, also I've added a restart script to check when stall happens and kills server for it's own script to restart and keep server running when admin isn't around:

#!/bin/bash

while true; do

    # wait 2 mins before check (server_map_update_interval * 2)
    sleep 120

    # get last access date from file
    filedate=$(date -r ~/.minetest/worlds/xanadu/env_meta.txt +%s)

    # get current time in utc
    now=$(date +%s)

    # calculate how many seconds file last accessed
    ((count = now - filedate))

    # if over 3 mins, kill server (server_map_update_interval * 2 + 60)
    if [ "$count" -gt 180 ]; then

        # kill process
        TIMESTAMP=`date +%Y%m%d.%H%M`
        killall minetest
        echo ${TIMESTAMP} "minetest terminated on freeze"
    else
        echo "last accessed $count seconds ago"
    fi

done
tenplus1 commented 8 years ago

Ok, latest minetest build 4879 with patch didnt work, if anything Xanadu stalls every 4-10 minutes, so we ran server in verbose until stall and here's the tail end of the debug.txt file, full file here: https://forum.minetest.net/viewtopic.php?f=10&t=8494&p=219753#p219753

2016-06-03 17:44:09: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[object 6172]
2016-06-03 17:44:09: ACTION[Server]: heyalex punches object 6172: LuaEntitySAO at (354.431,14,-176.406)
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 262
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:09: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[object 6172]
2016-06-03 17:44:09: ACTION[Server]: heyalex punches object 6172: LuaEntitySAO at (354.431,14,-176.406)
2016-06-03 17:44:09: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6178; there are now 176 active objects.
2016-06-03 17:44:09: VERBOSE[Server]: scriptapi_luaentity_add: id=6178 name="mobs:mese_arrow"
2016-06-03 17:44:09: VERBOSE[Server]: scriptapi_luaentity_activate: id=6178
2016-06-03 17:44:09: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:09: VERBOSE[Server]: scriptapi_luaentity_rm: id=5997
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 243
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 243
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 243
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 243
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 448
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 243
2016-06-03 17:44:09: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=2, pointed=[node under=358,13,-145 above=358,13,-144]
2016-06-03 17:44:09: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[object 6028]
2016-06-03 17:44:09: ACTION[Server]: Gizzy punches object 6028: LuaEntitySAO at (328.85,8.5,-163.15)
2016-06-03 17:44:09: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[object 6172]
2016-06-03 17:44:09: ACTION[Server]: heyalex punches object 6172: LuaEntitySAO at (354.431,14,-176.406)
2016-06-03 17:44:09: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6179; there are now 176 active objects.
2016-06-03 17:44:09: VERBOSE[Server]: scriptapi_luaentity_add: id=6179 name="__builtin:item"
2016-06-03 17:44:09: VERBOSE[Server]: scriptapi_luaentity_activate: id=6179
2016-06-03 17:44:09: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:09: VERBOSE[Server]: ObjectRef::l_remove(): id=6172
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 267
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 267
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 267
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sending TOCLIENT_MOVE_PLAYER pos=(3538,185,-20144) pitch=15.15 yaw=282.6
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:09: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 76
2016-06-03 17:44:10: VERBOSE[Server]: ObjectRef::l_remove(): id=6174
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6172
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: INFO[Server]: ServerMap: Unloaded 37 blocks from memory, of which 32 were written, 717 blocks in memory.
2016-06-03 17:44:10: INFO[Server]: ServerMap: Blocks modified by: 
2016-06-03 17:44:10: INFO[Server]:   setTimestamp: - - - - - - - - - - - - - - 7
2016-06-03 17:44:10: INFO[Server]:   setTimestamp, Timestamp expired (step): - 25
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 236
2016-06-03 17:44:10: VERBOSE[Server]: ObjectRef::l_remove(): id=6177
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 702
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 238
2016-06-03 17:44:10: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[object 6028]
2016-06-03 17:44:10: ACTION[Server]: Gizzy punches object 6028: LuaEntitySAO at (329.103,8.5,-163.15)
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6057 on inactive block (-1,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6057 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6057
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6058 on inactive block (-1,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6058 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6058
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6059 on inactive block (-1,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6059 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6059
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6060 on inactive block (-1,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6060 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6060
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6061 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6061 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6061
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6062 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6062 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6062
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6063 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6063 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6063
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6064 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6064 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6064
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6065 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6065 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6065
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6066 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6066 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6066
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6067 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6067 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6067
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6068 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6068 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6068
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6069 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6069 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6069
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6070 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6070 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6070
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6071 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6071 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6071
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6072 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6072 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6072
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6073 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6073 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6073
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6074 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6074 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6074
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6075 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6075 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6075
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6076 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6076 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6076
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6077 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6077 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6077
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6078 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6078 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6078
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6079 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6079 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6079
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6080 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6080 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6080
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6081 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6081 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6081
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6082 on inactive block (-1,0,1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6082 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6082
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6083 on inactive block (0,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6083 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6083
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6084 on inactive block (0,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6084 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6084
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6085 on inactive block (0,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6085 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6085
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6086 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6086 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6086
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6087 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6087 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6087
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6088 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6088 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6088
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6089 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6089 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6089
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6090 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6090 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6090
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6091 on inactive block (0,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6091 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6091
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6092 on inactive block (0,1,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6092 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6092
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6094 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6094 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6094
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6095 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6095 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6095
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6096 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6096 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6096
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6097 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6097 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6097
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6098 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6098 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6098
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6099 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6099 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6099
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6100 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6100 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6100
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6101 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6101 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6101
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6102 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6102 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6102
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6103 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6103 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6103
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6104 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6104 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6104
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6105 on inactive block (2,0,-2)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6105 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6105
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6106 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6106 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6106
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6107 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6107 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6107
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6108 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6108 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6108
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6109 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6109 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6109
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6110 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6110 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6110
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6111 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6111 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6111
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6112 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6112 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6112
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6113 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6113 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6113
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6114 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6114 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6114
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6115 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6115 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6115
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6116 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6116 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6116
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6117 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6117 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6117
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6118 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6118 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6118
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6119 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6119 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6119
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6120 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6120 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6120
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6121 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6121 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6121
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6122 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6122 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6122
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6123 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6123 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6123
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6124 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6124 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6124
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6125 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6125 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6125
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6126 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6126 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6126
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6127 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6127 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6127
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6128 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6128 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6128
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6129 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6129 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6129
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6130 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6130 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6130
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6131 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6131 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6131
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6132 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6132 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6132
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6133 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6133 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6133
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6134 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6134 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6134
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6135 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6135 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6135
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6136 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6136 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6136
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6137 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6137 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6137
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6138 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6138 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6138
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6139 on inactive block (2,0,-1)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6139 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6139
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6140 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6140 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6140
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6141 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6141 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6141
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6142 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6142 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6142
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6143 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6143 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6143
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6144 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6144 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6144
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6145 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6145 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6145
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6146 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6146 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6146
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6147 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6147 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6147
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6148 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6148 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6148
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6149 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6149 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6149
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6150 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6150 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6150
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6151 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6151 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6151
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6152 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6152 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6152
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6153 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6153 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6153
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6154 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6154 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6154
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6155 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6155 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6155
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6156 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6156 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6156
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): deactivating object id=6157 on inactive block (2,0,0)
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::deactivateFarObjects(): object id=6157 is not known by clients; deleting
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6157
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activating objects of block (20,-1,-14) (1 objects)
2016-06-03 17:44:10: INFO[Server]: LuaEntitySAO::create(name="mobs:ghost" state="")
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activated static object pos=(325.101,-14,-216.009) type=7
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6180; there are now 76 active objects.
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_add: id=6180 name="mobs:ghost"
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_activate: id=6180
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activating objects of block (21,1,-14) (1 objects)
2016-06-03 17:44:10: INFO[Server]: LuaEntitySAO::create(name="mobs:sand_monster" state="")
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activated static object pos=(347.349,16.5,-210.163) type=7
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6181; there are now 77 active objects.
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_add: id=6181 name="mobs:sand_monster"
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_activate: id=6181
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activating objects of block (293,-2,307) (1 objects)
2016-06-03 17:44:10: INFO[Server]: LuaEntitySAO::create(name="mobs:rat" state="")
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::activateObjects(): activated static object pos=(4687.7,-20,4925.7) type=7
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6182; there are now 78 active objects.
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_add: id=6182 name="mobs:rat"
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_activate: id=6182
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6174
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_rm: id=6177
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 236
2016-06-03 17:44:10: VERBOSE[Server]: Server: MapEditEvents:
2016-06-03 17:44:10: VERBOSE[Server]:   MEET_ADDNODE: - - - - - - - - - - - - - - 1
2016-06-03 17:44:10: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[object 6028]
2016-06-03 17:44:10: ACTION[Server]: Gizzy punches object 6028: LuaEntitySAO at (329.103,8.5,-163.15)
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6183; there are now 77 active objects.
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_add: id=6183 name="mobs:fireball"
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_activate: id=6183
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 227
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 227
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 227
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 240
2016-06-03 17:44:10: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[object 6028]
2016-06-03 17:44:10: ACTION[Server]: Gizzy punches object 6028: LuaEntitySAO at (329.103,8.5,-163.15)
2016-06-03 17:44:10: VERBOSE[Server]: TOSERVER_INTERACT: action=4, item=2, pointed=[nothing]
2016-06-03 17:44:10: ACTION[Server]: TenPlus1 uses mobs:egg, pointing at [nothing]
2016-06-03 17:44:10: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6184; there are now 78 active objects.
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_add: id=6184 name="mobs:egg_entity"
2016-06-03 17:44:10: VERBOSE[Server]: scriptapi_luaentity_activate: id=6184
2016-06-03 17:44:10: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 702
2016-06-03 17:44:10: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=6178
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=4, item=2, pointed=[nothing]
2016-06-03 17:44:11: ACTION[Server]: TenPlus1 uses mobs:egg, pointing at [nothing]
2016-06-03 17:44:11: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6185; there are now 79 active objects.
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_add: id=6185 name="mobs:egg_entity"
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_activate: id=6185
2016-06-03 17:44:11: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[node under=355,12,-178 above=355,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 473
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[object 6028]
2016-06-03 17:44:11: ACTION[Server]: Gizzy punches object 6028: LuaEntitySAO at (329.103,8.5,-163.15)
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=1, pointed=[node under=355,12,-178 above=355,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=6176
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=6183
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 244
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:11: INFO[Server]: Server: MapEditEvents:
2016-06-03 17:44:11: INFO[Server]:   MEET_ADDNODE: - - - - - - - - - - - - - - 6
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[node under=355,12,-178 above=355,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 242
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=1, pointed=[node under=355,12,-178 above=355,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 8
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[node under=356,12,-178 above=356,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=1, pointed=[node under=356,12,-178 above=356,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=5954
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=5956
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=5957
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=5958
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_rm: id=6176
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_rm: id=6178
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_rm: id=6183
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 12
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 12
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 12
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 12
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 12
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[object 6179]
2016-06-03 17:44:11: ACTION[Server]: heyalex punches object 6179: LuaEntitySAO at (355.731,12.7081,-177.706)
2016-06-03 17:44:11: VERBOSE[Server]: ObjectRef::l_remove(): id=6179
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=4, item=2, pointed=[nothing]
2016-06-03 17:44:11: ACTION[Server]: TenPlus1 uses mobs:egg, pointing at [nothing]
2016-06-03 17:44:11: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6186; there are now 77 active objects.
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_add: id=6186 name="mobs:egg_entity"
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_activate: id=6186
2016-06-03 17:44:11: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 232
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 234
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 232
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=5, pointed=[node under=327,8,-162 above=327,8,-161]
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=2, item=5, pointed=[node under=327,8,-162 above=327,8,-161]
2016-06-03 17:44:11: ACTION[Server]: Gizzy digs fire:basic_flame at (327,8,-162)
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:11: VERBOSE[Server]: Server: MapEditEvents:
2016-06-03 17:44:11: VERBOSE[Server]:   MEET_REMOVENODE: - - - - - - - - - - - -  1
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[node under=357,12,-178 above=357,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=1, pointed=[node under=357,12,-178 above=357,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=0, item=1, pointed=[node under=356,12,-178 above=356,13,-178]
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=4, item=2, pointed=[nothing]
2016-06-03 17:44:11: ACTION[Server]: TenPlus1 uses mobs:egg, pointing at [nothing]
2016-06-03 17:44:11: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6187; there are now 78 active objects.
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_add: id=6187 name="mobs:egg_entity"
2016-06-03 17:44:11: VERBOSE[Server]: scriptapi_luaentity_activate: id=6187
2016-06-03 17:44:11: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:11: VERBOSE[Server]: TOSERVER_INTERACT: action=1, item=1, pointed=[node under=356,12,-178 above=356,13,-178]
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_rm: id=5954
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_rm: id=5956
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_rm: id=5957
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_rm: id=5958
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_rm: id=6179
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: ObjectRef::l_remove(): id=6184
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 244
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: TOSERVER_INTERACT: action=4, item=2, pointed=[nothing]
2016-06-03 17:44:12: ACTION[Server]: TenPlus1 uses mobs:egg, pointing at [nothing]
2016-06-03 17:44:12: VERBOSE[Server]: ServerEnvironment::addActiveObjectRaw(): Added id=6188; there are now 74 active objects.
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_add: id=6188 name="mobs:egg_entity"
2016-06-03 17:44:12: VERBOSE[Server]: scriptapi_luaentity_activate: id=6188
2016-06-03 17:44:12: VERBOSE[Server]: virtual std::__cxx11::string LuaEntitySAO::getStaticData()
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 230
2016-06-03 17:44:12: ACTION[Server]: Player Gizzy punched by LuaEntitySAO at (329.103,8.5,-163.15), damage 0 HP
2016-06-03 17:44:12: VERBOSE[Server]: ObjectRef::l_remove(): id=6185
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:12: VERBOSE[Server]: Server: Sent object remove/add: 0 removed, 0 added, packet size is 6
2016-06-03 17:44:34: VERBOSE[ConnectionSend]: con(5/1)RE-SENDING timed-out RELIABLE to 108.52.69.10(t/o=3): from_peer_id=1, channel=0, seqnum=6421
2016-06-03 17:44:35: VERBOSE[ConnectionReceive]: con(5/1)WARNING: ACKed packet not in outgoing queue
2016-06-03 17:44:46: [Main]: INFO: sigint_handler(): Ctrl-C pressed, shutting down.
2016-06-03 17:44:46: INFO[Main]: Dedicated server quitting
2016-06-03 17:44:46: INFO[Main]: Server destructing
0-afflatus commented 8 years ago

Based on my experience with the patch on Grailtest, that's what I was expecting. I have to say I'm impressed with Xanadu's lack of lag and that does kind of discount it as a cause. My hunch is that we need to look at what I'm calling the 'Bermuda triangle effect', where certain areas of the map appear to cause server hangs. I think that is a different bug, but I have a feeling that if we can understand that we may get some useful info towards fixing this. I really would like to be working on more than just a hunch.

Thanks for the kill script as it looks like that will be necessary for the time being.

tenplus1 commented 8 years ago

The specific areas that causes the stall glitch to happen were regenerated using the /deleteblocks command and does indeed stop it from happening, but... deleting a huge chunk of map each time containing player builds isnt the best option so yeah, we really need to find the cause.

Apart from metadata, what else does the engine gather from nodes that may become corrupted and cause problems ?

verymilan commented 8 years ago

The last time i ran into this glitch was a few months ago, when i tryed to do a public message on minetest.register_on_newplayer. (#3563) Maybe not helpful...but...who knows.. .

0-afflatus commented 8 years ago

Apart from metadata, what else does the engine gather from nodes that may become corrupted and cause problems ?

Good question. I'm reminded of a problem rubenwardy's chatplus mod (#2383) had checking for players that were offline at the time.

Light?

rubenwardy commented 8 years ago

I had problems a year ago with the following code causing the server to lock up:

minetest.register_on_newplayer(function(player)
    minetest.chat_send_all(" has joined")
end)

but this has supposedly been fixed.

Capturetheflag, not chatplus

0-afflatus commented 8 years ago

Capturetheflag, not chatplus

Hmm? It was definitely the old version of chatplus I was using, I have never played or dl'd CTF. I'm saying that this bug seems similar rather than the same. Subtle but important difference.

rubenwardy commented 8 years ago

Oh, the issue is about capturetheflag but it's probably in chatplus as well.

Fixer-007 commented 8 years ago

Full backtrace and debug.txt available here: https://forum.minetest.net/viewtopic.php?f=10&t=8494&p=219753#p219753

est31 commented 8 years ago

I'm summarizing some knowledge collected on IRC:

Fixer-007 commented 8 years ago

Don't forget that stall glitch is not @tenplus1 exclusive, other servers were having stalls alike this, with somewhat different behaviours, for example, ESM was having big max_lag surges before going into coma. I think it could be in fact several bugs.

tenplus1 commented 8 years ago

Maybe we're looking at mods with "get_craft_result" problems ?

0-afflatus commented 8 years ago

OK, well I was planning to move to nodetimers anyway on Grailtest - I am also still using ABMs, so this analysis makes some kind of sense.

@Fixer-007 sure, but for most of the servers running MTgame the problem appears to be historical.

est31 commented 8 years ago

Still, in theory it should run bug-free with ABMs as well. Its a bug in any case.

0-afflatus commented 8 years ago

it should run bug-free with ABMs

I have made one change so far, on an educated hunch. I removed all references to catchup = false 24 hours ago. https://github.com/0-afflatus/grailtest/commit/ff4e6505a6b632b3110af2a0b66a38470104f694 I haven't noticed any problems with furnaces, which were not using catchup = false in Grailtest. As this is a case of proving the needle isn't in the haystack I'm not holding my breath ...

0-afflatus commented 8 years ago

So removing catchup = false doesn't prevent stalling, it just slows down the process somewhat. Inconclusive.

Fixer-007 commented 7 years ago

Can be closed I guess.

Fixer-007 commented 7 years ago

https://github.com/minetest/minetest/pull/4170 fixed the problem