search

webbukkit / dynmap

A set of Minecraft mods that provide a real time web-based map system for various Minecraft server implementations.
https://www.reddit.com/r/Dynmap/
Apache License 2.0
2.03k stars 414 forks source link

Memory leak with Dynmap 1.5 (Bukkit) when used with MCPC+ 1.4.7-R1.1 b245 and FTB/Ultimate 1.01 #1191

Closed WebMaka closed 11 years ago

WebMaka commented 11 years ago

Greetings Dynmap crew!

I'm running a test server to make sure all is well on Feed The Beast, Ultimate 1.01 running on MCPC+ 1.4.7-R1.1 build 245, and discovered a memory leak that ultimately crashes out the server with "out of heap space" errors. Removing only Dynmap (by adding ".disabled" to the filename so MCPC won't "see" it) resolved the issue, so it was pretty easy to narrow down.

Here's how MCPC reported its shutdown after its deadlock detector fired...

2013-03-13 18:26:59 [INFO] Stopping server 2013-03-13 18:26:12 [SEVERE] The server has stopped responding! 2013-03-13 18:29:02 [SEVERE] Please report this to http://www.mcportcentral.co.za/ 2013-03-13 18:28:43 [INFO] [EssentialsAntiBuild] Disabling EssentialsAntiBuild v2.10.1 2013-03-13 18:29:48 [SEVERE] Spigot version: 1.4.7-R1.1-SNAPSHOT 2013-03-13 18:29:48 [SEVERE] Begin Exception Trace For All Threads: 2013-03-13 18:29:41 [SEVERE] Exception in thread "Spigot Metrics Gatheri 2013-03-13 18:29:52 [SEVERE] ng Thread" Exception in thread "Listen thread" 2013-03-13 18:30:00 [SEVERE] Exception in thread "Immibis Core background task" 2013-03-13 18:30:00 [SEVERE] java.lang.OutOfMemoryError: Java heap space 2013-03-13 18:30:00 [SEVERE] java.lang.OutOfMemoryError: Java heap space 2013-03-13 18:30:03 [INFO] [EssentialsSpawn] Disabling EssentialsSpawn v2.10.1 2013-03-13 18:30:03 [INFO] [EssentialsChat] Disabling EssentialsChat v2.10.1 2013-03-13 18:30:24 [SEVERE] ------------------------------ 2013-03-13 18:30:41 [SEVERE] Current Thread: Server thread 2013-03-13 18:30:41 [SEVERE] PID: 18 | Alive: true | State: RUNNABLE 2013-03-13 18:30:45 [SEVERE] Stack: 2013-03-13 18:30:51 [INFO] [dynmap] Disabling dynmap v1.5-612 2013-03-13 18:31:09 [SEVERE] java.util.LinkedHashMap.createEntry(LinkedHashMap.java:421) 2013-03-13 18:31:12 [SEVERE] java.util.LinkedHashMap.addEntry(LinkedHashMap.java:403) 2013-03-13 18:31:12 [SEVERE] java.util.HashMap.put(HashMap.java:412) 2013-03-13 18:31:12 [SEVERE] org.anjocaido.groupmanager.permissions.BukkitPermissions.collectPermissions(Unknown Source) 2013-03-13 18:31:12 [SEVERE] org.anjocaido.groupmanager.permissions.BukkitPermissions$BukkitEvents.onPluginDisable(Unknown Source) 2013-03-13 18:31:12 [SEVERE] sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 2013-03-13 18:31:12 [SEVERE] sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) 2013-03-13 18:31:12 [SEVERE] sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) 2013-03-13 18:31:12 [SEVERE] java.lang.reflect.Method.invoke(Unknown Source) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:361) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:477) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:462) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.java.JavaPluginLoader.disablePlugin(JavaPluginLoader.java:416) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.SimplePluginManager.disablePlugin(SimplePluginManager.java:400) 2013-03-13 18:31:12 [SEVERE] org.bukkit.plugin.SimplePluginManager.disablePlugins(SimplePluginManager.java:393) 2013-03-13 18:31:12 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.CraftServer.disablePlugins(CraftServer.java:286) 2013-03-13 18:31:12 [SEVERE] net.minecraft.server.MinecraftServer.k(MinecraftServer.java:641) 2013-03-13 18:31:12 [SEVERE] net.minecraft.server.MinecraftServer.run(MinecraftServer.java:799) 2013-03-13 18:31:12 [SEVERE] fy.run(ThreadMinecraftServer.java:16) 2013-03-13 18:31:12 [SEVERE] ------------------------------ 2013-03-13 18:31:12 [SEVERE] Current Thread: pool-4-thread-1 Selector0 2013-03-13 18:31:12 [SEVERE] PID: 53 | Alive: true | State: RUNNABLE 2013-03-13 18:31:12 [SEVERE] Stack: 2013-03-13 18:31:12 [SEVERE] sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method) 2013-03-13 18:31:16 [SEVERE] sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source) 2013-03-13 18:31:20 [SEVERE] sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source) 2013-03-13 18:31:20 [SEVERE] sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source) 2013-03-13 18:31:20 [SEVERE] sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source) 2013-03-13 18:31:20 [SEVERE] sun.nio.ch.SelectorImpl.select(Unknown Source) 2013-03-13 18:31:20 [SEVERE] org.dynmap.jetty.io.nio.SelectorManager$SelectSet.doSelect(Unknown Source) 2013-03-13 18:31:20 [SEVERE] org.dynmap.jetty.io.nio.SelectorManager$1.run(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:31:20 [SEVERE] ------------------------------ 2013-03-13 18:31:20 [SEVERE] Current Thread: RMI TCP Accept-0 2013-03-13 18:31:20 [SEVERE] PID: 11 | Alive: true | State: RUNNABLE 2013-03-13 18:31:20 [SEVERE] Stack: 2013-03-13 18:31:20 [SEVERE] java.net.DualStackPlainSocketImpl.accept0(Native Method) 2013-03-13 18:31:20 [SEVERE] java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.net.AbstractPlainSocketImpl.accept(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.net.PlainSocketImpl.accept(Unknown Source) 2013-03-13 18:31:20 [SEVERE] java.net.ServerSocket.implAccept(Unknown Source) 2013-03-13 18:31:37 [SEVERE] java.net.ServerSocket.accept(Unknown Source) 2013-03-13 18:31:37 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 2013-03-13 18:31:40 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 2013-03-13 18:32:03 [SEVERE] Error occurred while disabling dynmap v1.5-612 (Is it up to date?) java.lang.NoClassDefFoundError: org/dynmap/snakeyaml/serializer/Serializer at org.dynmap.snakeyaml.Yaml.dumpAll(Unknown Source) at org.dynmap.snakeyaml.Yaml.dumpAll(Unknown Source) at org.dynmap.snakeyaml.Yaml.dump(Unknown Source) at org.dynmap.ConfigurationNode.save(Unknown Source) at org.dynmap.DynmapCore.saveIDsByIP(Unknown Source) at org.dynmap.DynmapCore.disableCore(Unknown Source) at org.dynmap.bukkit.DynmapPlugin.onDisable(Unknown Source) at org.bukkit.plugin.java.JavaPlugin.setEnabled(JavaPlugin.java:219) at org.bukkit.plugin.java.JavaPluginLoader.disablePlugin(JavaPluginLoader.java:422) at org.bukkit.plugin.SimplePluginManager.disablePlugin(SimplePluginManager.java:400) at org.bukkit.plugin.SimplePluginManager.disablePlugins(SimplePluginManager.java:393) at org.bukkit.craftbukkit.v1_4_R1.CraftServer.disablePlugins(CraftServer.java:286) at net.minecraft.server.MinecraftServer.k(MinecraftServer.java:641) at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:799) at fy.run(ThreadMinecraftServer.java:16) Caused by: java.lang.ClassNotFoundException: Failed to remap class org.dynmap.snakeyaml.serializer.Serializer at org.bukkit.plugin.java.PluginClassLoader.remappedFindClass(PluginClassLoader.java:344) at org.bukkit.plugin.java.PluginClassLoader.findClass(PluginClassLoader.java:265) at org.bukkit.plugin.java.PluginClassLoader.findClass(PluginClassLoader.java:243) at java.lang.ClassLoader.loadClass(Unknown Source) at java.lang.ClassLoader.loadClass(Unknown Source) ... 15 more Caused by: java.lang.OutOfMemoryError: Java heap space 2013-03-13 18:32:09 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:32:59 [SEVERE] ------------------------------ 2013-03-13 18:32:59 [INFO] [Essentials] Disabling Essentials v2.10.1 2013-03-13 18:33:04 [SEVERE] Current Thread: RMI TCP Accept-12323 2013-03-13 18:33:21 [SEVERE] PID: 12 | Alive: true | State: RUNNABLE 2013-03-13 18:33:21 [SEVERE] Stack: 2013-03-13 18:33:21 [SEVERE] java.net.DualStackPlainSocketImpl.accept0(Native Method) 2013-03-13 18:33:21 [SEVERE] java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 2013-03-13 18:33:21 [SEVERE] java.net.AbstractPlainSocketImpl.accept(Unknown Source) 2013-03-13 18:33:21 [SEVERE] java.net.PlainSocketImpl.accept(Unknown Source) 2013-03-13 18:33:21 [SEVERE] java.net.ServerSocket.implAccept(Unknown Source) 2013-03-13 18:33:21 [SEVERE] java.net.ServerSocket.accept(Unknown Source) 2013-03-13 18:33:21 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 2013-03-13 18:33:21 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 2013-03-13 18:33:21 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:21 [SEVERE] ------------------------------ 2013-03-13 18:33:21 [SEVERE] Current Thread: Signal Dispatcher 2013-03-13 18:33:21 [SEVERE] PID: 5 | Alive: true | State: RUNNABLE 2013-03-13 18:33:21 [SEVERE] Stack: 2013-03-13 18:33:21 [SEVERE] ------------------------------ 2013-03-13 18:33:21 [SEVERE] Current Thread: DestroyJavaVM 2013-03-13 18:33:21 [SEVERE] PID: 20 | Alive: true | State: RUNNABLE 2013-03-13 18:33:21 [SEVERE] Stack: 2013-03-13 18:33:21 [SEVERE] ------------------------------ 2013-03-13 18:33:21 [SEVERE] Current Thread: Dynmap Render Thread 2013-03-13 18:33:21 [SEVERE] PID: 48 | Alive: true | State: RUNNABLE 2013-03-13 18:33:21 [SEVERE] Stack: 2013-03-13 18:33:21 [SEVERE] sun.misc.Unsafe.park(Native Method) 2013-03-13 18:33:25 [SEVERE] java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source) 2013-03-13 18:33:25 [SEVERE] java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source) 2013-03-13 18:33:25 [SEVERE] java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source) 2013-03-13 18:33:25 [SEVERE] java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source) 2013-03-13 18:33:30 [INFO] [Permissions] Disabling Permissions v3.1.6 2013-03-13 18:33:30 [SEVERE] java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source) 2013-03-13 18:33:33 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:33:33 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:33:33 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:33 [SEVERE] ------------------------------ 2013-03-13 18:33:33 [INFO] WEPIF: GroupManager detected! Using GroupManager for permissions. 2013-03-13 18:33:33 [SEVERE] Current Thread: File IO Thread 2013-03-13 18:33:33 [INFO] Fake Permissions version 3.1.6 is disabled! 2013-03-13 18:33:33 [SEVERE] PID: 69 | Alive: true | State: RUNNABLE 2013-03-13 18:33:33 [SEVERE] Stack: 2013-03-13 18:33:33 [SEVERE] java.util.zip.DeflaterOutputStream.write(Unknown Source) 2013-03-13 18:33:33 [SEVERE] java.io.DataOutputStream.writeByte(Unknown Source) 2013-03-13 18:33:33 [SEVERE] cd.a(NBTBase.java:107) 2013-03-13 18:33:37 [INFO] [WorldEdit] Disabling WorldEdit v1372-48c3c3e 2013-03-13 18:33:38 [SEVERE] bq.a(NBTTagCompound.java:41) 2013-03-13 18:33:43 [SEVERE] by.a(NBTTagList.java:51) 2013-03-13 18:33:50 [SEVERE] cd.a(NBTBase.java:112) 2013-03-13 18:33:50 [SEVERE] bq.a(NBTTagCompound.java:41) 2013-03-13 18:33:50 [SEVERE] cd.a(NBTBase.java:112) 2013-03-13 18:33:50 [SEVERE] bq.a(NBTTagCompound.java:41) 2013-03-13 18:33:50 [SEVERE] cd.a(NBTBase.java:112) 2013-03-13 18:33:50 [SEVERE] ca.a(CompressedStreamTools.java:140) 2013-03-13 18:33:50 [SEVERE] aam.a(AnvilChunkLoader.java:274) 2013-03-13 18:33:50 [SEVERE] aam.c(AnvilChunkLoader.java:260) 2013-03-13 18:33:50 [SEVERE] aiw.b(ThreadedFileIOBase.java:39) 2013-03-13 18:33:50 [SEVERE] aiw.run(ThreadedFileIOBase.java:27) 2013-03-13 18:33:50 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:50 [SEVERE] ------------------------------ 2013-03-13 18:33:50 [SEVERE] Current Thread: RMI TCP Accept-0 2013-03-13 18:33:50 [SEVERE] PID: 13 | Alive: true | State: RUNNABLE 2013-03-13 18:33:50 [SEVERE] Stack: 2013-03-13 18:33:50 [SEVERE] java.net.DualStackPlainSocketImpl.accept0(Native Method) 2013-03-13 18:33:50 [SEVERE] java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.net.AbstractPlainSocketImpl.accept(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.net.PlainSocketImpl.accept(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.net.ServerSocket.implAccept(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.net.ServerSocket.accept(Unknown Source) 2013-03-13 18:33:50 [INFO] [GroupManager] Disabling GroupManager v2.0 (2.10.1) (Phoenix) 2013-03-13 18:33:50 [SEVERE] sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(Unknown Source) 2013-03-13 18:33:50 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 2013-03-13 18:33:50 [SEVERE] sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:50 [SEVERE] ------------------------------ 2013-03-13 18:33:50 [SEVERE] Current Thread: Attach Listener 2013-03-13 18:33:50 [SEVERE] PID: 6 | Alive: true | State: RUNNABLE 2013-03-13 18:33:50 [SEVERE] Stack: 2013-03-13 18:33:50 [SEVERE] ------------------------------ 2013-03-13 18:33:50 [SEVERE] Current Thread: pool-2-thread-1 2013-03-13 18:33:50 [SEVERE] PID: 44 | Alive: true | State: TIMED_WAITING 2013-03-13 18:33:50 [SEVERE] Stack: 2013-03-13 18:33:50 [SEVERE] sun.misc.Unsafe.park(Native Method) 2013-03-13 18:33:50 [SEVERE] java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source) 2013-03-13 18:33:50 [SEVERE] java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source) 2013-03-13 18:33:54 [INFO] GroupManager version 2.0 (2.10.1) (Phoenix) is disabled! 2013-03-13 18:33:54 [SEVERE] java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:54 [SEVERE] ------------------------------ 2013-03-13 18:33:54 [SEVERE] Current Thread: Snooper Timer 2013-03-13 18:33:54 [SEVERE] PID: 15 | Alive: true | State: TIMED_WAITING 2013-03-13 18:33:54 [SEVERE] Stack: 2013-03-13 18:33:54 [SEVERE] java.lang.Object.wait(Native Method) 2013-03-13 18:33:54 [SEVERE] java.util.TimerThread.mainLoop(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.util.TimerThread.run(Unknown Source) 2013-03-13 18:33:54 [SEVERE] ------------------------------ 2013-03-13 18:33:54 [INFO] [PerformanceMonitor] Disabling PerformanceMonitor v1.7.0 2013-03-13 18:33:54 [SEVERE] Current Thread: Thread-5 2013-03-13 18:33:54 [SEVERE] PID: 19 | Alive: true | State: TIMED_WAITING 2013-03-13 18:33:54 [INFO] [PerformanceMonitor 1.7.0] Plugin disabled! 2013-03-13 18:33:54 [SEVERE] Stack: 2013-03-13 18:33:54 [SEVERE] java.lang.Thread.sleep(Native Method) 2013-03-13 18:33:54 [SEVERE] hp.run(DedicatedServerSleepThread.java:23) 2013-03-13 18:33:54 [SEVERE] ------------------------------ 2013-03-13 18:33:54 [SEVERE] Current Thread: pool-4-thread-4 2013-03-13 18:33:54 [SEVERE] PID: 80 | Alive: true | State: TIMED_WAITING 2013-03-13 18:33:54 [SEVERE] Stack: 2013-03-13 18:33:54 [SEVERE] java.util.Arrays.copyOfRange(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.lang.String.(Unknown Source) 2013-03-13 18:33:54 [SEVERE] java.lang.String.substring(Unknown Source) 2013-03-13 18:33:54 [SEVERE] org.dynmap.web.HandlerRouter.handle(Unknown Source) 2013-03-13 18:33:54 [SEVERE] org.dynmap.web.FilterHandler$1.doFilter(Unknown Source) 2013-03-13 18:33:55 [SEVERE] org.dynmap.web.CustomHeaderFilter.doFilter(Unknown Source) 2013-03-13 18:33:55 [SEVERE] org.dynmap.web.FilterHandler$1.doFilter(Unknown Source) 2013-03-13 18:33:55 [INFO] Saving players 2013-03-13 18:33:59 [SEVERE] org.dynmap.web.BanIPFilter.doFilter(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.web.FilterHandler$1.doFilter(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.web.FilterHandler.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.handler.HandlerList.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.handler.HandlerWrapper.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.Server.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.AbstractHttpConnection.handleRequest(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.AbstractHttpConnection.headerComplete(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.http.HttpParser.parseNext(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.http.HttpParser.parseAvailable(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.AsyncHttpConnection.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.io.nio.SelectChannelEndPoint.handle(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.io.nio.SelectChannelEndPoint$1.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: pool-4-thread-6 2013-03-13 18:33:59 [SEVERE] PID: 82 | Alive: true | State: RUNNABLE 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] sun.misc.Unsafe.park(Native Method) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.LinkedBlockingQueue.poll(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: Immibis Core background task 2013-03-13 18:33:59 [SEVERE] PID: 22 | Alive: false | State: TERMINATED 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] java.io.PrintStream.write(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.io.PrintStream.print(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.ThreadGroup.uncaughtException(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.ThreadGroup.uncaughtException(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.dispatchUncaughtException(Unknown Source) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: Thread-11 2013-03-13 18:33:59 [SEVERE] PID: 29 | Alive: true | State: TIMED_WAITING 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.sleep(Native Method) 2013-03-13 18:33:59 [SEVERE] appeng.common.VersionChecker.run(VersionChecker.java:37) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: Spigot Watchdog Thread 2013-03-13 18:33:59 [SEVERE] PID: 35 | Alive: true | State: RUNNABLE 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.dumpThreads(Native Method) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.getAllStackTraces(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.util.WatchdogThread.run(WatchdogThread.java:60) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: pool-4-thread-2 Acceptor0 SelectChannelConnector@0.0.0.0:8125 2013-03-13 18:33:59 [SEVERE] PID: 54 | Alive: true | State: RUNNABLE 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) 2013-03-13 18:33:59 [SEVERE] sun.nio.ch.ServerSocketChannelImpl.accept(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.nio.SelectChannelConnector.accept(Unknown Source) 2013-03-13 18:33:59 [SEVERE] org.dynmap.jetty.server.AbstractConnector$Acceptor.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:33:59 [SEVERE] ------------------------------ 2013-03-13 18:33:59 [SEVERE] Current Thread: Thread-6 2013-03-13 18:33:59 [SEVERE] PID: 21 | Alive: true | State: RUNNABLE 2013-03-13 18:33:59 [SEVERE] Stack: 2013-03-13 18:33:59 [SEVERE] java.io.FileInputStream.readBytes(Native Method) 2013-03-13 18:33:59 [SEVERE] java.io.FileInputStream.read(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.io.BufferedInputStream.fill(Unknown Source) 2013-03-13 18:33:59 [SEVERE] java.io.BufferedInputStream.read(Unknown Source) 2013-03-13 18:34:03 [SEVERE] java.io.FilterInputStream.read(Unknown Source) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader$1.read(ConsoleReader.java:167) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.internal.InputStreamReader.read(InputStreamReader.java:267) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.internal.InputStreamReader.read(InputStreamReader.java:204) 2013-03-13 18:34:03 [INFO] Unloading Player: Xathras420 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader.readCharacter(ConsoleReader.java:995) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader.readLineSimple(ConsoleReader.java:1506) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader.readLine(ConsoleReader.java:1153) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader.readLine(ConsoleReader.java:1117) 2013-03-13 18:34:03 [SEVERE] org.bukkit.craftbukkit.libs.jline.console.ConsoleReader.readLine(ConsoleReader.java:1105) 2013-03-13 18:34:03 [SEVERE] hq.run(DedicatedServerCommandThread.java:41) 2013-03-13 18:34:03 [SEVERE] ------------------------------ 2013-03-13 18:34:03 [SEVERE] Current Thread: pool-4-thread-3 2013-03-13 18:34:03 [SEVERE] PID: 79 | Alive: true | State: TIMED_WAITING 2013-03-13 18:34:03 [SEVERE] Stack: 2013-03-13 18:34:03 [SEVERE] sun.misc.Unsafe.park(Native Method) 2013-03-13 18:34:03 [SEVERE] java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source) 2013-03-13 18:34:03 [SEVERE] java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source) 2013-03-13 18:34:03 [SEVERE] java.util.concurrent.LinkedBlockingQueue.poll(Unknown Source) 2013-03-13 18:34:08 [INFO] Saving worlds 2013-03-13 18:34:08 [SEVERE] java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source) 2013-03-13 18:34:08 [INFO] Saving chunks for level 'world'/Overworld 2013-03-13 18:34:08 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:34:08 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:34:12 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:34:12 [SEVERE] ------------------------------ 2013-03-13 18:34:12 [SEVERE] Current Thread: HashSessionScavenger-0 2013-03-13 18:34:12 [SEVERE] PID: 52 | Alive: true | State: TIMED_WAITING 2013-03-13 18:34:12 [SEVERE] Stack: 2013-03-13 18:34:12 [SEVERE] java.lang.Object.wait(Native Method) 2013-03-13 18:34:12 [SEVERE] java.util.TimerThread.mainLoop(Unknown Source) 2013-03-13 18:34:12 [SEVERE] java.util.TimerThread.run(Unknown Source) 2013-03-13 18:34:12 [SEVERE] ------------------------------ 2013-03-13 18:34:12 [SEVERE] Current Thread: Chunk I/O Executor Thread-1 2013-03-13 18:34:12 [SEVERE] PID: 78 | Alive: true | State: RUNNABLE 2013-03-13 18:34:12 [SEVERE] Stack: 2013-03-13 18:34:12 [SEVERE] cd.a(NBTBase.java:128) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:83) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] by.a(NBTTagList.java:67) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] by.a(NBTTagList.java:67) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] by.a(NBTTagList.java:67) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] bq.a(NBTTagCompound.java:55) 2013-03-13 18:34:12 [SEVERE] cd.b(NBTBase.java:87) 2013-03-13 18:34:12 [SEVERE] ca.a(CompressedStreamTools.java:126) 2013-03-13 18:34:15 [SEVERE] aam.loadChunk__Async_CB(AnvilChunkLoader.java:124) 2013-03-13 18:34:15 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.chunkio.ChunkIOProvider.callStage1(ChunkIOProvider.java:16) 2013-03-13 18:34:15 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.chunkio.ChunkIOProvider.callStage1(ChunkIOProvider.java:10) 2013-03-13 18:34:18 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.util.AsynchronousExecutor$Task.init(AsynchronousExecutor.java:150) 2013-03-13 18:35:04 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.util.AsynchronousExecutor$Task.initAsync(AsynchronousExecutor.java:95) 2013-03-13 18:35:04 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.util.AsynchronousExecutor$Task.run(AsynchronousExecutor.java:85) 2013-03-13 18:35:04 [SEVERE] java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 2013-03-13 18:35:00 [SEVERE] java.lang.OutOfMemoryError: Java heap space 2013-03-13 18:35:04 [SEVERE] java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 2013-03-13 18:35:12 [SEVERE] java.lang.Thread.run(Unknown Source) 2013-03-13 18:35:12 [SEVERE] ------------------------------ 2013-03-13 18:35:12 [SEVERE] Current Thread: Listen thread 2013-03-13 18:35:17 [SEVERE] PID: 34 | Alive: false | State: TERMINATED 2013-03-13 18:35:24 [SEVERE] Stack: 2013-03-13 18:35:24 [SEVERE] java.util.logging.StreamHandler.publish(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.util.logging.ConsoleHandler.publish(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.util.logging.Logger.log(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.util.logging.Logger.doLog(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.util.logging.Logger.logp(Unknown Source) 2013-03-13 18:35:24 [SEVERE] org.bukkit.craftbukkit.v1_4_R1.LoggerOutputStream.flush(LoggerOutputStream.java:27) 2013-03-13 18:35:24 [SEVERE] java.io.PrintStream.write(Unknown Source) 2013-03-13 18:35:24 [SEVERE] sun.nio.cs.StreamEncoder.writeBytes(Unknown Source) 2013-03-13 18:35:24 [SEVERE] sun.nio.cs.StreamEncoder.implWrite(Unknown Source) 2013-03-13 18:35:24 [SEVERE] sun.nio.cs.StreamEncoder.write(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.io.OutputStreamWriter.write(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.io.BufferedWriter.flushBuffer(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.io.PrintStream.write(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.io.PrintStream.print(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.lang.ThreadGroup.uncaughtException(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.lang.ThreadGroup.uncaughtException(Unknown Source) 2013-03-13 18:35:24 [SEVERE] java.lang.Thread.dispatchUncaughtException(Unknown Source) 2013-03-13 18:35:24 [SEVERE] ------------------------------ 2013-03-13 18:35:24 [SEVERE] Current Thread: Connection #14 read thread 2013-03-13 18:35:24 [SEVERE] PID: 307 | Alive: true | State: TIMED_WAITING 2013-03-13 18:35:24 [SEVERE] Stack: 2013-03-13 18:35:24 [SEVERE] java.lang.Thread.sleep(Native Method) 2013-03-13 18:35:24 [SEVERE] ch.run(TcpReaderThread.java:27) 2013-03-13 18:35:24 [SEVERE] ------------------------------ 2013-03-13 18:35:20 [INFO] Stopping server

Haruchai commented 11 years ago

First try was a bust. I missed something in the swap...working on it.

WebMaka commented 11 years ago

My test machine went down overnight from a power failure so I'll relaunch it with the Forge Dynmap.

BBBRV commented 11 years ago

@WebMaka sounds good. I would test it on my server but I have a busy day at work and can't remote in to restart it if it crashes.

WebMaka commented 11 years ago

Once a second this drops into the console...

2013-03-19 11:23:58 [SEVERE] [dynmap] Exception while loading chunks java.lang.IllegalAccessError: tried to access field zx.a from class org.dynmap.forge.ChunkSnapshot at org.dynmap.forge.ChunkSnapshot.(ChunkSnapshot.java:169) at org.dynmap.forge.ForgeMapChunkCache.loadChunks(ForgeMapChunkCache.java:1427) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:612) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:599) at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) at java.util.concurrent.FutureTask.run(Unknown Source) at org.dynmap.forge.DynmapPlugin$ForgeServer.tickEnd(DynmapPlugin.java:706) at cpw.mods.fml.common.SingleIntervalHandler.tickEnd(SingleIntervalHandler.java:22) at cpw.mods.fml.common.FMLCommonHandler.tickEnd(FMLCommonHandler.java:139) at cpw.mods.fml.common.FMLCommonHandler.onPostServerTick(FMLCommonHandler.java:275) at net.minecraft.server.MinecraftServer.q(MinecraftServer.java:892) at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:744) at fy.run(ThreadMinecraftServer.java:16)

(Using MCPC 1.4.7b245, FTB Ultimate 1.0.1, and the latest Forge dev build of Dynmap.)

BBBRV commented 11 years ago

Ah yeah that was the same error I had after switching from Bukkitforge to MCPC.

Haruchai commented 11 years ago

After blaming my wife, kids, parents and the government for my inability to get Dynmap to work on Forge (I just had it running a few days ago!), I realized I had d/l the version for MC server 1.5.

After correcting that mistake, I blistered a 3k radius surface map and had not one error. Memory levels were nice and low..

BTW, used the latest Dynmap Forge test build v1.6-alpha 1 (as is listed on the MC forum page)

BBBRV commented 11 years ago

amazing. I will do this as soon as i get a chance.

BBBRV commented 11 years ago

Nope :( getting the same error i was before.

[SEVERE] [dynmap] Exception while loading chunks java.lang.IllegalAccessError: tried to access field zx.a from class org.dynmap.forge.ChunkSnapshot at org.dynmap.forge.ChunkSnapshot.(ChunkSnapshot.java:169) at org.dynmap.forge.ForgeMapChunkCache.loadChunks(ForgeMapChunkCache.java:1427) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:612) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:599) at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) at java.util.concurrent.FutureTask.run(Unknown Source) at org.dynmap.forge.DynmapPlugin$ForgeServer.tickEnd(DynmapPlugin.java:706) at cpw.mods.fml.common.SingleIntervalHandler.tickEnd(SingleIntervalHandler.java:22) at cpw.mods.fml.common.FMLCommonHandler.tickEnd(FMLCommonHandler.java:139) at cpw.mods.fml.common.FMLCommonHandler.onPostServerTick(FMLCommonHandler.java:275) at net.minecraft.server.MinecraftServer.q(MinecraftServer.java:892) at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:744) at fy.run(ThreadMinecraftServer.java:16)

Using the same setup as WebMaka - MCPC v244 (latest recommended) FTB Ultimate 1.01, and latest dev version of dynmap (v1.6-a1)

BBBRV commented 11 years ago

@Haruchai what is your server setup like, plugin and mod wise? if yours is working i'd like to figure out why mine isn't.

WebMaka commented 11 years ago

I also made it a point to grab the 1.4.7 version of the Dynmap Forge dev build, BTW. The server isn't crashing out but Dynmap is not rendering a thing.

BBBRV commented 11 years ago

weird. I'm not getting the spam i pasted earlier, but dynmap also is not rendering anything.

edit: scratch that. had it paused. spam is still persisting after a server restart.

Haruchai commented 11 years ago

Ok, this will take a bit...bear with me.

--->My FTB/Ultimate server:

-All the standard mods that come with that package.

-I pulled "ftbserver.jar" out and placed MCPC+ 1.4.7-R1.1-SNAPSHOT-f534-246 in its place. (Because I use McMyAdmin as a management tool, I had to rename the MCPC+ file to "FTB-Beta-A". Evidently, MCMA and FTB are snobby at each other...blah blah. Anyway, that's how you have to do it so MCMA will recognize the file.)

-Through the MCMA plugin panel, I loaded the following bukkit plugins: WorldGuard, WorldEdit, WorldBorder. Dynmap v1.6-621 (manual install) at first. Later, as MP released them, I moved to build number 623 (which wasn't perfect, but a huge improvement).

-Using WorldBorder, I performed a 2k round radius render.

--->FTB/Ultimate Forge setup

-stock mod pack with only two additions: MyTown and PEX (Forge version). MyTown was used to render a 3k circle world. (not as good a tool as WorldBorder)

-Dynmap1.6-177 (Forge) installed.

-I was not able to run Dynmap with MyTown simultaneously as OOM's would happen. After MyTown finished, I enabled Dynmap and did a fullrender on both flat and surface. There were no memory issues (never rose above 50% allocation during a 3k surface render).

So, I guess it boils down to MCPC+ as the wild card. Although the bukkit plugins were installed, I doubt they were having an influence. One nice thing about MCPC+...no memory leaks. FTB server files are notorious and even in a pristine world I am getting memory leaks. I think I'll pass this info along to FTB and MCPC+.

BBBRV commented 11 years ago

Ah i see. So you got it working with the forge version, but without MCPC+? Because this worked fine for me as well (although we used Bukkitforge at the time, found MCPC to be much more stable), it was only after switching to MCPC that dynmap stopped working for me - on both Forge and Bukkit/MCPC versions.

Haruchai commented 11 years ago

The flat map rendering works in MCPC+....mostly, kinda, sorta. It gradually runs out of memory but takes a while. The surface map is another issue, however. Because the tiles have such a higher resolution, Dynmap tanks with OOM/Heap errors fairly quickly. Although, as I mentioned, MP's two releases last night really improved the situation.

As you can see, I left a little note on the MCPC+ page with the hope that someone there has a bit of insight. Once we get this issue resolved, I'm going to be a happy camper to get away from the FTB server file and all those world leaks.

WebMaka commented 11 years ago

Just posted this over on the MCPC+ github, but it could also be useful here:

Heapdump: http://actium.is-into-games.com/debuginfo/heapdump-1363792974182.hprof

Forge FML log: http://actium.is-into-games.com/debuginfo/ForgeModLoader-server-0.log

Server log: http://actium.is-into-games.com/debuginfo/server.log

Hopefully there's useful info in there somewhere...

Haruchai commented 11 years ago

Latest tests:

MCPC+ -1.4.7-R1.1-SNAPSHOT-f534-247 Dynmap v1.6-624 2G memory allocation (which mimics our commercially hosted server space) Fullrender Surface map 2k radius round (WorldBorder 1.6.1)

Server log results:

1st run: http://pastebin.com/jZPYbLJe

2nd run: http://pastebin.com/v2ur98tb

3rd run: http://pastebin.com/977PbYaB

Unfortunately, none of the three time resulted in a write to the crash log and I could not get it to print a heap dump. If anyone can help in that area I'd be happy to give it a go.

mikeprimm commented 11 years ago

@WebMaka - cool - I'll see if I can find the time to download the heap dump and give it a look.

Edit: Except none of the links work - still uploading?

WebMaka commented 11 years ago

Sorry 'bout that - never occurred to me that IIS7 doesn't natively include a MIME type for Java profile files or LOG files, so I had to add them. The links should work fine now.

BTW, the heapdump file is 4.3GB, so plan accordingly... ;-)

WebMaka commented 11 years ago

@Haruchai Add these to your command-line for launching the server:

-Djline.terminal=jline.UnsupportedTerminal -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=12321 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -Djava.rmi.server.hostname=localhost

Then you can use VisualVM (http://visualvm.java.net/) to connect to the JMX management port on port 12321 when the Minecraft server is running. That will allow you to pull a heap dump right out of the Java VM, as well as allow live profiling of processor and memory usage, thread states, etc. etc. etc.

This assumes, of course, that you have direct access to the machine the MC server's running on. If you're renting a server, you'll may need to edit the parameters a bit and will probably have to ask your host for an open port to use to connect via VisualVM.

WebMaka commented 11 years ago

Since it was requested...

ZIPped heapdump: http://actium.is-into-games.com/debuginfo/heapdump-1363792974182.zip (381MB)

Haruchai commented 11 years ago

Latest Test (and thanks WM):

mcpc-plus-1.4.7-R1.1-SNAPSHOT-f534-247 Dynmap v1.6-625

Server log: http://pastebin.com/eYCuY6mK

HeapDump: https://docs.google.com/file/d/0B_8t07me6_wFWk1HdFh2dnc1a2c/edit?usp=sharing

Let me know if that HeapDump link doesn't work. File size ~46.5 MB

Haruchai commented 11 years ago

Last one for the night. It appears v625 is a step back. Crashing fairly early. Thanks for all the effort, MP!

Server log: http://pastebin.com/bF7dse1G

HeapDump (~140MB): https://docs.google.com/file/d/0B_8t07me6_wFTlJBM1hXTElVT3c/edit?usp=sharing

mikeprimm commented 11 years ago

Please try with latest development build of Forge 1.4.6 version (with MCPC+).

Haruchai commented 11 years ago

---Using this file: Minecraft v1.4.7 with Forge v6.6.0+: Dynmap v1.6-alpha-2 (from the development build section):

Placing the Forge version of Dymap into the "mods" folder with a MCPC+ server file = immediate crash. Placing the Forge version of Dymap into the plugins folder with MCPC+ server file = no recognition of Dynmap being loaded (not mentioned in the server log) and no generation of the Dynmap config files.

---Using this version: Minecraft v1.4.6/1.4.7 with Forge v6.5.0/v6.6.0+ (from the alpha builds section)

If placed in the mods folder, Dynmap is recognized/registered, but the following error occurs if a fullrender command is given:

2013-03-21 02:44:26 [INFO] Full render starting on world 'Fiddlesticks'... 2013-03-21 02:44:26 [SEVERE] [dynmap] Exception while loading chunks java.lang.IllegalAccessError: tried to access field zx.a from class org.dynmap.forge.ChunkSnapshot at org.dynmap.forge.ChunkSnapshot.(ChunkSnapshot.java:169) at org.dynmap.forge.ForgeMapChunkCache.loadChunks(ForgeMapChunkCache.java:1427) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:612) at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:599) at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) at java.util.concurrent.FutureTask.run(Unknown Source) at org.dynmap.forge.DynmapPlugin$ForgeServer.tickEnd(DynmapPlugin.java:706) at cpw.mods.fml.common.SingleIntervalHandler.tickEnd(SingleIntervalHandler.java:22) at cpw.mods.fml.common.FMLCommonHandler.tickEnd(FMLCommonHandler.java:139) at cpw.mods.fml.common.FMLCommonHandler.onPostServerTick(FMLCommonHandler.java:275) at net.minecraft.server.MinecraftServer.q(MinecraftServer.java:892) at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:744) at fy.run(ThreadMinecraftServer.java:16)

If placed in the plugins folder, Dynmap doesn't register.

mikeprimm commented 11 years ago

Build server issue - the build was bad. Trying to fix it now.

Edit: OK - try build 183 or later

Haruchai commented 11 years ago

Please clarify. Is that #183 of the Forge build or MCPC+ build. Also, I have been d/l from your MC forum site and that site doesn't show build numbers. Do you have a jenkins or some other site that shows build number?

I'll go ahead and start runs on the Forge versions.

mikeprimm commented 11 years ago

Forge on 1.4.6/7 - don't bother with Bukkit version: I'm throwing in the towel on trying to support MCPC+ via the Bukkit version.

Haruchai commented 11 years ago

An improvement, no doubt about it. A surface fullrender ran for 50+ minutes before tanking with this error:

2013-03-21 13:35:26 [INFO] Attempted to place a tile entity (com.xcompwiz.mystcraft.tileentity.TileEntityDesk@3734013c) at -1536,72,-1370 (X1283) where there was no entity tile! 2013-03-21 13:35:26 [INFO] Chunk coordinates: -1536,-1376 2013-03-21 13:35:26 [SEVERE] java.lang.Exception 2013-03-21 13:35:26 [SEVERE] at zz.a(Chunk.java:1086) 2013-03-21 13:35:26 [SEVERE] at yc.a(World.java:3291) 2013-03-21 13:35:26 [SEVERE] at com.xcompwiz.mystcraft.block.BlockWritingDesk.g(BlockWritingDesk.java:220) 2013-03-21 13:35:26 [SEVERE] at zz.a(Chunk.java:784) 2013-03-21 13:35:26 [SEVERE] at yc.a(World.java:762) 2013-03-21 13:35:26 [SEVERE] at yc.c(World.java:740) 2013-03-21 13:35:26 [SEVERE] at aez.a(StructureComponent.java:544) 2013-03-21 13:35:26 [SEVERE] at afs.a(ComponentVillage.java:220) 2013-03-21 13:35:26 [SEVERE] at com.xcompwiz.mystcraft.world.gen.structure.ComponentVillageArchivistHouse.placeDeskAt(ComponentVillageArchivistHouse.java:187) 2013-03-21 13:35:26 [SEVERE] at com.xcompwiz.mystcraft.world.gen.structure.ComponentVillageArchivistHouse.a(ComponentVillageArchivistHouse.java:118) 2013-03-21 13:35:26 [SEVERE] at afb.a(StructureStart.java:35) 2013-03-21 13:35:26 [SEVERE] at aev.a(MapGenStructure.java:71) 2013-03-21 13:35:26 [SEVERE] at abb.a(ChunkProviderGenerate.java:533) 2013-03-21 13:35:26 [SEVERE] at org.bukkit.craftbukkit.v1_4_R1.generator.NormalChunkGenerator.a(NormalChunkGenerator.java:46) 2013-03-21 13:35:26 [SEVERE] at im.a(ChunkProviderServer.java:341) 2013-03-21 13:35:26 [SEVERE] at zz.a(Chunk.java:1318) 2013-03-21 13:35:26 [SEVERE] at im.getChunkAt(ChunkProviderServer.java:219) 2013-03-21 13:35:26 [SEVERE] at im.c(ChunkProviderServer.java:136) 2013-03-21 13:35:26 [SEVERE] at org.dynmap.forge.ForgeMapChunkCache.loadChunkNoGenerate(ForgeMapChunkCache.java:1141) 2013-03-21 13:35:26 [SEVERE] at org.dynmap.forge.ForgeMapChunkCache.loadChunks(ForgeMapChunkCache.java:1346) 2013-03-21 13:35:26 [SEVERE] at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:613) 2013-03-21 13:35:26 [SEVERE] at org.dynmap.forge.DynmapPlugin$ForgeServer$1.call(DynmapPlugin.java:600) 2013-03-21 13:35:26 [SEVERE] at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) 2013-03-21 13:35:26 [SEVERE] at java.util.concurrent.FutureTask.run(Unknown Source) 2013-03-21 13:35:26 [SEVERE] at org.dynmap.forge.DynmapPlugin$ForgeServer.tickEnd(DynmapPlugin.java:707) 2013-03-21 13:35:26 [SEVERE] at cpw.mods.fml.common.SingleIntervalHandler.tickEnd(SingleIntervalHandler.java:22) 2013-03-21 13:35:26 [SEVERE] at cpw.mods.fml.common.FMLCommonHandler.tickEnd(FMLCommonHandler.java:139) 2013-03-21 13:35:26 [SEVERE] at cpw.mods.fml.common.FMLCommonHandler.onPostServerTick(FMLCommonHandler.java:275) 2013-03-21 13:35:26 [SEVERE] at net.minecraft.server.MinecraftServer.q(MinecraftServer.java:892) 2013-03-21 13:35:26 [SEVERE] at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:744) 2013-03-21 13:35:26 [SEVERE] at fy.run(ThreadMinecraftServer.java:16)

As I mentioned in an earlier post, after memory hits 100% of the allocation, the rendering process becomes erratic. Tiles will be rendered in random patterns/areas and rendered tiles will even appear in the flat or surface maps. Regardless, this is the longest that a surface render has ran before bugging out.

Do you want to see the HeapDump from this run?

mikeprimm commented 11 years ago

Having a hard time seeing that as being caused by us - that is a chunk data integrity issue (the chunk has tile entity data for a block that isn't supposed to have tile entity data). All we've done is requested that the chunk be loaded, so there is no way for us to cause that.

Haruchai commented 11 years ago

I'll run another. Also, Dynmap/Forge with Forge server never goes over 50% of the memory allocation. This Forge/MCPC+ hybrid climbs to 100% in 15-20 minutes, but seems to be able to continue running for quite a while.

Will keep you posted.

BBBRV commented 11 years ago

@Haruchai Yeah, that error isn't dynmap related, I get that occasionally without dynmap installed - though it very rarely causes a crash for me. Glad to see the Forge/MCPC hybrid is coming along nicely though, may have to give it a shot tonight.

Haruchai commented 11 years ago

v 1.6-183 is looking to be the best yet. 1 hour and 43 minutes into a surface render and no errors. Heap size is floating between 1.8 and 2GB with used heap 1.2 - 1.6. So, not quite as good as Forge on Forge, but a big improvement. Great work!

I'll be visiting family the next few days and won't be able to run any tests for you. My apologies.

BBBRV commented 11 years ago

I'll do some testing tonight.

BBBRV commented 11 years ago

15 minutes into testing, so far so good. Will update periodically.

36 minutes in and still trucking - came dangerously low at once point (900MB) but jumped back up to 5GB just in time.

mikeprimm commented 11 years ago

Do remember that java is garbage collection based - it will grow its heap until it needs memory, and will clean up when that happens, so the "grow until nearly full, then suddenly shrink" cycle is standard. It just that loading and unloading lots of chunks while doing a render drives the cycle quicker.

BBBRV commented 11 years ago

Ah, I see. Does it do that at a certain percentage left? I wonder if I will even crash with 9.1GB allocated.

mikeprimm commented 11 years ago

If you give it 1GB, it'll grow until its just about full and then garbage collect. If you give it 8GB, it'll do the same - it'll just take longer. There are loads of controls on the java command line to manipulate GC behavior, although I find the defaults to be fine for Java 7 (Java 6 definitely benefited from tweaking).

BBBRV commented 11 years ago

Ah okay, unfortunately I don't know much about java, at least not as much as I would like to know that's for sure. But, 55 minutes in and still going, though we're down to 8 TPS at this point.

mikeprimm commented 11 years ago

Right - needing to GC isn't something that will drive a crash: its just normal behavior for java to assume that, since you said it could use N GB of RAM, that its free to do so, and that working to collect garbage, when there is still more memory available, isn't worth wasting time on (it takes CPU processing time to identify and recover the garbage). Now, if running the GC when the VM needs memory fails to recover enough to fill the request that drove the GC, then you crash out with an OOM exception. Alternately, if you are so short on free memory that the GC winds up running over and over just to get small bits of memory, you can also see an exception from that (and while that is starting to happen, system performance will definitely suffer).

BBBRV commented 11 years ago

Ahhh, alright I think I understand now :) I definitely agree with Haruchai on this build being a huge improvement, dont think I even made it to 20 minutes before running out of memory previously.

BBBRV commented 11 years ago

1 hour 35 minutes, crashed. D:

edit: It did generate a crash log. Here it is in case you want to see it.

http://pastebin.com/QXER7Ci5

mikeprimm commented 11 years ago

Question is - if you leave everything the same, but switch from MCPC+ to normal Forge, do you have the same issue? If so, we might be a factor (or another mod that leaks memory when chunks are loaded and unloaded....) - if not, its either MCPC+ or a consequence of a mod interaction with MCPC+ that results in leaked memory (my money is on the latter).

BBBRV commented 11 years ago

I'm going to assume it is MCPC or Xycraft.. I wasnt having any trouble using dynmap with Forge and Bukkitforge a month or two ago, but i recently switched to MCPC for various reasons:

A) Exploring with Bukkitforge caused tremendous lag (dropping us down to 5 TPS and under very quickly) B) Tried to solve problem A with worldborder. Could not generate terrain using Bukkitforge. C) Coreprotect did not work properly on Bukkitforge either.

Only noticed dynmap not working properly after switching to MCPC, however we also switched to the ultimate pack which in turn updated xycraft (which has been known to cause a lot of issues with chunk loading problems). So I guess it's either MCPC+ or Xycraft, I'm leaning towards Xycraft because of all the errors we get from it without even having Dynmap installed.

mikeprimm commented 11 years ago

If you guys take the latest stuff (MCPC+ with utilmate and my latest Forge dev build), run until it looks really bad, and grab a heap dump, I'll try to see if I can figure it out. I didn't crawl into the last ones because I'd already decided to switch supporting MCPC+ from being based on the Bukkit mod to being based on the Forge mod (and I'm developing a Bukkit compatible "bridge" mod to enable Dynmap-aware Bukkit mods to work with the Forge-based Dynmap on things like MCPC+ and BukkitForge - first drop should be this weekend, along with 1.6-alpha-2). So, I'm ready to at least try to figure out where the bleeding is - it'd be nice for everyone to get it addressed (even if it turns out to be an interaction issue between XyCraft and MCPC+ that we happen to drive to failure due to loading and unloading lots of chunks). What matters is getting everyone working nicely - don't really care who is at fault :)

BBBRV commented 11 years ago

Oh I totally agree, if I knew how to do a heap dump I would. I believe i heard somewhere that Soaryn had a fix for Xycraft in the next build of it, but who knows when that will get pushed to a new Ultimate pack build.

BBBRV commented 11 years ago

Another crash around the 1 hour 20 minute mark. Was talking to my boss so didn't catch the exact time. :(

BBBRV commented 11 years ago

Changing my automatic restart time to every hour to prevent crashes while this renders.

Haruchai commented 11 years ago

@Absolutist Visiting my daughter and everyone is in bed...so I lied, it won't be a few days... :). First, Ab, look above a few posts. You see WebMaka give me instructions on how to generate a heapdump. Believe me, if I can do it, anyone can.

I am going to do a remote login to my home computer and run another test. I'll let it go as long as it wants. If it runs two or three hours before crashing, the heapdumps can result in a substantial-sized file.

kencinder commented 11 years ago

Switched from the Bukkit build to Forge build 1.6-185, and I'm seeing a very slow and steady increase in memory usage, much more gradual than it was before but steadily climbing. Definitely need that bridge though, as all the towny/worldguard stuff is no longer present and that sucks.

Edit: After about 45-50 minutes it runs out of memory and crashes during a fullrender.

snake2332 commented 11 years ago

I haven't tried the Forge version yet, but am attempting to use the bukkit version DynMap v1.5-612 with my MCPC+ build 245 server based off of FTB Ultimate with about 20 other mods installed and maybe a dozen bukkit plugins. Naturally, I have the problems with the memory leak. I set the texture resolution to lowres instead of hires and it actually works fine. We have a new world and I haven't done any radius renders (didn't know you could do that actually).

I will switch to the Forge version and attempt hires textures and see what happens.

Now if only all the Biomes O' Plenty textures would render, I'd be happy...