your-land/bugtracker
your-land
/
bugtracker
44
20
Code Issues 2.4k Projects 2 Wiki

AliasAlreadyTaken reports: Builders flight globalstep1 le ... #5747

New Issue
Closed
opened 2023-12-19 12:25:45 +00:00 by yourland-report · 10 comments
yourland-report commented 2023-12-19 12:25:45 +00:00
Member
Copy Link

AliasAlreadyTaken reports a bug:

Builders flight globalstep1 leads to lag of +0.5 seconds on one player (Ecklair), but not on others (Boris)

Player position:

{
	x = 2042.919921875,
	y = 15.5,
	z = 1226.5209960938
}

Player look:

{
	x = 0.034909933805466,
	y = -0.36617639660835,
	z = 0.92989039421082
}

Player information:

{
	lang_code = "de",
	version_string = "5.8.0",
	ip_version = 6,
	min_rtt = 0.014999999664724,
	avg_rtt = 0.018999999389052,
	min_jitter = 0,
	max_jitter = 0.56299996376038,
	avg_jitter = 0,
	connection_uptime = 34042,
	serialization_version = 29,
	patch = 0,
	formspec_version = 7,
	max_rtt = 0.60000002384186,
	state = "Active",
	major = 5,
	minor = 8,
	protocol_version = 42
}

Player meta:

{
	fields = {
		played_time = "97207308",
		digged_nodes = "140492",
		placed_nodes = "181872",
		died = "1591",
		crafted = "4788",
		["ocean_build.last_warning"] = "1.67421e+09",
		["ocean_build.forbidden"] = "true",
		["ocean_build.ocean_built"] = "12",
		xp_redo_hud_color = "0xFFFF00",
		partychat = "party",
		hud_state = "on",
		lagometer = "1",
		partypvp = "true",
		team = "STAFF",
		yl_church = "return {[\"last_heal\"] = 1683837139, [\"last_death\"] = {[\"x\"] = 2251, [\"y\"] = -164, [\"z\"] = 1401}, [\"last_death_portal\"] = 1683839371}",
		arenalib_infobox_arenaID = "0",
		yl_commons_player_joined = "1702954728",
		["petz:werewolf"] = "0",
		["petz:lycanthropy"] = "0",
		["ethereal:fly_timer"] = "-99",
		yl_audio_state = "off",
		["signslib:pos"] = "(1993,17,990)",
		["arena_lib_editor.players_number"] = "0",
		["3d_armor_inventory"] = "return {\"\", \"\", \"\", \"\", \"\", \"\"}",
		["hud_manager:spawnit:hud_enabled"] = "y",
		["petz:old_override_table"] = "return {[\"speed\"] = 1, [\"new_move\"] = true, [\"sneak_glitch\"] = false, [\"gravity\"] = 1, [\"jump\"] = 1, [\"sneak\"] = true}",
		szutil_watch = "return {}",
		["arena_lib_editor.spawner_ID"] = "0",
		["petz:werewolf_vignette_id"] = "19",
		arenalib_watchID = "0",
		["petz:werewolf_clan_idx"] = "4",
		repellant = "0",
		["stamina:poisoned"] = "no",
		punch_count = "65132",
		xp = "0",
		bitten = "0",
		["sethome:home"] = "(1983.4349365234,17.5,1183.5950927734)",
		["arena_lib_editor.team_ID"] = "0",
		yl_commons_thankyou = "1397",
		["stamina:exhaustion"] = "81.5",
		inflicted_damage = "2991830",
		["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}",
		["stamina:level"] = "0"
	}
}

Log identifier


[MOD] yl_report log identifier = zyuQVjKSZpn1PaogJerrs0u9lNxL1sGn

Profiler save:

profile-20231219T122545.json_prettyEE

Status:

# Server: version: 5.7.0-yl-thx-tmm | game: Minetest Game | uptime: 2d 7h 28min 56s | max lag: 1.47s | clients (15/52): ALCOHOL3, AliasAlreadyTaken, Bailiff, Boris, Chache, Davidsoft, daydream, Ecklair, Griffe_De_l_Ombre, Heron, Murmel, nazthelizard122, Nomtom, Service, Silph

Teleport command:

/teleport xyz 2043 16 1227

Compass command:

/give_compass Construction zyuQVjKSZpn1PaogJerrs0u9lNxL1sGn D2691E 2043 16 1227
AliasAlreadyTaken reports a bug: > Builders flight globalstep1 leads to lag of +0.5 seconds on one player (Ecklair), but not on others (Boris) Player position: ``` { x = 2042.919921875, y = 15.5, z = 1226.5209960938 } ``` Player look: ``` { x = 0.034909933805466, y = -0.36617639660835, z = 0.92989039421082 } ``` Player information: ``` { lang_code = "de", version_string = "5.8.0", ip_version = 6, min_rtt = 0.014999999664724, avg_rtt = 0.018999999389052, min_jitter = 0, max_jitter = 0.56299996376038, avg_jitter = 0, connection_uptime = 34042, serialization_version = 29, patch = 0, formspec_version = 7, max_rtt = 0.60000002384186, state = "Active", major = 5, minor = 8, protocol_version = 42 } ``` Player meta: ``` { fields = { played_time = "97207308", digged_nodes = "140492", placed_nodes = "181872", died = "1591", crafted = "4788", ["ocean_build.last_warning"] = "1.67421e+09", ["ocean_build.forbidden"] = "true", ["ocean_build.ocean_built"] = "12", xp_redo_hud_color = "0xFFFF00", partychat = "party", hud_state = "on", lagometer = "1", partypvp = "true", team = "STAFF", yl_church = "return {[\"last_heal\"] = 1683837139, [\"last_death\"] = {[\"x\"] = 2251, [\"y\"] = -164, [\"z\"] = 1401}, [\"last_death_portal\"] = 1683839371}", arenalib_infobox_arenaID = "0", yl_commons_player_joined = "1702954728", ["petz:werewolf"] = "0", ["petz:lycanthropy"] = "0", ["ethereal:fly_timer"] = "-99", yl_audio_state = "off", ["signslib:pos"] = "(1993,17,990)", ["arena_lib_editor.players_number"] = "0", ["3d_armor_inventory"] = "return {\"\", \"\", \"\", \"\", \"\", \"\"}", ["hud_manager:spawnit:hud_enabled"] = "y", ["petz:old_override_table"] = "return {[\"speed\"] = 1, [\"new_move\"] = true, [\"sneak_glitch\"] = false, [\"gravity\"] = 1, [\"jump\"] = 1, [\"sneak\"] = true}", szutil_watch = "return {}", ["arena_lib_editor.spawner_ID"] = "0", ["petz:werewolf_vignette_id"] = "19", arenalib_watchID = "0", ["petz:werewolf_clan_idx"] = "4", repellant = "0", ["stamina:poisoned"] = "no", punch_count = "65132", xp = "0", bitten = "0", ["sethome:home"] = "(1983.4349365234,17.5,1183.5950927734)", ["arena_lib_editor.team_ID"] = "0", yl_commons_thankyou = "1397", ["stamina:exhaustion"] = "81.5", inflicted_damage = "2991830", ["unified_inventory:bags"] = "return {\"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\", \"unified_inventory:bag_large\"}", ["stamina:level"] = "0" } } ``` Log identifier ``` [MOD] yl_report log identifier = zyuQVjKSZpn1PaogJerrs0u9lNxL1sGn ``` Profiler save: ``` profile-20231219T122545.json_prettyEE ``` Status: ``` # Server: version: 5.7.0-yl-thx-tmm | game: Minetest Game | uptime: 2d 7h 28min 56s | max lag: 1.47s | clients (15/52): ALCOHOL3, AliasAlreadyTaken, Bailiff, Boris, Chache, Davidsoft, daydream, Ecklair, Griffe_De_l_Ombre, Heron, Murmel, nazthelizard122, Nomtom, Service, Silph ``` Teleport command: ``` /teleport xyz 2043 16 1227 ``` Compass command: ``` /give_compass Construction zyuQVjKSZpn1PaogJerrs0u9lNxL1sGn D2691E 2043 16 1227 ```
AliasAlreadyTaken was assigned by yourland-report 2023-12-19 12:25:45 +00:00
AliasAlreadyTaken commented 2023-12-19 12:27:35 +00:00
Owner
Copy Link
 instrumentation                                         |    min µs |    max µs |    avg µs | min % | max % | avg %
-------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------
 yl_statuseffects:                                       |      1083 |   1102284 |     90947 |   0.3 |  97.0 |  23.6
  - on_joinplayer[2] ..................................  |        39 |       177 |        82 |   0.0 |   0.1 |   0.0
  - on_leaveplayer[1] .................................  |         1 |         1 |         1 |   0.0 |   0.0 |   0.0
  - on_player_receive_fields[1] .......................  |        33 |      4225 |       105 |   0.0 |   7.9 |   0.2
  - globalstep[3] .....................................  |         1 |       165 |         2 |   0.0 |   0.4 |   0.0
  - globalstep[2] .....................................  |         1 |      5039 |       125 |   0.0 |   7.3 |   0.2
  - globalstep[1] .....................................  |      1081 |   1101408 |     90836 |   0.3 |  97.0 |  23.4
  - on_leaveplayer[3] .................................  |        47 |       138 |        93 |   0.0 |   0.3 |   0.1
  - on_joinplayer[1] ..................................  |        59 |      3509 |       684 |   0.0 |   1.1 |   0.2
  - /toggle_bf_hud ....................................  |       253 |       253 |       253 |   0.1 |   0.1 |   0.1
  - on_leaveplayer[2] .................................  |        91 |      1873 |       466 |   0.0 |   0.5 |   0.2
-------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------

After /profiler reset:

 instrumentation                                         |    min µs |    max µs |    avg µs | min % | max % | avg %
-------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------
 yl_statuseffects:                                       |    442886 |    511112 |    466232 |  79.2 |  91.9 |  85.5
  - on_player_receive_fields[1] .......................  |       106 |       106 |       106 |   0.0 |   0.0 |   0.0
  - globalstep[3] .....................................  |         2 |         3 |         2 |   0.0 |   0.0 |   0.0
  - globalstep[2] .....................................  |         1 |       464 |       266 |   0.0 |   0.1 |   0.0
  - globalstep[1] .....................................  |    442419 |    511111 |    465948 |  79.1 |  91.8 |  85.4
-------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------
``` instrumentation | min µs | max µs | avg µs | min % | max % | avg % -------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------ yl_statuseffects: | 1083 | 1102284 | 90947 | 0.3 | 97.0 | 23.6 - on_joinplayer[2] .................................. | 39 | 177 | 82 | 0.0 | 0.1 | 0.0 - on_leaveplayer[1] ................................. | 1 | 1 | 1 | 0.0 | 0.0 | 0.0 - on_player_receive_fields[1] ....................... | 33 | 4225 | 105 | 0.0 | 7.9 | 0.2 - globalstep[3] ..................................... | 1 | 165 | 2 | 0.0 | 0.4 | 0.0 - globalstep[2] ..................................... | 1 | 5039 | 125 | 0.0 | 7.3 | 0.2 - globalstep[1] ..................................... | 1081 | 1101408 | 90836 | 0.3 | 97.0 | 23.4 - on_leaveplayer[3] ................................. | 47 | 138 | 93 | 0.0 | 0.3 | 0.1 - on_joinplayer[1] .................................. | 59 | 3509 | 684 | 0.0 | 1.1 | 0.2 - /toggle_bf_hud .................................... | 253 | 253 | 253 | 0.1 | 0.1 | 0.1 - on_leaveplayer[2] ................................. | 91 | 1873 | 466 | 0.0 | 0.5 | 0.2 -------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------ ``` After /profiler reset: ``` instrumentation | min µs | max µs | avg µs | min % | max % | avg % -------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------ yl_statuseffects: | 442886 | 511112 | 466232 | 79.2 | 91.9 | 85.5 - on_player_receive_fields[1] ....................... | 106 | 106 | 106 | 0.0 | 0.0 | 0.0 - globalstep[3] ..................................... | 2 | 3 | 2 | 0.0 | 0.0 | 0.0 - globalstep[2] ..................................... | 1 | 464 | 266 | 0.0 | 0.1 | 0.0 - globalstep[1] ..................................... | 442419 | 511111 | 465948 | 79.1 | 91.8 | 85.4 -------------------------------------------------------- | --------- | --------- | --------- | ----- | ----- | ------ ```
AliasAlreadyTaken added the
1. kind/bug
3. source/lag
 labels 2023-12-19 12:30:27 +00:00
AliasAlreadyTaken commented 2023-12-19 12:53:21 +00:00
Owner
Copy Link

Due to #5746 I tried to profile like so:

yl_events.temp.show_particles = yl_statuseffects.builders_flight.show_particles

function yl_statuseffects.builders_flight.show_particles(player,t)
local t1 = minetest.get_us_time()
local ret = yl_events.temp.show_particles(player,t)
local t2 = minetest.get_us_time()
core.log("action","DEBUG show_particles = "..dump(t2-t1))
return ret
end

This returned me:

2023-12-19 12:50:53: ACTION[Server]: DEBUG show_particles = 430321
2023-12-19 12:50:53: ACTION[Server]: DEBUG show_particles = 1919
2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 425525
2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 2086
2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 433787

Apparently it#s the particles that use up so much? WHY?

For now, this stopped the lag:

//lua local p = minetest.get_player_by_name("Ecklair") yl_statuseffects.builders_flight.set_particles_enabled(p,false)

Boris, my testaccount, had the particles enabled all the time and they didn't cause any lag. Also, the issue is not reproducible on the testserver with the Ecklair account

2023-12-19 13:16:10: ACTION[Server]: DEBUG get_nearby_positions = 473033
2023-12-19 13:16:10: ACTION[Server]: DEBUG get_nearby_area_positions = 473295

Due to #5746 I tried to profile like so: ```lua yl_events.temp.show_particles = yl_statuseffects.builders_flight.show_particles function yl_statuseffects.builders_flight.show_particles(player,t) local t1 = minetest.get_us_time() local ret = yl_events.temp.show_particles(player,t) local t2 = minetest.get_us_time() core.log("action","DEBUG show_particles = "..dump(t2-t1)) return ret end ``` This returned me: > 2023-12-19 12:50:53: ACTION[Server]: DEBUG show_particles = 430321 > 2023-12-19 12:50:53: ACTION[Server]: DEBUG show_particles = 1919 > 2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 425525 > 2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 2086 > 2023-12-19 12:50:54: ACTION[Server]: DEBUG show_particles = 433787 Apparently it#s the particles that use up so much? WHY? For now, this stopped the lag: ``` //lua local p = minetest.get_player_by_name("Ecklair") yl_statuseffects.builders_flight.set_particles_enabled(p,false) ``` Boris, my testaccount, had the particles enabled all the time and they didn't cause any lag. Also, the issue is not reproducible on the testserver with the Ecklair account > 2023-12-19 13:16:10: ACTION[Server]: DEBUG get_nearby_positions = 473033 > 2023-12-19 13:16:10: ACTION[Server]: DEBUG get_nearby_area_positions = 473295
flux added this to the flux's TODO list project 2023-12-19 21:33:39 +00:00
AliasAlreadyTaken was unassigned by flux 2023-12-19 21:33:46 +00:00
flux self-assigned this 2023-12-19 21:33:46 +00:00
flux commented 2023-12-19 22:39:45 +00:00
Member
Copy Link

Apparently it#s the particles that use up so much? WHY?

one issue is that currently, if there's lots of overlapping areas, it'll show you particles for each one of them separately. i'm not sure why i didn't consider that.

another possibility that just querying which areas are nearby is expensive for some reason...

> Apparently it#s the particles that use up so much? WHY? one issue is that currently, if there's lots of overlapping areas, it'll show you particles for each one of them separately. i'm not sure why i didn't consider that. another possibility that just querying which areas are nearby is expensive for some reason...
flux commented 2023-12-19 23:09:07 +00:00
Member
Copy Link

this should help with the overlapping areas: 0541b1887f

i need more info on what's actually taking a lot of time, though. i can verify that /instrument_mod yl_statuseffects doesn't emit much that's useful, i'll try to debug that.

this should help with the overlapping areas: https://gitea.your-land.de/your-land/yl_statuseffects/commit/0541b1887fd5e8c41faf1ebac06557c9891bc25b i need more info on what's actually taking a lot of time, though. i can verify that `/instrument_mod yl_statuseffects` doesn't emit much that's useful, i'll try to debug that.
flux commented 2023-12-19 23:27:05 +00:00
Member
Copy Link

i've added an option to totally disable the flight particles: 241fd5e4a1

yl_statuseffects:builders_flight:show_area_particles = false

i've added an option to totally disable the flight particles: https://gitea.your-land.de/your-land/yl_statuseffects/commit/241fd5e4a16d26a1f2b258eef5eeb30cc6fe1a0f `yl_statuseffects:builders_flight:show_area_particles = false`
flux commented 2023-12-19 23:41:55 +00:00
Member
Copy Link

i've fixed the instrumentation, which was a problem with yl_statuseffects and not debuggery: 9d5393bcfe

i've fixed the instrumentation, which was a problem with yl_statuseffects and not debuggery: https://gitea.your-land.de/your-land/yl_statuseffects/commit/9d5393bcfe3d27e8cc31e1064d16429ebceefef9
👍 1
AliasAlreadyTaken commented 2023-12-20 02:06:52 +00:00
Owner
Copy Link

Sounds like ready for QA?

Sounds like ready for QA?
flux commented 2023-12-20 21:40:41 +00:00
Member
Copy Link

Sounds like ready for QA?

yeah, i'm not sure my fixes are good enough, but it's worth trying. it might also be due to there just being a bajillion more areas on your-land than on my test server.

> Sounds like ready for QA? yeah, i'm not sure my fixes are good enough, but it's worth trying. it might also be due to there just being a bajillion more areas on your-land than on my test server.
flux added the
4. step/ready to QA test
 label 2023-12-20 21:40:49 +00:00
AliasAlreadyTaken added this to the 1.1.123 milestone 2023-12-23 13:57:18 +00:00
AliasAlreadyTaken added the
ugh/QA main
 label 2024-01-25 23:51:37 +00:00
AliasAlreadyTaken commented 2024-01-25 23:52:06 +00:00
Owner
Copy Link

At least with Violetta I couldn't reproduce the issue. Boris however seems broken, but that is a different problem. We'll see on main.

At least with Violetta I couldn't reproduce the issue. Boris however seems broken, but that is a different problem. We'll see on main.
flux added
5. result/fixed
 and removed
4. step/ready to QA test
 labels 2024-03-29 00:05:20 +00:00
flux removed this from the flux's TODO list project 2024-03-29 00:05:27 +00:00
flux removed their assignment 2024-03-29 00:05:29 +00:00
flux commented 2024-03-29 00:05:50 +00:00
Member
Copy Link

this seems fixed, but i'm not really certain where Ecklair was flying so i can't test it exactly.

this *seems* fixed, but i'm not really certain where Ecklair was flying so i can't test it exactly.
flux closed this issue 2024-03-29 00:05:50 +00:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels   
1. kind/balancing

Depends on balancing

  
1. kind/breaking

something that alters or disables an existing game mechanic

  
1. kind/bug

Something is not working

  
1. kind/construction

A build needs fixing

  
1. kind/documentation

Needs proper documentation

  
1. kind/enhancement

New feature

  
1. kind/griefing

players despoiling builds or nature

  
1. kind/invalid

Not a valid report, e.g. created by mistake with no content.

  
1. kind/meme

issue is mostly a joke

  
1. kind/node limit

something which works for or against the node limit

  
1. kind/other

Something not within the other kinds

  
1. kind/protocol

something concerning how staff should react to player requests, or how players should treat each other

  
2. prio/controversial

not likely to happen w/out a lot of discussion

  
2. prio/critical

Very important

  
2. prio/elevated

something players are eager to have fixed

  
2. prio/good first issue

the resolution to this is could be done by a new minetest contributor, who doesn't yet understand the mod ecosystem

  
2. prio/interesting

one of us has real interest in getting this implemented or fixed. however, more research might be needed.

  
2. prio/low

Not so important

  
3. source/art

art needs to be created or found for this to exist. includes sound, 3d modelling, and in-game building.

  
3. source/client

Issue is with the minetest client, or with player client configuration or the technical details of their setup

  
3. source/engine

Issue is due to a bug or feature of the minetest engine

  
3. source/ingame

Problem and solution exist in-game, e.g. builds or player moderation

  
3. source/integration

Two or more nonbuggy mechanics conflict, or our attempts to rectify conflicting mechanics have created a new bug

  
3. source/lag

A problem which is caused or made worse by lag, due to server processing issues, client processing issues, or network issues

  
3. source/license

A licensing problem is involved

  
3. source/mod upstream

Problem is upstream (not engine/client)

  
3. source/unknown

   
3. source/website

Affects the website

  
4. step/approved

Alias has approved this feature, someone should implement it

  
4. step/at work

Being worked on

  
4. step/blocked

we plan to do this, but other work has to be finished first

  
4. step/discussion

issue is under discussion, a solution has not been dictated or agreed upon

  
4. step/help wanted

Need some help

  
4. step/needs confirmation

   
4. step/partially fixed

this is mitigated or partially solved, but more work needs to be done

  
4. step/question

More information is needed

  
4. step/ready to deploy

has been QA tested by another person. has no outstanding issues. might be installed on prod, but needs final testing

  
4. step/ready to QA test

the code is supposedly fixed, but needs to be tested.

  
4. step/want approval

Someone can quickly implement this if Alias approves the change/feature

  
5. result/cannot reproduce

   
5. result/duplicate

This issue or pull request already exists

  
5. result/fixed

problem is fixed

  
5. result/maybe

not planned currently, but maybe some day

  
5. result/wontfix

the reported issue won't be changed, whether it's intentional or not.

  
ugh/petz

yet another petz bugz.

  
ugh/QA main

That's something we can only wait and see whether it hapens again: On the main server

  
ugh/QA NOK

Fix didn't yield the expected results

  
ugh/QA OK

tested

No Label
1. kind/balancing
1. kind/breaking
1. kind/bug
1. kind/construction
1. kind/documentation
1. kind/enhancement
1. kind/griefing
1. kind/invalid
1. kind/meme
1. kind/node limit
1. kind/other
1. kind/protocol
2. prio/controversial
2. prio/critical
2. prio/elevated
2. prio/good first issue
2. prio/interesting
2. prio/low
3. source/art
3. source/client
3. source/engine
3. source/ingame
3. source/integration
3. source/lag
3. source/license
3. source/mod upstream
3. source/unknown
3. source/website
4. step/approved
4. step/at work
4. step/blocked
4. step/discussion
4. step/help wanted
4. step/needs confirmation
4. step/partially fixed
4. step/question
4. step/ready to deploy
4. step/ready to QA test
4. step/want approval
5. result/cannot reproduce
5. result/duplicate
5. result/fixed
5. result/maybe
5. result/wontfix
ugh/petz
ugh/QA main
ugh/QA NOK
ugh/QA OK
Milestone
Clear milestone
No items
No Milestone
1.1.123
Projects
Clear projects
No project
Assignees
Clear assignees
No Assignees
3 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#5747
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?