InventoryMoveItemEvent lag

[robobenklein]

I am having a very severe issue with the protections on my public server. While running, the Ticks Per Second are being bottlenecked to around 50% (10tps). I have tested to ensure that without LWC, I wouldn't have the same problem. Running the server directly after removing LWC resulted in ~21.0 TPS. Here is the information I could gather from the reports:

21:54:23 [INFO] LWC Report
21:54:23 [INFO] Version: 4.4.0 (b889)
21:54:23 [INFO] Running time: 4 minutes 24 seconds
21:54:23 [INFO] Players: 0/24
21:54:23 [INFO] Item entities: 0/311
21:54:23 [INFO] Permissions API: VaultPermissions
21:54:23 [INFO] Currency API: VaultCurrency
21:54:23 [INFO]
21:54:23 [INFO] ==== Modules ====
21:54:23 [INFO] LWC v4.4.0 (b889) (October 11, 2013) -> 46 registered modules
21:54:23 [INFO]
21:54:23 [INFO] ==== Database ====
21:54:23 [INFO] Engine: MySQL
21:54:23 [INFO] Protections: 872
21:54:23 [INFO] Queries: 886 | 3.36 / second
21:54:23 [INFO]
21:54:23 [INFO] ==== Cache ====
21:54:23 [INFO] Usage: 43.60% ( 872/2000 [2000+0] ) [ Reads: 46,751,074 <=> 177087.40 r/s ] [ Writes: 3,706 <=> 14.04 w/s ]

[Hidendra]

How many InventoryMoveItemEvent invocations is that (clicking on it will show it under count)? Also, if you could update to b892+ it has slightly better counting under the cache section (and is more readable)

Do you use hoppers at all? To get that high it sounds like your world has thousands of them (not just hundreds which I've test spammed)

[robobenklein]

By looking around through the loaded chunks for each world, I found a total of 6 hoppers drawing from 3 unregistered double chests, however, upon further examination, I found ~1000 hoppers drawing from other hoppers, and ~100 hoppers drawing and placing into locked and unlocked dispensers.

I will try to get you more information using build b892 and without those hoppers. Disabling magnets and drop transfer has had no noticeable effects.

[Hidendra]

InventoryMoveItemEvent is strictly just hoppers nothing else so yeah disabling anything else wouldn't have any effect. Indeed it's a problem I've been working on (as can be seen in the last few commits) just hoppers are pretty problematic :( they send events every single tick if they can pull/push items and in your case it's even doing everything in the cache (which is in RAM) so it shouldn't be that slow.

[robobenklein]

I am using FriendlyHopper however, and it does quite a few things with protecting locked chests from hoppers. ( http://dev.bukkit.org/bukkit-plugins/friendlyhopper/ ) After removing this plugin, TPS increases by 2.

Also, if I were to create a plugin that does only this have any effect? I would guess it would only take the load off LWC and cause lag on its own having so many hoppers.

On InventoryMoveItemEvent (args) {
If LWC lock is nearby: cancel event; }

[Hidendra]

From what I can see (and looking at the source) FriendlyHopper only prevents hopper carts from being crafted / used it doesn't use InventoryMoveItemEvent

Shifting the same logic to another plugin I don't think would do much -- that is basically what LWC is doing already except it's using its internal caches where it can.

p.s. you may want to try the latest build (896). it's b92e97b and should help a little bit

[robobenklein]

You are pushing out dev builds like nobody's business, thanks so much for what you do!

[robobenklein]

Build #898 is definitely helping with the hoppers, TPS improved to 15 (75%). Here are the new reports:

17:32:33 [INFO] LWC Report
17:32:33 [INFO] Version: 4.4.0 (b898)
17:32:33 [INFO] Running time: 3 minutes 31 seconds
17:32:33 [INFO] Players: 0/24
17:32:33 [INFO] Item entities: 1/312
17:32:33 [INFO] Permissions API: VaultPermissions
17:32:33 [INFO] Currency API: VaultCurrency
17:32:33 [INFO]
17:32:33 [INFO] ==== Modules ====
17:32:33 [INFO] LWC v4.4.0 (b898) (October 14, 2013) -> 47 registered modules
17:32:33 [INFO]
17:32:33 [INFO] ==== Database ====
17:32:33 [INFO] Engine: MySQL
17:32:33 [INFO] Protections: 872
17:32:33 [INFO] Queries: 16 | 0.08 / second
17:32:33 [INFO]
17:32:33 [INFO] ==== Cache ====
17:32:33 [INFO] Usage: 43.60% ( 872/2000 [2000+0] )
17:32:33 [INFO] Profile:
17:32:33 [INFO] isKnownNull: 8,452,902 (40061.15 / second)
17:32:33 [INFO] getProtection: 934 (4.43 / second)
17:32:33 [INFO] addProtection: 872 (4.13 / second)
17:32:33 [INFO] addKnownNull: 392 (1.86 / second)

And the InventoryMoveItemEvent specifics:

Total duration: 21435.792 ms / 500 ticks
Average duration: 42.872 ms/tick
Selected event: InventoryMoveItemEvent[NORMAL]
Plugin: LWC
Location: class com.griefcraft.listeners.LWCPlayerListener
Execution count: 1507479
Cancelled: 0 (0.0%)