whosit reports: led_marquee: seems to ignore m ... #6351

New Issue

yourland-report · 2024-02-25T23:55:16Z

yourland-report commented

2024-02-25 23:55:16 +00:00

whosit reports a bug:

led_marquee: seems to ignore most of digiline messages during moderate/high lag

Player position:

{
	z = -2774.8310546875,
	x = 2972.1750488281,
	y = 5.5
}

Player look:

{
	z = -0.28536394238472,
	x = -0.95784556865692,
	y = 0.033155180513859
}

Player information:

{
	minor = 8,
	state = "Active",
	major = 5,
	max_rtt = 1.3309999704361,
	ip_version = 6,
	min_rtt = 0.041999999433756,
	avg_rtt = 0.043999999761581,
	min_jitter = 0,
	max_jitter = 1.25,
	avg_jitter = 0.0010000020265579,
	connection_uptime = 433,
	serialization_version = 29,
	patch = 0,
	protocol_version = 42,
	version_string = "5.8.0",
	formspec_version = 7,
	lang_code = ""
}

Player meta:

{
	fields = {
		["petz:lycanthropy"] = "1",
		arenalib_infobox_arenaID = "0",
		["stamina:level"] = "10",
		["stamina:poisoned"] = "no",
		["stamina:exhaustion"] = "43",
		["petz:old_override_table"] = "return {[\"new_move\"] = true, [\"sneak\"] = true, [\"sneak_glitch\"] = false, [\"jump\"] = 1.5, [\"speed\"] = 2, [\"gravity\"] = 1}",
		["petz:pre_werewolf_animation"] = "return {[\"model\"] = \"skinsdb_3d_armor_character_5.b3d\", [\"animation_speed\"] = 30, [\"textures\"] = {\"blank.png\", \"character.warrior_m1.png\", \"3d_armor_trans.png^shields_shield_crystal.png^3d_armor_chestplate_crystal.png^3d_armor_boots_crystal.png^3d_armor_leggings_crystal.png\", \"wine_wine_glass.png\"}, [\"animation\"] = \"sit\"}",
		xp = "206710",
		["petz:werewolf_clan_idx"] = "3",
		yl_church = "return {[\"last_death_portal\"] = 1708461659, [\"last_death\"] = {[\"x\"] = 3759, [\"y\"] = 78, [\"z\"] = 423}, [\"last_heal\"] = 1708284048}",
		["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}",
		yl_commons_player_created = "1615221933",
		["3d_armor_inventory"] = "return {\"shields:shield_crystal 1 21580\", \"3d_armor:chestplate_crystal 1 21580\", \"\", \"3d_armor:boots_crystal 1 21980\", \"3d_armor:leggings_crystal 1 21580\", \"\"}",
		punch_count = "41122",
		xp_redo_hud_color = "0x0000ff",
		lagometer = "1",
		hud_state = "on",
		bitten = "0",
		crafted = "82661",
		["signslib:pos"] = "(2183,22,1163)",
		yl_commons_player_joined = "1708904896",
		yl_commons_thankyou = "257",
		jointime = "1615221933",
		["petz:werewolf_vignette_id"] = "20",
		inflicted_damage = "633944",
		partychat = "party",
		played_time = "8615397",
		digged_nodes = "343497",
		placed_nodes = "99061",
		died = "785",
		["petz:werewolf"] = "1",
		repellant = "0"
	}
}

Log identifier


[MOD] yl_report log identifier = dmKuqtlmra6rlfUB8wV90pHWpdq0Tuhe

Profiler save:

profile-20240225T235516.json_prettyEE

Status:

# Server: version: 5.7.0-yl-thx-tmm | game: Minetest Game | uptime: 1d 4h 45min 25s | max lag: 0.828s | clients (26/52): AliasAlreadyTaken, AspireMint, Azelf, Bailiff, betzi, Chache, DanteLives, daydream, DragonWrangler1, Empempires, flux, Hecate, Historia_reiss, jackofthebean000, JeCel, Jennison, LeetPeet, MineWorlds, MrClean, poppyasdan, RileyB, Service, tagtraum, testmineweirdo, UnchainedFen, whosit

Teleport command:

/teleport xyz 2972 6 -2775

Compass command:

/give_compass Construction dmKuqtlmra6rlfUB8wV90pHWpdq0Tuhe D2691E 2972 6 -2775

whosit reports a bug: > led_marquee: seems to ignore most of digiline messages during moderate/high lag Player position: ``` { z = -2774.8310546875, x = 2972.1750488281, y = 5.5 } ``` Player look: ``` { z = -0.28536394238472, x = -0.95784556865692, y = 0.033155180513859 } ``` Player information: ``` { minor = 8, state = "Active", major = 5, max_rtt = 1.3309999704361, ip_version = 6, min_rtt = 0.041999999433756, avg_rtt = 0.043999999761581, min_jitter = 0, max_jitter = 1.25, avg_jitter = 0.0010000020265579, connection_uptime = 433, serialization_version = 29, patch = 0, protocol_version = 42, version_string = "5.8.0", formspec_version = 7, lang_code = "" } ``` Player meta: ``` { fields = { ["petz:lycanthropy"] = "1", arenalib_infobox_arenaID = "0", ["stamina:level"] = "10", ["stamina:poisoned"] = "no", ["stamina:exhaustion"] = "43", ["petz:old_override_table"] = "return {[\"new_move\"] = true, [\"sneak\"] = true, [\"sneak_glitch\"] = false, [\"jump\"] = 1.5, [\"speed\"] = 2, [\"gravity\"] = 1}", ["petz:pre_werewolf_animation"] = "return {[\"model\"] = \"skinsdb_3d_armor_character_5.b3d\", [\"animation_speed\"] = 30, [\"textures\"] = {\"blank.png\", \"character.warrior_m1.png\", \"3d_armor_trans.png^shields_shield_crystal.png^3d_armor_chestplate_crystal.png^3d_armor_boots_crystal.png^3d_armor_leggings_crystal.png\", \"wine_wine_glass.png\"}, [\"animation\"] = \"sit\"}", xp = "206710", ["petz:werewolf_clan_idx"] = "3", yl_church = "return {[\"last_death_portal\"] = 1708461659, [\"last_death\"] = {[\"x\"] = 3759, [\"y\"] = 78, [\"z\"] = 423}, [\"last_heal\"] = 1708284048}", ["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}", yl_commons_player_created = "1615221933", ["3d_armor_inventory"] = "return {\"shields:shield_crystal 1 21580\", \"3d_armor:chestplate_crystal 1 21580\", \"\", \"3d_armor:boots_crystal 1 21980\", \"3d_armor:leggings_crystal 1 21580\", \"\"}", punch_count = "41122", xp_redo_hud_color = "0x0000ff", lagometer = "1", hud_state = "on", bitten = "0", crafted = "82661", ["signslib:pos"] = "(2183,22,1163)", yl_commons_player_joined = "1708904896", yl_commons_thankyou = "257", jointime = "1615221933", ["petz:werewolf_vignette_id"] = "20", inflicted_damage = "633944", partychat = "party", played_time = "8615397", digged_nodes = "343497", placed_nodes = "99061", died = "785", ["petz:werewolf"] = "1", repellant = "0" } } ``` Log identifier ``` [MOD] yl_report log identifier = dmKuqtlmra6rlfUB8wV90pHWpdq0Tuhe ``` Profiler save: ``` profile-20240225T235516.json_prettyEE ``` Status: ``` # Server: version: 5.7.0-yl-thx-tmm | game: Minetest Game | uptime: 1d 4h 45min 25s | max lag: 0.828s | clients (26/52): AliasAlreadyTaken, AspireMint, Azelf, Bailiff, betzi, Chache, DanteLives, daydream, DragonWrangler1, Empempires, flux, Hecate, Historia_reiss, jackofthebean000, JeCel, Jennison, LeetPeet, MineWorlds, MrClean, poppyasdan, RileyB, Service, tagtraum, testmineweirdo, UnchainedFen, whosit ``` Teleport command: ``` /teleport xyz 2972 6 -2775 ``` Compass command: ``` /give_compass Construction dmKuqtlmra6rlfUB8wV90pHWpdq0Tuhe D2691E 2972 6 -2775 ```

AliasAlreadyTaken was assigned by yourland-report

2024-02-25 23:55:16 +00:00

AliasAlreadyTaken added the

1. kind/bug

4. step/needs confirmation

3. source/lag

labels 2024-02-26 01:57:15 +00:00

flux commented

2024-02-26 04:41:17 +00:00

well, most mesecons/digilines signals can be lost when there's "high lag", which has been almost constant lately whenever there's more than 10 players on the server. i think i mentioned somewhere that i suspect the reason for that is spawnit, but it's not showing up in any of the spawnit metrics. 1.1.123 will update spawnit, and i'll be able to toggle a global switch that will let me verify that assumption. unfortunately the jit usage mod crashes things.

i also don't have any suspicions of what exactly would be causing the issue, if it's in the spawnit code. spawnit was very carefully designed to not cause performance problems with multiple players. however, my ability to test 20-30-40 players locally is limited. this didn't show up when i was using a bunch of headless clients.

well, most mesecons/digilines signals can be lost when there's "high lag", which has been almost constant lately whenever there's more than 10 players on the server. i think i mentioned somewhere that i suspect the reason for that is spawnit, but it's not showing up in any of the spawnit metrics. 1.1.123 will update spawnit, and i'll be able to toggle a global switch that will let me verify that assumption. unfortunately the jit usage mod crashes things. i also don't have any suspicions of what exactly would be causing the issue, if it's in the spawnit code. spawnit was very carefully designed to not cause performance problems with multiple players. however, my ability to *test* 20-30-40 players locally is limited. this didn't show up when i was using a bunch of headless clients.

AliasAlreadyTaken commented

2024-02-26 11:27:33 +00:00

Please add any debug or maybe even a live debug option to the mod as you see fit. spawnit occasionally grabs the whole CPU, means: All threads

Could it be that serialization is slow?

Also your-land/bugtracker#6357

Also, wouldn't digilines, pipeworks and mesecons be good for async? Especially where larger machines need to be simulated, without touching stuff that is not available there?

Could we add logging to digilines to see where stuff gets lost?

Please add any debug or maybe even a live debug option to the mod as you see fit. spawnit occasionally grabs the whole CPU, means: All threads Could it be that serialization is slow? Also your-land/bugtracker#6357 Also, wouldn't digilines, pipeworks and mesecons be good for async? Especially where larger machines need to be simulated, without touching stuff that is not available there? Could we add logging to digilines to see where stuff gets lost?

tour commented

2024-02-26 23:05:44 +00:00

I guess I know where the digiline stuff is lost:

mesecons maintains a so called actionQueue where they store stuff they want to execute in the next globalstep after time seconds (https://github.com/minetest-mods/mesecons/blob/master/mesecons/actionqueue.lua, the code is well-commented).

Luacontrollers do not send out digiline messages immediately, they add it to the queue (59780437f2/mesecons_luacontroller/init.lua (L473)), so the digiline:send() will be called in the next globalstep.

That is, where mesecons_debug comes in. If it decides that lag is too high, it prevents the action from being added to the queue (792d266c89/overrides/mesecons_queue.lua (L38)). That's where the message is lost.
Note that you can loose luacontroller interrupts in the same way.

Maybe offtopic:
IMO mesecons_debug is doing a bad job here:
I can use my penalty-free time to fill the queue with heavy code. Even if I get penalty later, all my code in the queue will still be executed. If I fill my queue with luac interrupts, I can even create lag at any time I want.

I guess I know where the digiline stuff is lost: mesecons maintains a so called actionQueue where they store stuff they want to execute in the next globalstep after `time` seconds (https://github.com/minetest-mods/mesecons/blob/master/mesecons/actionqueue.lua, the code is well-commented). Luacontrollers do not send out digiline messages immediately, they add it to the queue (https://github.com/minetest-mods/mesecons/blob/59780437f2f47954b84122a4f1286e0c5b3bd168/mesecons_luacontroller/init.lua#L473), so the digiline:send() will be called in the next globalstep. That is, where mesecons_debug comes in. If it decides that lag is too high, it prevents the action from being added to the queue (https://github.com/minetest-monitoring/mesecons_debug/blob/792d266c892addc073f0c83ee818566c878458e5/overrides/mesecons_queue.lua#L38). That's where the message is lost. Note that you can loose luacontroller interrupts in the same way. Maybe offtopic: IMO mesecons_debug is doing a bad job here: I can use my penalty-free time to fill the queue with heavy code. Even if I get penalty later, all my code in the queue will still be executed. If I fill my queue with luac interrupts, I can even create lag at any time I want.

👀 1

whosit commented

2024-02-27 08:52:58 +00:00

Today we had only 4 players online and I decided to try out my pong machine:

Display worked really strange: it works fine for a couple of frames, then gets frozen for a minute, then starts "fast-forwarding" everything at extreme speeds... While it's fast-forwarding, I can't even toggle a lever...

Seems consistent with queue filling up before ratelimiter hits? The effect that tour wrote about?

And while all this was happening, mesecons_hud was showing "penalty: 0.0s"...

(I have 20MB video showing this, idk if I should zip and put it here)

Today we had only 4 players online and I decided to try out my pong machine: ![image](/attachments/9062f123-e3ad-47ad-a130-333e64eeb8bf) Display worked really strange: it works fine for a couple of frames, then gets frozen for a minute, then starts "fast-forwarding" everything at extreme speeds... While it's fast-forwarding, I can't even toggle a lever... Seems consistent with queue filling up before ratelimiter hits? The effect that tour wrote about? And while all this was happening, mesecons_hud was showing "penalty: 0.0s"... (I have 20MB video showing this, idk if I should zip and put it here)

image.png

114 KiB

flux commented

2024-03-05 04:32:22 +00:00

Today we had only 4 players online and I decided to try out my pong machine:

question number one: was the entire machine within a single mapblock? machine logic breaks in a deep way if that's not the case.

> Today we had only 4 players online and I decided to try out my pong machine: question number one: was the entire machine within a single mapblock? machine logic breaks in a deep way if that's not the case.

whosit commented

2024-03-05 04:53:38 +00:00

Screen edge is peeking out:

(I didn't know this XD probably miscalculated that because there was no good mapblock display?)

But it was working on test just fine (i.e. in low lag) at some point in the past...

Rest of it is just this:

Screen edge is peeking out: ![image](/attachments/78a10e3d-e66b-4d08-953a-a7829e4abb46) (I didn't know this XD probably miscalculated that because there was no good mapblock display?) But it was working on test just fine (i.e. in low lag) at some point in the past... Rest of it is just this: ![image](/attachments/fad00b3c-c240-4aa4-bf60-37a44b4d32a0)

image.png

104 KiB

image.png

120 KiB

flux commented

2024-03-08 02:25:14 +00:00

Also, wouldn't digilines, pipeworks and mesecons be good for async? Especially where larger machines need to be simulated, without touching stuff that is not available there?

theoretically, yes, absolutely. but async is new, and so far as i know, spawnit is really the only thing that's load-testing that currently (though i think there's some stuff in the works for plantlife). and the results are not super encouraging. see #6417 for more discussion about that issue.

> Also, wouldn't digilines, pipeworks and mesecons be good for async? Especially where larger machines need to be simulated, without touching stuff that is not available there? theoretically, yes, absolutely. but async is new, and so far as i know, spawnit is really the only thing that's load-testing that currently (though i think there's some stuff in the works for plantlife). and the results are not super encouraging. see #6417 for more discussion about that issue.

👍 1

Sign in to join this conversation.