Queenfire234312 reports: report chat lagging bad ... #2300

New Issue

yourland-report · 2022-07-23T16:43:22Z

yourland-report commented

2022-07-23 16:43:22 +00:00

Queenfire234312 reports a bug:

report chat lagging bad

Player position:

{
	x = 2036.0830078125,
	y = 14.5,
	z = 1153.9099121094
}

Player look:

{
	x = -0.77232158184052,
	y = -0.027921639382839,
	z = 0.63461774587631
}

Player information:

{
	patch = 1,
	state = "Active",
	formspec_version = 4,
	lang_code = "",
	major = 5,
	minor = 4,
	version_string = "5.4.1",
	avg_rtt = 0.35499998927116,
	ip_version = 6,
	min_rtt = 0.13799999654293,
	max_rtt = 1.6690000295639,
	protocol_version = 39,
	min_jitter = 0,
	max_jitter = 1.5199999809265,
	avg_jitter = 0.19799998402596,
	connection_uptime = 149,
	serialization_version = 28
}

Player meta:

{
	fields = {
		played_time = "553119",
		digged_nodes = "21839",
		placed_nodes = "14379",
		died = "126",
		["stamina:level"] = "13",
		crafted = "1452",
		["stamina:poisoned"] = "no",
		inflicted_damage = "250424",
		["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}",
		["3d_armor_inventory"] = "return {\"3d_armor:helmet_crystal 1 26725\", \"3d_armor:boots_crystal 1 20100\", \"3d_armor:leggings_crystal 1 26725\", \"3d_armor:chestplate_crystal 1 26725\", \"\", \"\"}",
		partychat = "party",
		["stamina:exhaustion"] = "73.5",
		jointime = "1653939142",
		bitten = "0",
		yl_church = "return {[\"last_death\"] = {[\"x\"] = 392, [\"y\"] = -31, [\"z\"] = 23023}, [\"last_death_portal\"] = 1658161344}",
		["ocean_build.last_warning"] = "1.65812e+09",
		repellant = "0",
		hud_state = "on",
		yl_commons_thankyou = "10",
		arenalib_infobox_arenaID = "0",
		yl_commons_player_created = "1653939142",
		yl_commons_player_joined = "1658594487",
		["ocean_build.ocean_built"] = "7",
		["signslib:pos"] = "(396,-35,23112)",
		punch_count = "11776",
		xp = "34372"
	}
}

Log identifier


[MOD] yl_report log identifier = oRy76yjqpLNMFJTZSJUE6tb891GRVNp3

Profiler save:

profile-20220723T184321.json_prettyEE

Status:

# Server: version: 5.5.1-yl | game: Minetest Game | uptime: 3d 5h 31min 19s | max lag: 5.96s | clients: Therottenpotato, 1308, Queenfire234312, puppy12346, BTS-, goofykid, Ivanhoe, BurstSetucalation, Bla, puppy12342, Greater_Dog, AliasAlreadyTaken, Mielle, Service, jenda, Bailiff

Teleport command:

/teleport xyz 2036 15 1154

Compass command:

/give_compass Construction oRy76yjqpLNMFJTZSJUE6tb891GRVNp3 D2691E 2036 15 1154

Queenfire234312 reports a bug: > report chat lagging bad Player position: ``` { x = 2036.0830078125, y = 14.5, z = 1153.9099121094 } ``` Player look: ``` { x = -0.77232158184052, y = -0.027921639382839, z = 0.63461774587631 } ``` Player information: ``` { patch = 1, state = "Active", formspec_version = 4, lang_code = "", major = 5, minor = 4, version_string = "5.4.1", avg_rtt = 0.35499998927116, ip_version = 6, min_rtt = 0.13799999654293, max_rtt = 1.6690000295639, protocol_version = 39, min_jitter = 0, max_jitter = 1.5199999809265, avg_jitter = 0.19799998402596, connection_uptime = 149, serialization_version = 28 } ``` Player meta: ``` { fields = { played_time = "553119", digged_nodes = "21839", placed_nodes = "14379", died = "126", ["stamina:level"] = "13", crafted = "1452", ["stamina:poisoned"] = "no", inflicted_damage = "250424", ["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}", ["3d_armor_inventory"] = "return {\"3d_armor:helmet_crystal 1 26725\", \"3d_armor:boots_crystal 1 20100\", \"3d_armor:leggings_crystal 1 26725\", \"3d_armor:chestplate_crystal 1 26725\", \"\", \"\"}", partychat = "party", ["stamina:exhaustion"] = "73.5", jointime = "1653939142", bitten = "0", yl_church = "return {[\"last_death\"] = {[\"x\"] = 392, [\"y\"] = -31, [\"z\"] = 23023}, [\"last_death_portal\"] = 1658161344}", ["ocean_build.last_warning"] = "1.65812e+09", repellant = "0", hud_state = "on", yl_commons_thankyou = "10", arenalib_infobox_arenaID = "0", yl_commons_player_created = "1653939142", yl_commons_player_joined = "1658594487", ["ocean_build.ocean_built"] = "7", ["signslib:pos"] = "(396,-35,23112)", punch_count = "11776", xp = "34372" } } ``` Log identifier ``` [MOD] yl_report log identifier = oRy76yjqpLNMFJTZSJUE6tb891GRVNp3 ``` Profiler save: ``` profile-20220723T184321.json_prettyEE ``` Status: ``` # Server: version: 5.5.1-yl | game: Minetest Game | uptime: 3d 5h 31min 19s | max lag: 5.96s | clients: Therottenpotato, 1308, Queenfire234312, puppy12346, BTS-, goofykid, Ivanhoe, BurstSetucalation, Bla, puppy12342, Greater_Dog, AliasAlreadyTaken, Mielle, Service, jenda, Bailiff ``` Teleport command: ``` /teleport xyz 2036 15 1154 ``` Compass command: ``` /give_compass Construction oRy76yjqpLNMFJTZSJUE6tb891GRVNp3 D2691E 2036 15 1154 ```

AliasAlreadyTaken was assigned by yourland-report

2022-07-23 16:43:22 +00:00

flux added the

1. kind/other

3. source/lag

labels 2022-07-23 17:39:01 +00:00

flux commented

2022-07-23 17:41:59 +00:00

i've noticed this on and off recently, where the server has really low reported lag, but it still takes forever for chat or the world to respond (outside of client-side prediction). this makes me think the source is a network issue. are we getting DOS'ed again, but the "hacker" isn't even getting into the game?

AliasAlreadyTaken commented

2022-08-05 03:34:54 +00:00

Not solved by your-land/administration#153

We took those lags with us.

Not solved by https://gitea.your-land.de/your-land/administration/issues/153 We took those lags with us.

flux commented

2022-08-05 03:47:15 +00:00

the migration to the new server helped a lot. however, we've discovered a new, weirder species of lag. more research is needed, eventually i'll come up w/ a pcap script and some mechanism to toggle it, so i can see what's actually going on.

the source is related to (1) the sheer quantity of players we have on the server (2) the number of packets that have to be exchanged between client and server. my feeling is that the game isn't prioritizing packets correctly, resulting in some players getting the info they need in order to have have a smooth response w/ the server, and others not getting that that data for arbitrary reasons.

the migration to the new server helped *a lot*. however, we've discovered a new, weirder species of lag. more research is needed, eventually i'll come up w/ a pcap script and some mechanism to toggle it, so i can see what's actually going on. the source is related to (1) the sheer quantity of players we have on the server (2) the number of packets that have to be exchanged between client and server. my feeling is that the game isn't prioritizing packets correctly, resulting in some players getting the info they need in order to have have a smooth response w/ the server, and others not getting that that data for arbitrary reasons.

AliasAlreadyTaken commented

2022-08-05 04:02:42 +00:00

To infinity ... and beyond!

I'll add verbose logging upon next server restart. There's a way to see how many packets were sent or similar.

To infinity ... and beyond! I'll add verbose logging upon next server restart. There's a way to see how many packets were sent or similar.

flux commented

2022-08-05 04:22:46 +00:00

To infinity ... and beyond!

I'll add verbose logging upon next server restart. There's a way to see how many packets were sent or similar.

i'm not sure whether i trust minetest's internal logging more than a proper record of actual packets. player privacy is important - but it's easy enough to obfuscate player IPs using either method, and i intend to incorporate that.

setting the log level beyond "action" will absolutely cause more lag on the server. packet capturing is preferable, imo.

> To infinity ... and beyond! > > I'll add verbose logging upon next server restart. There's a way to see how many packets were sent or similar. i'm not sure whether i trust minetest's internal logging more than a proper record of actual packets. player privacy is important - but it's easy enough to obfuscate player IPs using either method, and i intend to incorporate that. setting the log level beyond "action" will absolutely cause more lag on the server. packet capturing is preferable, imo.

flux commented

2022-08-05 04:26:29 +00:00

setting the log level beyond "action" will absolutely cause more lag on the server.

one of my early suspects about the network lag was whether we were logging too much stuff - so much that the logging was blocking real processing from going on. but i checked minetst.settings:get("debug_log_level") and discovered it's currently at "action", which should probably be fine

> setting the log level beyond "action" will absolutely cause more lag on the server. one of my early suspects about the network lag was whether we were logging too much stuff - so much that the logging was blocking real processing from going on. but i checked `minetst.settings:get("debug_log_level")` and discovered it's currently at `"action"`, which should probably be fine

flux commented

2022-09-11 18:57:48 +00:00

this was due to smartshops sending a huge quantity of detached inventory updates to all players whenever they loaded, and has been fixed and is live.

flux closed this issue

2022-09-11 18:57:48 +00:00

flux added the

5. result/fixed

label 2022-09-11 18:57:56 +00:00

Sign in to join this conversation.