Player died, other player looted the bones in less than 15 minutes #3082

Closed
opened 2022-11-19 07:56:22 +00:00 by AliasAlreadyTaken · 8 comments

From first glance, Koolk7474mine died from fall damage near the Battle Royale Arena. Only seconds after the bones were created, player zanezand got hold of the items.

Parts of the death:

2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added mobs:lava_orb to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added shields:shield_crystal 1 23640 to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:helmet_crystal 1 23640 to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:leggings_crystal 1 24790 to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:chestplate_crystal 1 24790 to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:boots_crystal 1 30082 to bones @ (-29016,15,-30705)
2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine dies at (-29016,15,-30705) and their inventory goes to bones.
2022-11-19 07:32:19: ACTION[Server]: [MOD] xp_redo: Koolk7474mine lost 66 XP!
2022-11-19 07:32:19: ACTION[Server]: [MOD] xp_redo: Reason of death of Koolk7474mine: return {["type"] = "fall", ["from"] = "engine"}

What's this?

2022-11-19 07:32:20: ACTION[Server]: [yl_commons] Koolk7474mine is not immune to fall damage
2022-11-19 07:32:20: ACTION[Server]: Moving Koolk7474mine to static spawnpoint at (2002,15,1154)
2022-11-19 07:32:20: ACTION[Server]: Koolk7474mine respawns at (2002,15,1154)

The log says Koolk7474mine went to the priest and took the items from the bones.

2022-11-19 07:32:35: ACTION[Server]: zanezand activates 
2022-11-19 07:32:42: ACTION[Server]: Koolk7474mine right-clicks object 1558: LuaEntitySAO "yl_speak_up:human" at (1981,15,1216)
2022-11-19 07:32:50: ACTION[Server]: player Koolk7474mine (id=5560, hp=20) punched player zanezand (id=60425, hp=12), damage=0 (handled by Lua)
2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes shields:shield_crystal 1 23640 from bones @ (-29016,15,-30705)
2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:helmet_crystal 1 23640 from bones @ (-29016,15,-30705)
2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:leggings_crystal 1 24790 from bones @ (-29016,15,-30705)
2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:chestplate_crystal 1 24790 from bones @ (-29016,15,-30705)
2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:boots_crystal 1 30082 from bones @ (-29016,15,-30705)

How did the items then end up with zanezand? zanezand is a new player, nothing in the log indicates where he would have gotten those items from. Still, he suddenly "had" them. He took them from the bones, which were generated two seconds earlier. But how? They should have been "fresh" ?

2022-11-19 07:32:52: ACTION[Server]: [yl_commons] zanezand moves "shields:shield_crystal 1 23640" to {"name":"zanezand","type":"player"} [main]
2022-11-19 07:32:52: ACTION[Server]: [bones] zanezand takes shields:shield_crystal 1 23640 from bones @ (-29016,15,-30705)
2022-11-19 07:32:54: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:helmet_crystal 1 23640" to {"name":"zanezand","type":"player"} [main]
2022-11-19 07:32:54: ACTION[Server]: [bones] zanezand takes 3d_armor:helmet_crystal 1 23640 from bones @ (-29016,15,-30705)
2022-11-19 07:32:54: ACTION[Server]: [yl_commons] "Koolk7474mine" dropped "default:coal_lump 4" at pos "(-29016,15.5,-30705)"
2022-11-19 07:32:54: ACTION[Server]: [yl_commons] Koolk7474mine takes "default:coal_lump 4" from {"name":"Koolk7474mine","type":"player"} [main]
2022-11-19 07:32:54: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:leggings_crystal 1 24790" to {"name":"zanezand","type":"player"} [main]
2022-11-19 07:32:54: ACTION[Server]: [bones] zanezand takes 3d_armor:leggings_crystal 1 24790 from bones @ (-29016,15,-30705)
2022-11-19 07:32:55: ACTION[Server]: Koolk7474mine uses default:book_written, pointing at [object 2584]
2022-11-19 07:32:56: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:chestplate_crystal 1 24790" to {"name":"zanezand","type":"player"} [main]
2022-11-19 07:32:56: ACTION[Server]: [bones] zanezand takes 3d_armor:chestplate_crystal 1 24790 from bones @ (-29016,15,-30705)
2022-11-19 07:32:57: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:boots_crystal 1 30082" to {"name":"zanezand","type":"player"} [main]
2022-11-19 07:32:57: ACTION[Server]: [bones] zanezand takes 3d_armor:boots_crystal 1 30082 from bones @ (-29016,15,-30705)

I tried to kill Boris at the location and grab the bones contents with Violetta. No chance.

From first glance, Koolk7474mine died from fall damage near the Battle Royale Arena. Only seconds after the bones were created, player zanezand got hold of the items. Parts of the death: ``` 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added mobs:lava_orb to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added shields:shield_crystal 1 23640 to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:helmet_crystal 1 23640 to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:leggings_crystal 1 24790 to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:chestplate_crystal 1 24790 to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine added 3d_armor:boots_crystal 1 30082 to bones @ (-29016,15,-30705) 2022-11-19 07:32:19: ACTION[Server]: [bones] Koolk7474mine dies at (-29016,15,-30705) and their inventory goes to bones. 2022-11-19 07:32:19: ACTION[Server]: [MOD] xp_redo: Koolk7474mine lost 66 XP! 2022-11-19 07:32:19: ACTION[Server]: [MOD] xp_redo: Reason of death of Koolk7474mine: return {["type"] = "fall", ["from"] = "engine"} ``` What's this? ``` 2022-11-19 07:32:20: ACTION[Server]: [yl_commons] Koolk7474mine is not immune to fall damage 2022-11-19 07:32:20: ACTION[Server]: Moving Koolk7474mine to static spawnpoint at (2002,15,1154) 2022-11-19 07:32:20: ACTION[Server]: Koolk7474mine respawns at (2002,15,1154) ``` The log says Koolk7474mine went to the priest and took the items from the bones. ``` 2022-11-19 07:32:35: ACTION[Server]: zanezand activates 2022-11-19 07:32:42: ACTION[Server]: Koolk7474mine right-clicks object 1558: LuaEntitySAO "yl_speak_up:human" at (1981,15,1216) 2022-11-19 07:32:50: ACTION[Server]: player Koolk7474mine (id=5560, hp=20) punched player zanezand (id=60425, hp=12), damage=0 (handled by Lua) 2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes shields:shield_crystal 1 23640 from bones @ (-29016,15,-30705) 2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:helmet_crystal 1 23640 from bones @ (-29016,15,-30705) 2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:leggings_crystal 1 24790 from bones @ (-29016,15,-30705) 2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:chestplate_crystal 1 24790 from bones @ (-29016,15,-30705) 2022-11-19 07:32:50: ACTION[Server]: [bones] Koolk7474mine takes 3d_armor:boots_crystal 1 30082 from bones @ (-29016,15,-30705) ``` How did the items then end up with zanezand? zanezand is a new player, nothing in the log indicates where he would have gotten those items from. Still, he suddenly "had" them. He took them from the bones, which were generated two seconds earlier. But how? They should have been "fresh" ? ``` 2022-11-19 07:32:52: ACTION[Server]: [yl_commons] zanezand moves "shields:shield_crystal 1 23640" to {"name":"zanezand","type":"player"} [main] 2022-11-19 07:32:52: ACTION[Server]: [bones] zanezand takes shields:shield_crystal 1 23640 from bones @ (-29016,15,-30705) 2022-11-19 07:32:54: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:helmet_crystal 1 23640" to {"name":"zanezand","type":"player"} [main] 2022-11-19 07:32:54: ACTION[Server]: [bones] zanezand takes 3d_armor:helmet_crystal 1 23640 from bones @ (-29016,15,-30705) 2022-11-19 07:32:54: ACTION[Server]: [yl_commons] "Koolk7474mine" dropped "default:coal_lump 4" at pos "(-29016,15.5,-30705)" 2022-11-19 07:32:54: ACTION[Server]: [yl_commons] Koolk7474mine takes "default:coal_lump 4" from {"name":"Koolk7474mine","type":"player"} [main] 2022-11-19 07:32:54: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:leggings_crystal 1 24790" to {"name":"zanezand","type":"player"} [main] 2022-11-19 07:32:54: ACTION[Server]: [bones] zanezand takes 3d_armor:leggings_crystal 1 24790 from bones @ (-29016,15,-30705) 2022-11-19 07:32:55: ACTION[Server]: Koolk7474mine uses default:book_written, pointing at [object 2584] 2022-11-19 07:32:56: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:chestplate_crystal 1 24790" to {"name":"zanezand","type":"player"} [main] 2022-11-19 07:32:56: ACTION[Server]: [bones] zanezand takes 3d_armor:chestplate_crystal 1 24790 from bones @ (-29016,15,-30705) 2022-11-19 07:32:57: ACTION[Server]: [yl_commons] zanezand moves "3d_armor:boots_crystal 1 30082" to {"name":"zanezand","type":"player"} [main] 2022-11-19 07:32:57: ACTION[Server]: [bones] zanezand takes 3d_armor:boots_crystal 1 30082 from bones @ (-29016,15,-30705) ``` I tried to kill Boris at the location and grab the bones contents with Violetta. No chance.
AliasAlreadyTaken added the
1. kind/bug
label 2022-11-19 07:56:26 +00:00
flux added the
2. prio/critical
label 2022-11-19 15:47:22 +00:00
Member

did the items get duped?

now, for things to get even weirder: here's what the rollback logs say (times are in UTC)

Checking (-29016,14,-30705) ...
2022-10-24 17:34:50Z: (-29016,15,-30704) player:Koolk7474 bones:bones -> air 2240597 seconds ago.
2022-11-11 00:23:34Z: (-29016,15,-30704) player:Minetest13 bones:bones -> air 747273 seconds ago.
2022-11-11 21:45:50Z: (-29017,15,-30704) player:etherflows bones:bones -> air 670337 seconds ago.
2022-11-19 07:32:52Z: (0,0,0) player:zanezand  ->  30315 seconds ago.
2022-11-19 07:32:54Z: (0,0,0) player:zanezand  ->  30313 seconds ago.
2022-11-19 07:32:54Z: (0,0,0) player:zanezand  ->  30313 seconds ago.
2022-11-19 07:32:56Z: (0,0,0) player:zanezand  ->  30311 seconds ago.
2022-11-19 07:32:57Z: (0,0,0) player:zanezand  ->  30310 seconds ago.
2022-11-19 07:32:57Z: (-29016,15,-30705) player:zanezand bones:bones -> air 30310 seconds ago.
2022-11-19 07:54:52Z: (-29015,15,-30705) player:Boris bones:bones -> air 28995 seconds ago.
2022-11-19 07:55:37Z: (-29016,15,-30706) player:Boris air -> bones:bones 28950 seconds ago.

according to this, Koolk7474 removed bones from that spot almost 26 days ago, and not sooner. and 2 other players removed bones from that spot as well, before zanezand came along.

what???

2022-11-19 07:32:20: ACTION[Server]: [yl_commons] Koolk7474mine is not immune to fall damage

that's an artifact of the fix for #720. here it means they got their hp reset to 20. it probably doesn't need to be logged.

did the items get duped? now, for things to get even weirder: here's what the rollback logs say (times are in UTC) ``` Checking (-29016,14,-30705) ... 2022-10-24 17:34:50Z: (-29016,15,-30704) player:Koolk7474 bones:bones -> air 2240597 seconds ago. 2022-11-11 00:23:34Z: (-29016,15,-30704) player:Minetest13 bones:bones -> air 747273 seconds ago. 2022-11-11 21:45:50Z: (-29017,15,-30704) player:etherflows bones:bones -> air 670337 seconds ago. 2022-11-19 07:32:52Z: (0,0,0) player:zanezand -> 30315 seconds ago. 2022-11-19 07:32:54Z: (0,0,0) player:zanezand -> 30313 seconds ago. 2022-11-19 07:32:54Z: (0,0,0) player:zanezand -> 30313 seconds ago. 2022-11-19 07:32:56Z: (0,0,0) player:zanezand -> 30311 seconds ago. 2022-11-19 07:32:57Z: (0,0,0) player:zanezand -> 30310 seconds ago. 2022-11-19 07:32:57Z: (-29016,15,-30705) player:zanezand bones:bones -> air 30310 seconds ago. 2022-11-19 07:54:52Z: (-29015,15,-30705) player:Boris bones:bones -> air 28995 seconds ago. 2022-11-19 07:55:37Z: (-29016,15,-30706) player:Boris air -> bones:bones 28950 seconds ago. ``` according to this, Koolk7474 removed bones from that spot almost 26 days ago, and not sooner. and 2 other players removed bones from that spot as well, before zanezand came along. what??? > 2022-11-19 07:32:20: ACTION[Server]: [yl_commons] Koolk7474mine is not immune to fall damage that's an artifact of the fix for #720. here it means they got their hp reset to 20. it probably doesn't need to be logged.
flux added the
3. source/unknown
label 2022-11-20 21:16:24 +00:00
Member

i reviewed the bones logic, and there was an error which would result in the bones becoming "old" whenever the timer triggers, no matter how much time has elapsed. i'm not sure why a timer would trigger early though.

i've reworked the logic so that the bones only become old when wall-time says they should: 9cd73daa90

also, bones now log when they become old, in case there's some other issue going on here which allowed a player to loot another's fresh bones.

i reviewed the bones logic, and there was an error which would result in the bones becoming "old" whenever the timer triggers, no matter how much time has elapsed. i'm not sure why a timer would trigger early though. i've reworked the logic so that the bones only become old when wall-time says they should: https://github.com/fluxionary/minetest-bones_redo/commit/9cd73daa907e679d380613ede1e01780eb3d689c also, bones now log when they become old, in case there's some other issue going on here which allowed a player to loot another's fresh bones.
flux added the
3. source/mod upstream
4. step/ready to QA test
labels 2023-06-15 16:44:17 +00:00
Member

hm. to QA test this, the following snippet will help:

local bones_pos = ...  -- location of the fresh bones node
minetest.get_node_timer(bones_pos):set(1, 1)

before this fix, this will cause a fresh bones node to become old immediately. now, it will reset the timer and continue waiting.

hm. to QA test this, the following snippet will help: ```lua local bones_pos = ... -- location of the fresh bones node minetest.get_node_timer(bones_pos):set(1, 1) ``` before this fix, this will cause a fresh bones node to become old immediately. now, it will reset the timer and continue waiting.
AliasAlreadyTaken added this to the 1.1.120 milestone 2023-06-15 19:47:33 +00:00
Author
Owner

Apparently we're on some outdated bones branch. We should switch to flux' bones mod: https://github.com/fluxionary/minetest-bones_redo

Unfortunately there is already a yl_stable branch, so we can't add our own.

Apparently we're on some outdated bones branch. We should switch to flux' bones mod: https://github.com/fluxionary/minetest-bones_redo Unfortunately there is already a yl_stable branch, so we can't add our own.
Author
Owner

hm. to QA test this, the following snippet will help:

local bones_pos = ...  -- location of the fresh bones node
minetest.get_node_timer(bones_pos):set(1, 1)

before this fix, this will cause a fresh bones node to become old immediately. now, it will reset the timer and continue waiting.

This makes the bones near-instantly old on the testserver. We're on https://gitea.your-land.de/your-land/minetest-bones_redo.git commit 05f96940000ad5fe994f93bb8e8ba2b6a5cfbc3d of origin/yl_stable

If you're right and this is a surefire way to prove the issue is still there, then the Issue is NOK. Otherwise I'd say we need to wait for the issue happening again on main.

> hm. to QA test this, the following snippet will help: > > ```lua > local bones_pos = ... -- location of the fresh bones node > minetest.get_node_timer(bones_pos):set(1, 1) > ``` > > before this fix, this will cause a fresh bones node to become old immediately. now, it will reset the timer and continue waiting. This makes the bones near-instantly old on the testserver. We're on https://gitea.your-land.de/your-land/minetest-bones_redo.git commit 05f96940000ad5fe994f93bb8e8ba2b6a5cfbc3d of origin/yl_stable If you're right and this is a surefire way to prove the issue is still there, then the Issue is NOK. Otherwise I'd say we need to wait for the issue happening again on main.
AliasAlreadyTaken added the
ugh/QA NOK
ugh/QA main
labels 2023-09-03 23:04:07 +00:00
Member

Unfortunately there is already a yl_stable branch, so we can't add our own.

whoops, removed that

> Unfortunately there is already a yl_stable branch, so we can't add our own. whoops, removed that
Member

If you're right and this is a surefire way to prove the issue is still there, then the Issue is NOK. Otherwise I'd say we need to wait for the issue happening again on main.

yeah, we probably need to switch to use my repo as the new upstream. i think the current situation is a result of me trying to push changes from my repo directly into yl_stable on gitea at some point in the past.

> If you're right and this is a surefire way to prove the issue is still there, then the Issue is NOK. Otherwise I'd say we need to wait for the issue happening again on main. yeah, we probably need to switch to use my repo as the new upstream. i think the current situation is a result of me trying to push changes from my repo directly into yl_stable on gitea at some point in the past.
Author
Owner
We switched to https://github.com/fluxionary/minetest-bones_redo as upstream :)
AliasAlreadyTaken added
5. result/fixed
and removed
4. step/ready to QA test
ugh/QA NOK
labels 2023-11-27 01:27:49 +00:00
Sign in to join this conversation.
No Milestone
No project
No Assignees
2 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#3082
No description provided.