Mineclonia
/
Mineclonia
Archived
12
17
Fork 13
Code Issues 105 Pull Requests 19 Projects Releases Wiki Activity

Server crash on client crash #104

New Issue
Closed
opened 2021-07-02 02:33:48 +02:00 by cora · 10 comments
cora commented 2021-07-02 02:33:48 +02:00
Member
Copy Link
What happened?

I was trying to log into clamity and being stupid as i am i had a syntax error in an unfinished csm and boom the server crashed right after my client crashed. I did it multiple times with multiple accounts which are at different locations.

Here's the error message i got from the friendly substitute admin Clamork ^^

2021-07-02 01:43:25: ERROR[Main]: ServerError: AsyncErr: environment_Step: Runtime error from mod 'wieldview' in callback environment_Step(): Invalid position (expected table got nil).
2021-07-02 01:43:25: ERROR[Main]: stack traceback:
2021-07-02 01:43:25: ERROR[Main]:       [C]: in function 'add_entity'
2021-07-02 01:43:25: ERROR[Main]:       .../misc/../games/mineclonia/mods/PLAYER/wieldview/init.lua:74: in function 'func'
2021-07-02 01:43:25: ERROR[Main]:       /home/strychten/server/misc/../builtin/common/after.lua:20: in function </home/strychten/server/misc/../builtin/common/after.lua:5>
2021-07-02 01:43:25: ERROR[Main]:       /home/strychten/server/misc/../builtin/game/register.lua:425: in function </home/strychten/server/misc/../builtin/game/register.lua:409>
2021-07-02 01:43:25: ERROR[Main]: stack traceback:
What did I expect?

I expected my miserable failure at lua to not affect server operation i.e. I expected the server not to crash even if my client did so horribly.

How to get it to happen

I will try to reproduce it locally today

Environment

Mineclonia Version: commit 00ee2d5013 (current master)
Minetest Version:https://github.com/ClamityAnarchy/minetest/

##### What happened? I was trying to log into clamity and being stupid as i am i had a syntax error in an unfinished csm and *boom* the server crashed right after my client crashed. I did it multiple times with multiple accounts which are at different locations. Here's the error message i got from the friendly substitute admin Clamork ^^ ``` 2021-07-02 01:43:25: ERROR[Main]: ServerError: AsyncErr: environment_Step: Runtime error from mod 'wieldview' in callback environment_Step(): Invalid position (expected table got nil). 2021-07-02 01:43:25: ERROR[Main]: stack traceback: 2021-07-02 01:43:25: ERROR[Main]: [C]: in function 'add_entity' 2021-07-02 01:43:25: ERROR[Main]: .../misc/../games/mineclonia/mods/PLAYER/wieldview/init.lua:74: in function 'func' 2021-07-02 01:43:25: ERROR[Main]: /home/strychten/server/misc/../builtin/common/after.lua:20: in function </home/strychten/server/misc/../builtin/common/after.lua:5> 2021-07-02 01:43:25: ERROR[Main]: /home/strychten/server/misc/../builtin/game/register.lua:425: in function </home/strychten/server/misc/../builtin/game/register.lua:409> 2021-07-02 01:43:25: ERROR[Main]: stack traceback: ``` ##### What did I expect? I expected my miserable failure at lua to not affect server operation i.e. I expected the server not to crash even if my client did so horribly. ##### How to get it to happen I will try to reproduce it locally today ##### Environment Mineclonia Version: commit 00ee2d5013589105946a41999e682ff358b55e29 (current master) Minetest Version:https://github.com/ClamityAnarchy/minetest/
cora added the
bug
unconfirmed
 labels 2021-07-02 02:33:48 +02:00
cora commented 2021-07-02 02:37:03 +02:00
Author
Member
Copy Link

So what appears to be happening is this: wieldview calls minetest.add_entity with the player position as argument. This happens 1 step after on_joinplayer(, which passes the player object via minetest.after. When the client crashes though the player object is already removed and get_pos returns nil. This is the on_joinplayer:

minetest.register_on_joinplayer(function(player)
	local name = player:get_player_name()
	wieldview.wielded_item[name] = ""
	minetest.after(0, function(player)
		wieldview:update_wielded_item(player)
		local itementity = minetest.add_entity(player:get_pos(), "wieldview:wieldnode")
		itementity:set_attach(player, "Hand_Right", vector.new(0, 0, 0), vector.new(15, 45, 0))
		itementity:get_luaentity().wielder = name
	end, player)
end)

It seems somewhat likely this might not be the only place where this is happening. It's not a huge problem pracitcally speaking as long as noone abuses it but we should still investigate this.

So what appears to be happening is this: wieldview calls minetest.add_entity with the player position as argument. This happens 1 step after on_joinplayer(, which passes the player object via minetest.after. When the client crashes though the player object is already removed and get_pos returns nil. This is the on_joinplayer: ``` minetest.register_on_joinplayer(function(player) local name = player:get_player_name() wieldview.wielded_item[name] = "" minetest.after(0, function(player) wieldview:update_wielded_item(player) local itementity = minetest.add_entity(player:get_pos(), "wieldview:wieldnode") itementity:set_attach(player, "Hand_Right", vector.new(0, 0, 0), vector.new(15, 45, 0)) itementity:get_luaentity().wielder = name end, player) end) ``` It seems somewhat likely this might not be the only place where this is happening. It's not a huge problem pracitcally speaking as long as noone abuses it but we should still investigate this.
cora commented 2021-07-02 02:55:17 +02:00
Author
Member
Copy Link

I have not been able to reproduce it locally so far. Not sure what's going on.

I have not been able to reproduce it locally so far. Not sure what's going on.
erlehmann commented 2021-08-22 03:06:15 +02:00
Owner
Copy Link

This can be reproduced locally by increasing the timeout for minetest.after() to a few seconds, and connecting to a server, then disconnecting within that timeframe.

This can be reproduced locally by increasing the timeout for `minetest.after()` to a few seconds, and connecting to a server, then disconnecting within that timeframe.
erlehmann commented 2021-08-22 03:26:16 +02:00
Owner
Copy Link

I wondered why there is a minetest.after() with a time of 0 (i.e. immediate).

So far the only thing I suspect is that this creates a new execution context.

I wondered why there is a minetest.after() with a time of 0 (i.e. immediate). So far the only thing I suspect is that this creates a new execution context.
erlehmann commented 2021-08-22 03:27:41 +02:00
Owner
Copy Link

When a player disappears, then in the body of the anonymous function called by minetest.after() the player variable is still valid, but player:get_pos() returns nil.

This means that the code needs to check if player:get_pos() is nil.

When a player disappears, then in the body of the anonymous function called by minetest.after() the player variable is still valid, but `player:get_pos()` returns `nil`. This means that the code needs to check if `player:get_pos()` is nil.
erlehmann commented 2021-08-22 03:31:07 +02:00
Owner
Copy Link

I tried to figure out if there exist more functions called by minetest.after() that take a player argument:

; git grep -W 'minetest.after.*player'
mods/HUD/mcl_death_messages/init.lua=local start_damage_reset_countdown = function (player, sequence_number)
mods/HUD/mcl_death_messages/init.lua:   minetest.after(1, function(playername, sequence_number)
mods/HUD/mcl_death_messages/init.lua-           if last_damages[playername] and last_damages[playername].sequence_number == sequence_number then
mods/HUD/mcl_death_messages/init.lua-                   last_damages[playername] = nil
mods/HUD/mcl_death_messages/init.lua-           end
mods/HUD/mcl_death_messages/init.lua-   end, player:get_player_name(), sequence_number)
--
mods/ITEMS/mcl_portals/portal_nether.lua=local function animation(player, playername)
mods/ITEMS/mcl_portals/portal_nether.lua-       local chatter = touch_chatter_prevention[player] or 0
mods/ITEMS/mcl_portals/portal_nether.lua-       if mcl_portals.nether_portal_cooloff[player] or minetest.get_us_time() - chatter < TOUCH_CHATTER_TIME_US then
mods/ITEMS/mcl_portals/portal_nether.lua-               local pos = player:get_pos()
mods/ITEMS/mcl_portals/portal_nether.lua-               if not pos then
mods/ITEMS/mcl_portals/portal_nether.lua-                       return
mods/ITEMS/mcl_portals/portal_nether.lua-               end
mods/ITEMS/mcl_portals/portal_nether.lua-               minetest.add_particlespawner({
mods/ITEMS/mcl_portals/portal_nether.lua-                       amount = 1,
mods/ITEMS/mcl_portals/portal_nether.lua-                       minpos = {x = pos.x - 0.1, y = pos.y + 1.4, z = pos.z - 0.1},
mods/ITEMS/mcl_portals/portal_nether.lua-                       maxpos = {x = pos.x + 0.1, y = pos.y + 1.6, z = pos.z + 0.1},
mods/ITEMS/mcl_portals/portal_nether.lua-                       minvel = 0,
mods/ITEMS/mcl_portals/portal_nether.lua-                       maxvel = 0,
mods/ITEMS/mcl_portals/portal_nether.lua-                       minacc = 0,
mods/ITEMS/mcl_portals/portal_nether.lua-                       maxacc = 0,
mods/ITEMS/mcl_portals/portal_nether.lua-                       minexptime = 0.1,
mods/ITEMS/mcl_portals/portal_nether.lua-                       maxexptime = 0.2,
mods/ITEMS/mcl_portals/portal_nether.lua-                       minsize = 5,
mods/ITEMS/mcl_portals/portal_nether.lua-                       maxsize = 15,
mods/ITEMS/mcl_portals/portal_nether.lua-                       collisiondetection = false,
mods/ITEMS/mcl_portals/portal_nether.lua-                       texture = "mcl_particles_nether_portal_t.png",
mods/ITEMS/mcl_portals/portal_nether.lua-                       playername = playername,
mods/ITEMS/mcl_portals/portal_nether.lua-               })
mods/ITEMS/mcl_portals/portal_nether.lua:               minetest.after(0.3, animation, player, playername)
mods/ITEMS/mcl_portals/portal_nether.lua-       end
--
mods/ITEMS/mcl_potions/functions.lua=minetest.register_on_joinplayer( function(player)
mods/ITEMS/mcl_potions/functions.lua-   mcl_potions._reset_player_effects(player, false) -- make sure there are no wierd holdover effects
mods/ITEMS/mcl_potions/functions.lua-   mcl_potions._load_player_effects(player)
mods/ITEMS/mcl_potions/functions.lua-   potions_init_icons(player)
mods/ITEMS/mcl_potions/functions.lua-   -- .after required because player:hud_change doesn't work when called
mods/ITEMS/mcl_potions/functions.lua-   -- in same tick as player:hud_add
mods/ITEMS/mcl_potions/functions.lua-   -- (see <https://github.com/minetest/minetest/pull/9611>)
mods/ITEMS/mcl_potions/functions.lua-   -- FIXME: Remove minetest.after
mods/ITEMS/mcl_potions/functions.lua:   minetest.after(3, function(player)
mods/ITEMS/mcl_potions/functions.lua-           if player and player:is_player() then
mods/ITEMS/mcl_potions/functions.lua-                   potions_set_hud(player)
mods/ITEMS/mcl_potions/functions.lua-           end
mods/ITEMS/mcl_potions/functions.lua-   end, player)
--
mods/PLAYER/wieldview/init.lua=minetest.register_on_joinplayer(function(player)
mods/PLAYER/wieldview/init.lua-	local name = player:get_player_name()
mods/PLAYER/wieldview/init.lua-	wieldview.wielded_item[name] = ""
mods/PLAYER/wieldview/init.lua:	minetest.after(0, function(player)
mods/PLAYER/wieldview/init.lua-		wieldview:update_wielded_item(player)
mods/PLAYER/wieldview/init.lua-		local itementity = minetest.add_entity(player:get_pos(), "wieldview:wieldnode")
mods/PLAYER/wieldview/init.lua-		itementity:set_attach(player, "Hand_Right", vector.new(0, 0, 0), vector.new(15, 45, 0))
mods/PLAYER/wieldview/init.lua-		itementity:get_luaentity().wielder = name
mods/PLAYER/wieldview/init.lua-	end, player)
I tried to figure out if there exist more functions called by minetest.after() that take a player argument: ``` ; git grep -W 'minetest.after.*player' mods/HUD/mcl_death_messages/init.lua=local start_damage_reset_countdown = function (player, sequence_number) mods/HUD/mcl_death_messages/init.lua: minetest.after(1, function(playername, sequence_number) mods/HUD/mcl_death_messages/init.lua- if last_damages[playername] and last_damages[playername].sequence_number == sequence_number then mods/HUD/mcl_death_messages/init.lua- last_damages[playername] = nil mods/HUD/mcl_death_messages/init.lua- end mods/HUD/mcl_death_messages/init.lua- end, player:get_player_name(), sequence_number) -- mods/ITEMS/mcl_portals/portal_nether.lua=local function animation(player, playername) mods/ITEMS/mcl_portals/portal_nether.lua- local chatter = touch_chatter_prevention[player] or 0 mods/ITEMS/mcl_portals/portal_nether.lua- if mcl_portals.nether_portal_cooloff[player] or minetest.get_us_time() - chatter < TOUCH_CHATTER_TIME_US then mods/ITEMS/mcl_portals/portal_nether.lua- local pos = player:get_pos() mods/ITEMS/mcl_portals/portal_nether.lua- if not pos then mods/ITEMS/mcl_portals/portal_nether.lua- return mods/ITEMS/mcl_portals/portal_nether.lua- end mods/ITEMS/mcl_portals/portal_nether.lua- minetest.add_particlespawner({ mods/ITEMS/mcl_portals/portal_nether.lua- amount = 1, mods/ITEMS/mcl_portals/portal_nether.lua- minpos = {x = pos.x - 0.1, y = pos.y + 1.4, z = pos.z - 0.1}, mods/ITEMS/mcl_portals/portal_nether.lua- maxpos = {x = pos.x + 0.1, y = pos.y + 1.6, z = pos.z + 0.1}, mods/ITEMS/mcl_portals/portal_nether.lua- minvel = 0, mods/ITEMS/mcl_portals/portal_nether.lua- maxvel = 0, mods/ITEMS/mcl_portals/portal_nether.lua- minacc = 0, mods/ITEMS/mcl_portals/portal_nether.lua- maxacc = 0, mods/ITEMS/mcl_portals/portal_nether.lua- minexptime = 0.1, mods/ITEMS/mcl_portals/portal_nether.lua- maxexptime = 0.2, mods/ITEMS/mcl_portals/portal_nether.lua- minsize = 5, mods/ITEMS/mcl_portals/portal_nether.lua- maxsize = 15, mods/ITEMS/mcl_portals/portal_nether.lua- collisiondetection = false, mods/ITEMS/mcl_portals/portal_nether.lua- texture = "mcl_particles_nether_portal_t.png", mods/ITEMS/mcl_portals/portal_nether.lua- playername = playername, mods/ITEMS/mcl_portals/portal_nether.lua- }) mods/ITEMS/mcl_portals/portal_nether.lua: minetest.after(0.3, animation, player, playername) mods/ITEMS/mcl_portals/portal_nether.lua- end -- mods/ITEMS/mcl_potions/functions.lua=minetest.register_on_joinplayer( function(player) mods/ITEMS/mcl_potions/functions.lua- mcl_potions._reset_player_effects(player, false) -- make sure there are no wierd holdover effects mods/ITEMS/mcl_potions/functions.lua- mcl_potions._load_player_effects(player) mods/ITEMS/mcl_potions/functions.lua- potions_init_icons(player) mods/ITEMS/mcl_potions/functions.lua- -- .after required because player:hud_change doesn't work when called mods/ITEMS/mcl_potions/functions.lua- -- in same tick as player:hud_add mods/ITEMS/mcl_potions/functions.lua- -- (see <https://github.com/minetest/minetest/pull/9611>) mods/ITEMS/mcl_potions/functions.lua- -- FIXME: Remove minetest.after mods/ITEMS/mcl_potions/functions.lua: minetest.after(3, function(player) mods/ITEMS/mcl_potions/functions.lua- if player and player:is_player() then mods/ITEMS/mcl_potions/functions.lua- potions_set_hud(player) mods/ITEMS/mcl_potions/functions.lua- end mods/ITEMS/mcl_potions/functions.lua- end, player) -- mods/PLAYER/wieldview/init.lua=minetest.register_on_joinplayer(function(player) mods/PLAYER/wieldview/init.lua- local name = player:get_player_name() mods/PLAYER/wieldview/init.lua- wieldview.wielded_item[name] = "" mods/PLAYER/wieldview/init.lua: minetest.after(0, function(player) mods/PLAYER/wieldview/init.lua- wieldview:update_wielded_item(player) mods/PLAYER/wieldview/init.lua- local itementity = minetest.add_entity(player:get_pos(), "wieldview:wieldnode") mods/PLAYER/wieldview/init.lua- itementity:set_attach(player, "Hand_Right", vector.new(0, 0, 0), vector.new(15, 45, 0)) mods/PLAYER/wieldview/init.lua- itementity:get_luaentity().wielder = name mods/PLAYER/wieldview/init.lua- end, player) ```
erlehmann commented 2021-08-22 03:38:23 +02:00
Owner
Copy Link

From the following comment in mods/ITEMS/mcl_potions/functions.lua I deduce that the purpose of the minetest.after() can be to force a wait of at least one server tick:

minetest.register_on_joinplayer( function(player)
	mcl_potions._reset_player_effects(player, false) -- make sure there are no wierd holdover effects
	mcl_potions._load_player_effects(player)
	potions_init_icons(player)
	-- .after required because player:hud_change doesn't work when called
	-- in same tick as player:hud_add
	-- (see <https://github.com/minetest/minetest/pull/9611>)
	-- FIXME: Remove minetest.after
	minetest.after(3, function(player)
		if player and player:is_player() then
			potions_set_hud(player)
		end
	end, player)
end)
From the following comment in `mods/ITEMS/mcl_potions/functions.lua` I deduce that the purpose of the minetest.after() can be to force a wait of at least one server tick: ``` minetest.register_on_joinplayer( function(player) mcl_potions._reset_player_effects(player, false) -- make sure there are no wierd holdover effects mcl_potions._load_player_effects(player) potions_init_icons(player) -- .after required because player:hud_change doesn't work when called -- in same tick as player:hud_add -- (see <https://github.com/minetest/minetest/pull/9611>) -- FIXME: Remove minetest.after minetest.after(3, function(player) if player and player:is_player() then potions_set_hud(player) end end, player) end) ```
erlehmann commented 2021-08-22 03:42:58 +02:00
Owner
Copy Link

The code in mods/ITEMS/mcl_portals/portal_nether.lua contains a probably working check for a player that left (checking if player:get_pos() returns something falsy):

local function animation(player, playername)
	local chatter = touch_chatter_prevention[player] or 0
	if mcl_portals.nether_portal_cooloff[player] or minetest.get_us_time() - chatter < TOUCH_CHATTER_TIME_US then
		local pos = player:get_pos()
		if not pos then
			return
		end
		minetest.add_particlespawner({
			amount = 1,
			minpos = {x = pos.x - 0.1, y = pos.y + 1.4, z = pos.z - 0.1},
			maxpos = {x = pos.x + 0.1, y = pos.y + 1.6, z = pos.z + 0.1},
			minvel = 0,
			maxvel = 0,
			minacc = 0,
			maxacc = 0,
			minexptime = 0.1,
			maxexptime = 0.2,
			minsize = 5,
			maxsize = 15,
			collisiondetection = false,
			texture = "mcl_particles_nether_portal_t.png",
			playername = playername,
		})
		minetest.after(0.3, animation, player, playername)
	end
end
The code in `mods/ITEMS/mcl_portals/portal_nether.lua` contains a *probably* working check for a player that left (checking if `player:get_pos()` returns something falsy): ``` local function animation(player, playername) local chatter = touch_chatter_prevention[player] or 0 if mcl_portals.nether_portal_cooloff[player] or minetest.get_us_time() - chatter < TOUCH_CHATTER_TIME_US then local pos = player:get_pos() if not pos then return end minetest.add_particlespawner({ amount = 1, minpos = {x = pos.x - 0.1, y = pos.y + 1.4, z = pos.z - 0.1}, maxpos = {x = pos.x + 0.1, y = pos.y + 1.6, z = pos.z + 0.1}, minvel = 0, maxvel = 0, minacc = 0, maxacc = 0, minexptime = 0.1, maxexptime = 0.2, minsize = 5, maxsize = 15, collisiondetection = false, texture = "mcl_particles_nether_portal_t.png", playername = playername, }) minetest.after(0.3, animation, player, playername) end end ```
erlehmann commented 2021-08-22 03:55:27 +02:00
Owner
Copy Link

This bug looks like an instance of a common mistake, according to rubenwardy:

https://rubenwardy.com/minetest_modding_book/en/quality/common_mistakes.html

Be Careful When Storing ObjectRefs (ie: players or entities)

An ObjectRef is invalidated when the player or entity it represents leaves the game. This may happen when the player goes offline, or the entity is unloaded or removed.

The methods of ObjectRefs will always return nil when invalid, since Minetest 5.2. Any call will essentially be ignored.

You should avoid storing ObjectRefs where possible. If you do to store an ObjectRef, you should make you check it before use, like so:

-- This only works in Minetest 5.2+
if obj:get_pos() then
	-- is valid!
end
This bug looks like an instance of a common mistake, according to rubenwardy: https://rubenwardy.com/minetest_modding_book/en/quality/common_mistakes.html > Be Careful When Storing ObjectRefs (ie: players or entities) > > An ObjectRef is invalidated when the player or entity it represents leaves the game. This may happen when the player goes offline, or the entity is unloaded or removed. > > The methods of ObjectRefs will always return nil when invalid, since Minetest 5.2. Any call will essentially be ignored. > > You should avoid storing ObjectRefs where possible. If you do to store an ObjectRef, you should make you check it before use, like so: > > ``` > -- This only works in Minetest 5.2+ > if obj:get_pos() then > -- is valid! > end > ```
erlehmann commented 2021-08-22 20:37:38 +02:00
Owner
Copy Link

Fixed with merge of PR #138 I guess.

Fixed with merge of PR https://git.minetest.land/Mineclonia/Mineclonia/pulls/138 I guess.
This repo is archived. You cannot comment on issues.
No Branch/Tag Specified
Branches Tags
master
fix_copyright_music
cora-production
extend-nether-upwards
refactor-stairs-api-to-allow-modnames
add-podzol-to-large-spruce-trees
uncarved-pumpkin-4
limit-redstone-distance
add-mcl2-maps
fix-nether-portal-stack-overflow-2
fix-nether-portal-stack-overflow
fix-malformed-clientready
fix-daylight-detector
optimize-png-textures
add-ruined-portal
mcl-game
fix-daylightsensor-chmodsayshello
fix-etable-lag
fix-nether-portal-particles
add-selftests-setting
fix-dimension-hopping
erlehmann-production
fix-find-nodes-in-area
fix-village-freeze
rewrite-weather
fix-weather-particles
easier-grass-path-creation
fix-lavacasting-4
fix-lavacasting-2
fix-lavacasting
minecart-with-mobs-2
uncarved-pumpkin
banner-mask-fix-3
fake_master
banner-mask-fix-2
banner-mask-fix
mineclone2-backport-portals-2
mineclone2-backport-portals
mineclone2-pr-1315-portals
0.71.0
0.70.0
Labels
Clear labels   
blocker

blocks release until resolved

  
bug

   
code quality

   
confirmed

   
critical

crashes, catastrophic bugs

  
discussion

   
high priority

   
incompatibility

incompatible with mcl2

  
incomplete feature

   
invalid

   
low priority

   
missing feauture

   
needs testing

   
packet spam

   
performance

   
project

meta-issues

  
regression

   
translations

   
unconfirmed
  
in review

   
ready for review
No Label
blocker
bug
code quality
confirmed
critical
discussion
high priority
incompatibility
incomplete feature
invalid
low priority
missing feauture
needs testing
packet spam
performance
project
regression
translations
unconfirmed
in review
ready for review
Milestone
Clear milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
No Assignees
2 Participants
Due Date
The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: Mineclonia/Mineclonia#104
No description provided.
Delete Branch "%!s(<nil>)"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?