Serious Lag with ICs enabled
LadyCailinBot opened this issue ยท 82 comments
CRAFTBOOK-2681 - Reported by SacredSkull
I get major block lag on my server with the circuit section enabled (I have a feeling it is ST ICs.). It only started with the latest beta (time of writing, Build #2539-bed519d). Tested all sections (disabling mechanisms, and minecart functions).
With circuits enabled
http://aikar.co/timings.php?url=5963744
TPS 7
Without
http://aikar.co/timings.php?url=5963751
TPS 19
Quite a TPS difference..
Server is not a bad machine at all.
32GB RAM
i7 CPU 4GHz
100mbit line
Comment by me4502
So this doesn't occur with #2538? What build did this start with?
Comment by SacredSkull
What ever the most recent stable release was, I haven't been using the beta builds since then, so cannot comment
Comment by SacredSkull
Eh, you mean the unstable builds ? The next stable is #2539-bed519d, which is what I was using
Comment by me4502
Sk's Jenkins is currently broken, you'll need to use his other build site
Comment by me4502
Comment by me4502
If you disable the snow mechanic, do speeds return to normal?
Comment by SacredSkull
The snow mechanic has always been disabled
Config:
http://paste.ubuntu.com/5968167/
If I recall correctly, changing "ST-think-ticks" to 4 slightly reduced lag for a time
Comment by me4502
I don't think that issue exists anymore. Use the latest dev builds for that specific issue.
Comment by SacredSkull
Not entirely sure if a snapshot is what you want:
http://www.mediafire.com/?kb8rexw5xw6en4r
Only 6kb..
Seriously doubt there is a list of 8,000 classes in there
Comment by SacredSkull
I believe this is the LWP that is responsible for lag
"Server thread" prio=10 tid=0x00007fdbd4454000 nid=0x97b runnable [0x00007fdbc9b93000]
java.lang.Thread.State: RUNNABLE
at org.bukkit.craftbukkit.v1_6_R2.util.LongHashSet.remove0(LongHashSet.java:167)
at org.bukkit.craftbukkit.v1_6_R2.util.LongHashSet.remove(LongHashSet.java:152)
at net.minecraft.server.v1_6_R2.ChunkProviderServer.getChunkAt(ChunkProviderServer.java:88)
at net.minecraft.server.v1_6_R2.ChunkProviderServer.getChunkAt(ChunkProviderServer.java:84)
at org.bukkit.craftbukkit.v1_6_R2.CraftWorld.getChunkAt(CraftWorld.java:118)
at org.bukkit.craftbukkit.v1_6_R2.CraftWorld.getBlockAt(CraftWorld.java:82)
at com.sk89q.craftbook.circuits.gates.world.blocks.Planter.searchBlocks(Planter.java:139)
at com.sk89q.craftbook.circuits.gates.world.blocks.Planter.plant(Planter.java:99)
at com.sk89q.craftbook.circuits.gates.world.blocks.Planter.think(Planter.java:81)
at com.sk89q.craftbook.circuits.ic.SelfTriggeredICMechanic.think(SelfTriggeredICMechanic.java:44)
at com.sk89q.craftbook.MechanicManager.think(MechanicManager.java:662)
at com.sk89q.craftbook.MechanicClock.run(MechanicClock.java:26)
at org.bukkit.craftbukkit.v1_6_R2.scheduler.CraftTask.run(CraftTask.java:67)
at org.bukkit.craftbukkit.v1_6_R2.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:345)
at net.minecraft.server.v1_6_R2.MinecraftServer.t(MinecraftServer.java:518)
at net.minecraft.server.v1_6_R2.DedicatedServer.t(DedicatedServer.java:239)
at net.minecraft.server.v1_6_R2.MinecraftServer.s(MinecraftServer.java:481)
at net.minecraft.server.v1_6_R2.MinecraftServer.run(MinecraftServer.java:413)
at net.minecraft.server.v1_6_R2.ThreadServerApplication.run(SourceFile:582)
Comment by SacredSkull
Might be easier to simply use IRC (your choice) I'm logged on right now
Comment by SacredSkull
Unfortunately, sampling is not possible over an SSH connection, and installing x-server or any other window management service is not an option
Comment by Dark_Arc
Try disabling the farming ICs, they can majorly impact performance.
Comment by me4502
Sampling isn't what is needed, it's the profiling that needs to be done. That is possible over all connection types.
Comment by Dark_Arc
I wonder if a compile time test could be made to check for excessively demanding ICs... Hm...
Comment by me4502
So you're thinking if a unit test that profiles IC's? That'd just increase compile time, whilst doing something that should be easily obtainable by looking at the code
Comment by SacredSkull
I assure you that profiling was disabled over the remote- it said that it was unsupported by the Java virtual machine. Also, the farming ICs are literally what I use the IC section of craftbook for, so I'd really prefer not to disable them. Besides, I'm not talking about a little lag- I'm talking about 70% performance loss, which I have never heard of before when people talk about craftbook maybe reducing performance a tiny bit.
Note. VisualVM can retrieve monitoring information on remote applications but it cannot profile remote applications.
According to it's own documentation, profiling is not possible
Comment by me4502
I personally use profiling remotely. You need to add something to the servers startup script to use it though.. And once that's done, you can connect fine and profile.
Comment by SacredSkull
clearly you are the only person who knows this ^^
how?
Comment by me4502
The top answers, those are literally the steps I follow to use it, and either profiling or sampling works fine (I can't remember which one it is)
Comment by SacredSkull
Can't get the SSH tunnel working- connection keeps refusing when I use the SOCKS proxy tunnel
source:
http://www.javacodegeeks.com/2012/09/visualvm-monitoring-remote-jvm-over-ssh.html
Comment by me4502
jstatd is the one you want to be using, make sure it's all setup correctly
Comment by SacredSkull
I'll be away for a couple of days, so please don't shelf this issue and I'll get right back to it once I'm back
Comment by me4502
Okay...
Please type /cb report -i and pastebin the file it makes
Comment by SacredSkull
without modification of think-tick
http://pastebin.com/tz5QUzET
I am aware that two logging plugins are enabled- they have been ruled out as the cause of lag (I.e. they have been disabled separately). We are in the middle of a switchover and the logblock mysql db is much too big to use an export sql script.
Comment by SacredSkull
I'll assume you mean IC-radius, tuned down to 10 (originally 15)
Comment by me4502
Yes, that's what I meant. Restart and see if the lag persists.
If it persists, are you running on a game server? (Someone who just runs a mc server).
Or from a VPS/Dedicated server?
If VPS/Dedi.. Can you please run jVisualVM on the server for a while and give me the reports? It'd allow me to find exactly what is slow.
Comment by SacredSkull
Edit again:
Can't see any terminal mode for jvisualvm
@:~$ jvisualvm --help
Usage: /usr/lib/jvm/java-7-oracle/bin/../lib/visualvm//platform/lib/nbexec {opti ons} arguments
General options:
--help show this help
--jdkhome path to Java(TM) 2 SDK, Standard Edition
-J<jvm_option> pass <jvm_option> to JVM
--cp:p prepend to classpath
--cp:a append to classpath
/usr/lib/jvm/java-7-oracle/bin/../lib/visualvm//platform/lib/nbexec: WARNING: en vironment variable DISPLAY is not set
Module reload options:
--reload /path/to/module.jar install or reinstall a module JAR file
Additional module options:
--openfile open file specified by , file can be Applicatio n snapshot, NetBeans Profiler snapshot or HPROF heap dump.
--openjmx open application specified by JMX connection (host:p ort)
--openpid open application with process id
--openid open application with id
Core options:
--laf use given LookAndFeel class instead of the default
--fontsize set the base font size of the user interface, in points
--locale <language[:country[:variant]]> use specified locale
--userdir use specified directory to store user settings
--cachedir use specified directory to store user cache
--nosplash do not show the splash screen
Comment by me4502
There is a way to open it as a connection, then connect to it from a local computer.
Try this,
http://www.codefactorycr.com/java-visualvm-to-profile-a-remote-server.html
Comment by SacredSkull
Different issue, but just noticed.
Netty is spigot's networking engine, so not entirely sure what caused the exception - certainly looks like craftbook never received the event fire (I.e. spigot's fault):
2013-08-10 02:24:52 [SEVERE] Could not pass event PlayerItemHeldEvent to CraftBook v3.7-SNAPSHOT:3165-055fb8d,master
org.bukkit.event.EventException
at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:427)
at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:47)
at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:478)
at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:463)
at net.minecraft.server.v1_6_R2.PlayerConnection.a(PlayerConnection.java:755)
at net.minecraft.server.v1_6_R2.Packet16BlockItemSwitch.handle(SourceFile:27)
at org.spigotmc.netty.NettyNetworkManager.b(NettyNetworkManager.java:230)
at net.minecraft.server.v1_6_R2.PlayerConnection.e(PlayerConnection.java:116)
at net.minecraft.server.v1_6_R2.ServerConnection.b(SourceFile:37)
at org.spigotmc.netty.NettyServerConnection.b(NettyServerConnection.java:125)
at net.minecraft.server.v1_6_R2.MinecraftServer.t(MinecraftServer.java:592)
at net.minecraft.server.v1_6_R2.DedicatedServer.t(DedicatedServer.java:239)
at net.minecraft.server.v1_6_R2.MinecraftServer.s(MinecraftServer.java:481)
at net.minecraft.server.v1_6_R2.MinecraftServer.run(MinecraftServer.java:413)
at net.minecraft.server.v1_6_R2.ThreadServerApplication.run(SourceFile:582)
Caused by: java.lang.NullPointerException
at com.sk89q.craftbook.mech.PaintingSwitch.onHeldItemChange(PaintingSwitch.java:80)
at sun.reflect.GeneratedMethodAccessor262.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:425)
... 15 more
Comment by SacredSkull
Clock IC (MC1421) has stopped working altogether- the signs don't count and the lever never toggles
Comment by me4502
Did you use /reload, /cb reload or plugman? Try to restart the server, it works fine for me
Comment by SacredSkull
Comment by me4502
Hmm.. That seems to look all fine, when you say the signs don't count, what do you mean? Are there console errors?
Comment by SacredSkull
The clock IC- the signs count to the number eg.
[mc1421]
60
10 - > 11 - > 12 - > etc. - this is stuck on one number, and the output never changes.
Regarding console errors, there was a massive error spam, but it didn't output to the log file, and never occurred again after I restarted (it hadn't locked up- just wouldn't output to log)
Comment by me4502
If you shift right click the IC, does it start again? There could be a corrupt tile entity in the chunk, which will lock up IC's and there is nothing I can do about it from the code point. Usually the server will error sometime on startup if a corrupt tile entity exists.
Comment by SacredSkull
Tried that, no effect, and didn't see anything in the console log
Comment by me4502
Issue with bukkits signs it looks like, I'm looking into it.
Edit: Use the latest dev build.
Comment by SacredSkull
Using Build #3221-9d4377a, and no change in signs not updating - I'm using spigot for the record- so they might have tried to fix the bug themselves or have a slightly different issue
Comment by me4502
Hmm, do gates/bridges work?
Edit: I just tested many different IC's which use sign states, they all work.
Comment by SacredSkull
Huh- all CraftBook functionality has ceased to function O_o
EDIT: Another admin must have disabled circuits without telling me, but regardless- that one bool setting turned off ALL other mechanics
Comment by me4502
In game,please type /cb report -p and paste the link here
Edit: so doors/gates weren't working either? Are you sure there wasnt an error occurring in e console?
Comment by me4502
None on startup at all? That option can't disable everything, craftbook is modular.
Comment by SacredSkull
I know it is modular, hence the point of the different bools that toggle each module, but I assure you, everything worked when that was changed from false to true
Regarding MC1234/Planter, I seriously suggest adding an option to disable ST, OR make the terrain scanner slower (Seeing as the lag continues whilst nothing is being planted, it suggests that it is actively scanning for terraformed dirt to use)
Comment by Dark_Arc
Farming ICs can do that kind of tps damage if you have a bunch of them... Unfortunately...
Comment by SacredSkull
Yes, it is. I am unable to get a remote sampling to work, so not sure how to progress
Comment by me4502
Without a remote sampling there is very little we can do. Does the lag go away if you disable the planter IC in the config? That's the most intensive IC I know of.
Comment by Dark_Arc
I might see about doing some optimizations later... I don't know what all can be done for it though.
Comment by SacredSkull
Planter IC has been narrowed down the source of the lag - is it possible for a config option to disable self timing (either just for this IC or a list field)? This would mean I could force the planter to only check on a slow(er) clock signal
Comment by me4502
Are you using more Planter IC's that other farm IC's? They should use around the same resourse usage.
Comment by me4502
Well I don't see how the planter IC could be so much more laggy than others, but I believe I may have just optimized it in the latest dev build.
Comment by SacredSkull
Put it this way- disabling the Planter IC changed CPU usage from about 130 to 40-70
Comment by SacredSkull
Silly me- I'll fix that.
Whilst it could reduce lag if there are blocks available to plant, what if there are no blocks? Then you have accessed the chest and counted for no reason - and you keep doing that on every iteration. You also need to ensure that only one stack is used at one time. (pseudo -
if(fertileDirtAvail()){ plant(countSeeds(),ItemID.SEEDS);}
)
Enumerating dirt blocks in the early is also going to be a bit laggy if you do it every clock pulse - you should probably divide the clock by a few times, as the dirt is unlikely to change that often (+that speed is really not necessary)
This function returns a hashmap of items that cannot be removed- so instead of calling a getInv() function just "assume" the chest has seeds- and create an if statement for the hashmap (if(hashmap.contains(ItemID.SEEDS)){ return none; } and you effectively reduce inventory checks by half
Comment by me4502
The planter only scans for dirt to use, if it has seeds to plant. I think bukkits inventory accesses are just slow.
And with the circuit bool, what was disabled exactly? Turn it off again then type /cb report -p and paste the link here, it'll tell me how may things are disabled.
Comment by SacredSkull
Hmm, doesn't seem like it's going to happen again, other mechanisms do work now. Seems to have been a one off bug. Didn't know pastebin had an API, cool..
http://pastebin.com/JE2GFbJp
Comment by SacredSkull
Then perhaps doing it the other way might be faster? Enumerate available dirt blocks, then check if seeds are available?
Comment by me4502
The issue with that is, some crops need to be planted on different blocks - so it checks for every block in that case.
Comment by SacredSkull
Really clutching at straws here, but maybe an option (e.g. 3rd line - wheat) to select what type of crop you want planted? That would limit the block search, and might give a performance boost. If what you say is true about inventory checks, then you'll want to only access chests when you are sure there are blocks available and not the other way around
Comment by me4502
When I'm not busy ill look into the speeds of inventory accesses and I'll try to speed it up.
Comment by SacredSkull
I'm impressed by the amount of time you give it, so whenever you want to
Comment by SacredSkull
Does LWC have any history with CB as being laggy? I just installed a modified version of LWC that shaved off about 20% usage (on InventoryMoveItemEvent)
Comment by me4502
Uh, it may just be the usage of both together, because LWC can get pretty laggy.
Comment by SacredSkull
Also, don't know if I toggled a setting by accident, but pretty sure that minecarts aren't supposed to work without rails. Currently on CraftBook version 3.7-SNAPSHOT:3221-9d4377a,master - minecarts simply go VERY fast if they "fall off" a rail onto a block without rails - also, I set st-think-ticks = 16, which obviously WILL reduce lag, so I really think that a per-IC config of ST tick rate would be good
Comment by me4502
Per-IC config of ST ticks would actually cause a lot more lag, as I'd have to have a IC tick loop running for every IC, and iteration would be slower due to not being able to use standard arrays.
Edit: And the minecart question, the last craftbook report you pastebin'd had the max speed modifiers turned on, causing the off rail speed to be much higher.
Comment by Dark_Arc
http://pastebin.com/huRhayTL - Proposal