LeetPeet reports: Two death messages for jike at ... #3017

Closed
opened 2022-11-13 13:01:33 +00:00 by yourland-report · 19 comments

LeetPeet reports a bug:

Two death messages for jike at 8:00 AM EST? "jike was killed by mime near Arena." and "jike was killed near Arena."

Player position:

{
	x = 1578.1159667969,
	y = -30.5,
	z = 297.68099975586
}

Player look:

{
	x = 0.032820913940668,
	y = 0.29737484455109,
	z = -0.95419651269913
}

Player information:

{
	max_rtt = 1.3200000524521,
	lang_code = "",
	state = "Active",
	formspec_version = 6,
	ip_version = 6,
	min_rtt = 0.093000002205372,
	avg_rtt = 0.097999997437,
	min_jitter = 0,
	max_jitter = 1.2170000076294,
	avg_jitter = 0,
	connection_uptime = 3669,
	serialization_version = 29,
	patch = 0,
	minor = 6,
	version_string = "5.6.0",
	major = 5,
	protocol_version = 41
}

Player meta:

{
	fields = {
		bitten = "0",
		played_time = "7825638",
		digged_nodes = "3108462",
		placed_nodes = "616372",
		yl_commons_thankyou = "60",
		crafted = "21138",
		hud_state = "on",
		xp = "2928016",
		yl_church = "return {[\"last_heal\"] = 1630693112, [\"last_death_portal\"] = 1667960745, [\"last_death\"] = {[\"x\"] = 781, [\"y\"] = -5, [\"z\"] = 2179}}",
		["stamina:exhaustion"] = "27",
		punch_count = "23243",
		["stamina:level"] = "9",
		repellant = "0",
		partychat = "main",
		["ocean_build.forbidden"] = "true",
		died = "305",
		["stamina:poisoned"] = "no",
		["ocean_build.last_warning"] = "1.65343e+09",
		["signslib:pos"] = "(810,2,2198)",
		["ocean_build.ocean_built"] = "12",
		inflicted_damage = "373982",
		["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}",
		yl_commons_player_created = "1609243939",
		yl_commons_player_joined = "1668340856",
		arenalib_infobox_arenaID = "0",
		["3d_armor_inventory"] = "return {\"3d_armor:leggings_crystal 1 37180\", \"3d_armor:chestplate_crystal 1 37180\", \"shields:shield_crystal 1 37180\", \"3d_armor:helmet_crystal 1 36880\", \"3d_armor:boots_crystal 1 37180\", \"\"}"
	}
}

Log identifier


[MOD] yl_report log identifier = T9tbrIEc0t4sgY9YuDGeBEb5nsW676FX

Profiler save:

profile-20221113T130133.json_prettyEE

Status:

# Server: version: 5.6.1-yl | game: Minetest Game | uptime: 1h 59min 42s | max lag: 2.27s | clients (17/42): alexandre2005, AliasAlreadyTaken, Bailiff, damiemk, daydream, Greater_Dog, JeCel, jike, Laylem, LeetPeet, lorenzofoz, Sense, Service, sherkhan30452, Stelio, Sundew, yo_hi

Teleport command:

/teleport xyz 1578 -31 298

Compass command:

/give_compass Construction T9tbrIEc0t4sgY9YuDGeBEb5nsW676FX D2691E 1578 -31 298
LeetPeet reports a bug: > Two death messages for jike at 8:00 AM EST? "jike was killed by mime near Arena." and "jike was killed near Arena." Player position: ``` { x = 1578.1159667969, y = -30.5, z = 297.68099975586 } ``` Player look: ``` { x = 0.032820913940668, y = 0.29737484455109, z = -0.95419651269913 } ``` Player information: ``` { max_rtt = 1.3200000524521, lang_code = "", state = "Active", formspec_version = 6, ip_version = 6, min_rtt = 0.093000002205372, avg_rtt = 0.097999997437, min_jitter = 0, max_jitter = 1.2170000076294, avg_jitter = 0, connection_uptime = 3669, serialization_version = 29, patch = 0, minor = 6, version_string = "5.6.0", major = 5, protocol_version = 41 } ``` Player meta: ``` { fields = { bitten = "0", played_time = "7825638", digged_nodes = "3108462", placed_nodes = "616372", yl_commons_thankyou = "60", crafted = "21138", hud_state = "on", xp = "2928016", yl_church = "return {[\"last_heal\"] = 1630693112, [\"last_death_portal\"] = 1667960745, [\"last_death\"] = {[\"x\"] = 781, [\"y\"] = -5, [\"z\"] = 2179}}", ["stamina:exhaustion"] = "27", punch_count = "23243", ["stamina:level"] = "9", repellant = "0", partychat = "main", ["ocean_build.forbidden"] = "true", died = "305", ["stamina:poisoned"] = "no", ["ocean_build.last_warning"] = "1.65343e+09", ["signslib:pos"] = "(810,2,2198)", ["ocean_build.ocean_built"] = "12", inflicted_damage = "373982", ["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}", yl_commons_player_created = "1609243939", yl_commons_player_joined = "1668340856", arenalib_infobox_arenaID = "0", ["3d_armor_inventory"] = "return {\"3d_armor:leggings_crystal 1 37180\", \"3d_armor:chestplate_crystal 1 37180\", \"shields:shield_crystal 1 37180\", \"3d_armor:helmet_crystal 1 36880\", \"3d_armor:boots_crystal 1 37180\", \"\"}" } } ``` Log identifier ``` [MOD] yl_report log identifier = T9tbrIEc0t4sgY9YuDGeBEb5nsW676FX ``` Profiler save: ``` profile-20221113T130133.json_prettyEE ``` Status: ``` # Server: version: 5.6.1-yl | game: Minetest Game | uptime: 1h 59min 42s | max lag: 2.27s | clients (17/42): alexandre2005, AliasAlreadyTaken, Bailiff, damiemk, daydream, Greater_Dog, JeCel, jike, Laylem, LeetPeet, lorenzofoz, Sense, Service, sherkhan30452, Stelio, Sundew, yo_hi ``` Teleport command: ``` /teleport xyz 1578 -31 298 ``` Compass command: ``` /give_compass Construction T9tbrIEc0t4sgY9YuDGeBEb5nsW676FX D2691E 1578 -31 298 ```
AliasAlreadyTaken was assigned by yourland-report 2022-11-13 13:01:33 +00:00
flux added the
1. kind/bug
label 2022-11-13 15:04:53 +00:00
Member

possibly a regression of #1015

possibly a regression of #1015
Member
@respawn)phillip was killed by big near caves.
[STAFF] phillip dies at (2206,20,101) and their inventory goes to bones.
@respawn)phillip was killed near caves.
[STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped.
@respawn)phillip was killed near caves.
[STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped.
@respawn)phillip was killed near caves.
[STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped.
<phillip> ups rein gefallen

so this is definitely happening, but it's not a regression of #1015, which was due to the game predicting the player would die, and the armor heal factor negating it.

this feels more like multiple mobs are attacking the player, and one kills the player, but the attacks from the others still land.

``` @respawn)phillip was killed by big near caves. [STAFF] phillip dies at (2206,20,101) and their inventory goes to bones. @respawn)phillip was killed near caves. [STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped. @respawn)phillip was killed near caves. [STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped. @respawn)phillip was killed near caves. [STAFF] phillip dies at (2206,20,101) and doesn't have any inventory to be dropped. <phillip> ups rein gefallen ``` so this is definitely happening, but it's not a regression of #1015, which was due to the game *predicting* the player would die, and the armor heal factor negating it. this feels more like multiple mobs are attacking the player, and one kills the player, but the attacks from the others still land.
Member

after testing, this seems to be caused when the player is getting attacked by multiple mobs and they're wearing armor w/ "heal".

after testing, this seems to be caused when the player is getting attacked by multiple mobs *and* they're wearing armor w/ "heal".
Member

verified that "on_dieplayer" is called again if the player is killed while dead. which sounds like a glitch, but consider the case that the player is "dead" but didn't get the "death formspec" e.g. https://github.com/minetest/minetest/issues/11523

question is, can we detect that and ignore it...

verified that "on_dieplayer" is called again if the player is killed while dead. which sounds like a glitch, but consider the case that the player is "dead" but didn't get the "death formspec" e.g. https://github.com/minetest/minetest/issues/11523 question is, can we detect that and ignore it...
Member

i was able to reliably cause the issue for a while, then it stopped happening. possibly this fixes it, but the problem wasn't occurring when i was testing it:

fb0200b640

i was able to reliably cause the issue for a while, then it stopped happening. possibly this fixes it, but the problem wasn't occurring when i was testing it: https://gitea.your-land.de/your-land/mt-respawn/commit/fb0200b64003d029286257fd08f29f7028cfac1b
flux added the
4. step/ready to QA test
label 2022-11-17 21:40:53 +00:00

Why did it happen just now? We (more likely: 3d_armor?) must have changed something in some on_death (or on_hp_change) callback?

Why did it happen just now? We (more likely: 3d_armor?) must have changed something in some on_death (or on_hp_change) callback?
Member

Why did it happen just now? We (more likely: 3d_armor?) must have changed something in some on_death (or on_hp_change) callback?

very good questions that i don't have good theories about. let's wait and see if it happens more, it doesn't seem to happen often?

> Why did it happen just now? We (more likely: 3d_armor?) must have changed something in some on_death (or on_hp_change) callback? very good questions that i don't have good theories about. let's wait and see if it happens more, it doesn't seem to happen often?

Current rotation of the log started on 2022-11-13 10:46:17
Today is 2022-11-24 16:23:58

In this period 2376 death were recorded, of which 455 seem "duplicate death", measured by "death in the same second"

Current rotation of the log started on 2022-11-13 10:46:17 Today is 2022-11-24 16:23:58 In this period 2376 death were recorded, of which 455 seem "duplicate death", measured by "death in the same second"

One example:

2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:pick_stone 1 38071 to bones @ (2211,-913,582)
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:iron_lump 4 to bones @ (2211,-913,582)
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:tree to bones @ (2211,-913,582)
..
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and their inventory goes to bones.
2022-11-24 19:21:48: ACTION[Server]: [MOD] xp_redo: Spectro lost 37 XP!
2022-11-24 19:21:48: ACTION[Server]: [MOD] xp_redo: Reason of death of Spectro: return {["from"] = "engine", ["type"] = "punch", ["object"] = nil}
2022-11-24 19:21:48: ACTION[Server]: LuaEntitySAO "mobs_monster:oerkki" at (2211,-912,584) (id=42074, hp=38) punched player Spectro (id=29162, hp=0), damage=4
2022-11-24 19:21:48: ACTION[Server]: Server: Spectro tried to interact while dead; ignoring.
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro tried to interacted_while_dead while dead; killing again
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage
2022-11-24 19:21:48: ACTION[Server]: Sandra places node ethereal:glostone at (1642,-881,623)
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and doesn't have any inventory to be dropped.
2022-11-24 19:21:48: ACTION[Server]: Server: Spectro tried to interact while dead; ignoring.
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro tried to interacted_while_dead while dead; killing again
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage
2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage
2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and doesn't have any inventory to be dropped.

One example: 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:pick_stone 1 38071 to bones @ (2211,-913,582) 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:iron_lump 4 to bones @ (2211,-913,582) 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro added default:tree to bones @ (2211,-913,582) .. 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and their inventory goes to bones. 2022-11-24 19:21:48: ACTION[Server]: [MOD] xp_redo: Spectro lost 37 XP! 2022-11-24 19:21:48: ACTION[Server]: [MOD] xp_redo: Reason of death of Spectro: return {["from"] = "engine", ["type"] = "punch", ["object"] = nil} 2022-11-24 19:21:48: ACTION[Server]: LuaEntitySAO "mobs_monster:oerkki" at (2211,-912,584) (id=42074, hp=38) punched player Spectro (id=29162, hp=0), damage=4 2022-11-24 19:21:48: ACTION[Server]: Server: Spectro tried to interact while dead; ignoring. 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro tried to interacted_while_dead while dead; killing again 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage 2022-11-24 19:21:48: ACTION[Server]: Sandra places node ethereal:glostone at (1642,-881,623) 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and doesn't have any inventory to be dropped. 2022-11-24 19:21:48: ACTION[Server]: Server: Spectro tried to interact while dead; ignoring. 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro tried to interacted_while_dead while dead; killing again 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage 2022-11-24 19:21:48: ACTION[Server]: [yl_commons] Spectro is not immune to fall damage 2022-11-24 19:21:48: ACTION[Server]: [bones] Spectro dies at (2211,-913,582) and doesn't have any inventory to be dropped.

Sometimes they are not just sent twice but four or five times. Generally I have seen this happen quite often now.

Sometimes they are not just sent twice but four or five times. Generally I have seen this happen quite often now.
Member

Spectro tried to interacted_while_dead while dead; killing again

i bet that's the issue - i'm not sure why it's getting triggered, but it seems due to the solution to #478.

when a player is dead, further death messages should be ignored until they respawn.

> Spectro tried to interacted_while_dead while dead; killing again i bet that's the issue - i'm not sure why it's getting triggered, but it seems due to the solution to #478. when a player is dead, further death messages should be ignored until they respawn.
Member

fixed in 502b5a7706

fixed in https://gitea.your-land.de/your-land/mt-respawn/commit/502b5a77063ffd0ef7f67572208121e3b1284e07
AliasAlreadyTaken added this to the 1.1.117 milestone 2022-11-25 17:24:16 +00:00

I still get more than one staff message when aplayer dies and the death portal points to a wrong location?

I still get more than one staff message when aplayer dies and the death portal points to a wrong location?
Member

I still get more than one staff message when aplayer dies and the death portal points to a wrong location?

ah, that's handled by entirely different code, isn't it.

> I still get more than one staff message when aplayer dies and the death portal points to a wrong location? ah, that's handled by entirely different code, isn't it.
Member

I still get more than one staff message when aplayer dies
ah, that's handled by entirely different code, isn't it.

fixed in ba092b8075

the death portal points to a wrong location?

wait really? i didn't think players could meaningfully move while dead, at least as far as the server was concerned.

> I still get more than one staff message when aplayer dies > ah, that's handled by entirely different code, isn't it. fixed in https://gitea.your-land.de/your-land/yl_commons/commit/ba092b8075ca5833ae1f873d4f79d4b9b87669b1 > the death portal points to a wrong location? wait really? i didn't think players could meaningfully move while dead, at least as far as the server was concerned.

There must be something that kills the player over and over and even affects dead players. We should go through all register_on_dieplayer and see if there's some death loop there? Could also happen in some register_on_respawnplayer or register_on_player_hpchange or any other that affects the hp0-death-respawn order.

the death portal points to a wrong location?

wait really? i didn't think players could meaningfully move while dead, at least as far as the server was concerned.

Lag may cause a player to "keep on dieing" at the spawnpoint, effectively setting the death portal to the spawnpoint.

There must be something that kills the player over and over and even affects dead players. We should go through all register_on_dieplayer and see if there's some death loop there? Could also happen in some register_on_respawnplayer or register_on_player_hpchange or any other that affects the hp0-death-respawn order. > > the death portal points to a wrong location? > > wait really? i didn't think players could meaningfully move while dead, at least as far as the server was concerned. Lag may cause a player to "keep on dieing" at the spawnpoint, effectively setting the death portal to the spawnpoint.
Member

Lag may cause a player to "keep on dieing" at the spawnpoint, effectively setting the death portal to the spawnpoint.

lag. i see a race condition in my "kill on dead" code, that's almost certainly the cause.

> Lag may cause a player to "keep on dieing" at the spawnpoint, effectively setting the death portal to the spawnpoint. lag. i see a race condition in my "kill on dead" code, that's almost certainly the cause.
Member

fixed in 8b3a832f86

still testing it, but i think this works ....

fixed in https://gitea.your-land.de/your-land/yl_commons/commit/8b3a832f86ad59917fe96c7d1688613a48ba5d78 still testing it, but i think this works ....
AliasAlreadyTaken added the
ugh/QA main
label 2023-01-18 10:53:04 +00:00
flux added
5. result/fixed
and removed
4. step/ready to QA test
labels 2023-01-25 22:23:10 +00:00
AliasAlreadyTaken was unassigned by flux 2023-01-25 22:23:13 +00:00
Member

this is live and appears to solve the problem - i don't see any more repeated death messages.

this is live and appears to solve the problem - i don't see any more repeated death messages.
flux closed this issue 2023-01-25 22:23:37 +00:00
Sign in to join this conversation.
No Milestone
No project
No Assignees
4 Participants
Notifications
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: your-land/bugtracker#3017
No description provided.