PluginBugs / Issues-ItemsAdder

Repository used to keep track of issues of my plugin ItemsAdder
https://itemsadder.devs.beer
53 stars 21 forks source link

Very slow loading of many new items with the same material #2649

Closed EpicPlayerA10 closed 1 year ago

EpicPlayerA10 commented 1 year ago

Terms

Discord tag (optional)

EpicPlayerA10#3800

What happened?

I found out that when I have a lot of new items with the same material, that weren't loaded before, then loading them is very slow in the first time.

This can even lead to print a stacktrace, when server is not responding. The stacktrace is in the FULL server log section.

Maybe we can do something about this. Caching or something...

Steps to reproduce the issue

  1. Add a lot of new items with the same material
  2. Type /iazip
  3. The server won't respond for some time.

Server version

Current: git-Purpur-1968 (MC: 1.19.4)*

ItemsAdder Version

ItemsAdder version 3.4.1c

ProtocolLib Version

ProtocolLib version 5.0.0

LoneLibs Version

LoneLibs version 1.0.24

FULL server log

[11:00:48 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH  - git-Purpur-1968 (MC: 1.19.4) ---
[11:00:48 ERROR]: The server has not responded for 10 seconds! Creating thread dump
[11:00:48 ERROR]: ------------------------------
[11:00:48 ERROR]: Server thread dump (Look for plugins here before reporting to Purpur!):
[11:00:48 ERROR]: ------------------------------
[11:00:48 ERROR]: Current Thread: Server thread
[11:00:48 ERROR]:       PID: 27 | Suspended: false | Native: false | State: RUNNABLE
[11:00:48 ERROR]:       Stack:
[11:00:48 ERROR]:               java.base@17.0.7/java.util.LinkedHashMap.containsValue(LinkedHashMap.java:416)
[11:00:48 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.a(SourceFile:2928)
[11:00:48 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.b(SourceFile:1598)
[11:00:48 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.c(SourceFile:577)
[11:00:48 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I$$Lambda$8414/0x00000008028cbb78.run(Unknown Source)
[11:00:48 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftTask.run(CraftTask.java:101)
[11:00:48 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
[11:00:48 ERROR]:               net.minecraft.server.MinecraftServer.tickChildren(MinecraftServer.java:1510)
[11:00:48 ERROR]:               net.minecraft.server.dedicated.DedicatedServer.tickChildren(DedicatedServer.java:487)
[11:00:48 ERROR]:               net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1424)
[11:00:48 ERROR]:               net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1195)
[11:00:48 ERROR]:               net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:325)
[11:00:48 ERROR]:               net.minecraft.server.MinecraftServer$$Lambda$4604/0x00000008019c17d0.run(Unknown Source)
[11:00:48 ERROR]:               java.base@17.0.7/java.lang.Thread.run(Thread.java:833)
[11:00:48 ERROR]: ------------------------------
[11:00:48 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH ---
[11:00:48 ERROR]: ------------------------------
[11:00:53 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH  - git-Purpur-1968 (MC: 1.19.4) ---
[11:00:53 ERROR]: The server has not responded for 15 seconds! Creating thread dump
[11:00:53 ERROR]: ------------------------------
[11:00:53 ERROR]: Server thread dump (Look for plugins here before reporting to Purpur!):
[11:00:53 ERROR]: ------------------------------
[11:00:53 ERROR]: Current Thread: Server thread
[11:00:53 ERROR]:       PID: 27 | Suspended: false | Native: false | State: RUNNABLE
[11:00:53 ERROR]:       Stack:
[11:00:53 ERROR]:               java.base@17.0.7/java.util.LinkedHashMap.containsValue(LinkedHashMap.java:416)
[11:00:53 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.a(SourceFile:2928)
[11:00:53 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.b(SourceFile:1598)
[11:00:53 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.c(SourceFile:577)
[11:00:53 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I$$Lambda$8414/0x00000008028cbb78.run(Unknown Source)
[11:00:53 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftTask.run(CraftTask.java:101)
[11:00:53 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
[11:00:53 ERROR]:               net.minecraft.server.MinecraftServer.tickChildren(MinecraftServer.java:1510)
[11:00:53 ERROR]:               net.minecraft.server.dedicated.DedicatedServer.tickChildren(DedicatedServer.java:487)
[11:00:53 ERROR]:               net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1424)
[11:00:53 ERROR]:               net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1195)
[11:00:53 ERROR]:               net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:325)
[11:00:53 ERROR]:               net.minecraft.server.MinecraftServer$$Lambda$4604/0x00000008019c17d0.run(Unknown Source)
[11:00:53 ERROR]:               java.base@17.0.7/java.lang.Thread.run(Thread.java:833)
[11:00:53 ERROR]: ------------------------------
[11:00:53 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH ---
[11:00:53 ERROR]: ------------------------------
[11:00:58 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH  - git-Purpur-1968 (MC: 1.19.4) ---
[11:00:58 ERROR]: The server has not responded for 20 seconds! Creating thread dump
[11:00:58 ERROR]: ------------------------------
[11:00:58 ERROR]: Server thread dump (Look for plugins here before reporting to Purpur!):
[11:00:58 ERROR]: ------------------------------
[11:00:58 ERROR]: Current Thread: Server thread
[11:00:58 ERROR]:       PID: 27 | Suspended: false | Native: false | State: RUNNABLE
[11:00:58 ERROR]:       Stack:
[11:00:58 ERROR]:               java.base@17.0.7/java.util.LinkedHashMap.containsValue(LinkedHashMap.java:416)
[11:00:58 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.a(SourceFile:2928)
[11:00:58 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.b(SourceFile:1598)
[11:00:58 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I.c(SourceFile:577)
[11:00:58 ERROR]:               ItemsAdder_3.4.1c.jar//ia.m.I$$Lambda$8414/0x00000008028cbb78.run(Unknown Source)
[11:00:58 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftTask.run(CraftTask.java:101)
[11:00:58 ERROR]:               org.bukkit.craftbukkit.v1_19_R3.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
[11:00:58 ERROR]:               net.minecraft.server.MinecraftServer.tickChildren(MinecraftServer.java:1510)
[11:00:58 ERROR]:               net.minecraft.server.dedicated.DedicatedServer.tickChildren(DedicatedServer.java:487)
[11:00:58 ERROR]:               net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1424)
[11:00:58 ERROR]:               net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1195)
[11:00:58 ERROR]:               net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:325)
[11:00:58 ERROR]:               net.minecraft.server.MinecraftServer$$Lambda$4604/0x00000008019c17d0.run(Unknown Source)
[11:00:58 ERROR]:               java.base@17.0.7/java.lang.Thread.run(Thread.java:833)
[11:00:58 ERROR]: ------------------------------
[11:00:58 ERROR]: --- DO NOT REPORT THIS TO PURPUR - THIS IS NOT A BUG OR A CRASH ---
[11:00:58 ERROR]: ------------------------------

Error (optional)

No response

Problematic items yml configuration file (optional)

No response

Other files, you can drag and drop them here to upload. (optional)

No response

Screenshots/Videos (you can drag and drop files or paste links)

No response

LoneDev6 commented 1 year ago

Print the output of /iainfo.

Also what is your server hardware? The plugin was tested with lot of items and configurations and never had a performance issue on loading, I always benchmark the plugin before releasing updates.

EpicPlayerA10 commented 1 year ago

A looooooot of items: /iainfo

[09:02:22 INFO]: -=[ ItemsAdder ]=-
[09:02:22 INFO]: Version: 3.4.1c
[09:02:22 INFO]: ResourcePack
[09:02:22 INFO]:      Path: /container/plugins/ItemsAdder/output/generated.zip
[09:02:22 INFO]:      Download: xxx
[09:02:22 INFO]:      Size: 27 MB/250 MB
[09:02:22 INFO]:      Last update: 2023-05-21 19:45:35
[09:02:22 INFO]:      Host type: auto-external-host
[09:02:22 INFO]: Data
[09:02:22 INFO]:      Items: 6358
[09:02:22 INFO]:      Items in /ia: 6344
[09:02:22 INFO]:      Namespaces: 56
[09:02:22 INFO]:      Materials: 59
[09:02:22 INFO]:      REAL block IDs: 3/191
[09:02:22 INFO]:      REAL_NOTE block IDs: 714/750
[09:02:22 INFO]:      REAL_TRANSPARENT block IDs: 25/63
[09:02:22 INFO]:      REAL_WIRE block IDs: 0/127
[09:02:22 INFO]:      FIRE block IDs: 0/14
[09:02:22 INFO]:      Font images: 965/6608
[09:02:22 INFO]: Loaded chunks (2645)
[09:02:22 INFO]:      Armorstands: 0
[09:02:22 INFO]:      Mobs: 0

Also what is your server hardware?

My server hardware is pretty good.

Maybe it is because I have too many items. That's why i'm asking if it can be optimized somehow.

It isn't too annoying, it will only load new items slowly. Already existing items load in decent time.

LoneDev6 commented 1 year ago

Without any proper spark or timings report I cannot identify where the issue relies. The plugin was benchmarked and working without any significant slow down on loading lot of items, so this is strange.

EpicPlayerA10 commented 1 year ago

I loaded those 6k items (for the first time) on a new fresh server and i got some logs and data.

FULL server log: https://pastebin.com/PGaGxrBe Spark report: https://spark.lucko.me/ssMQNao0JN

LoneDev6 commented 1 year ago

Thanks bro

LoneDev6 commented 1 year ago

This issue happens only when the items are added to the configurations for the first time. It won't happen again in the next plugin loads, because the plugin uses a cache.

Although I optimized the cache generation so it won't cause slowdowns even at the first load of your items.

Benchmarks

File I used to benchmark: https://gist.github.com/LoneDev6/03f875e7d5872cffb1f190214676c60e

Old version (2 minutes)

Image

Image

New version (6 seconds)

Image

Image