Add tick list monitoring - deal with 1.0.0 getting behind when rendering

src/main/java/org/dynmap/MapManager.java

@@ -1,6 +1,7 @@
 package org.dynmap;
 
 import java.io.File;
+import java.lang.reflect.Field;
 import java.util.ArrayList;
 import java.util.Collection;
 import java.util.Collections;
@@ -70,6 +71,7 @@ public class MapManager {
     AtomicInteger chunks_attempted = new AtomicInteger(0);
     AtomicLong total_loadtime_ns = new AtomicLong(0L);
     AtomicLong total_exceptions = new AtomicLong(0L);
+    AtomicInteger ticklistcalls = new AtomicInteger(0);
     
     /* Tile hash manager */
     public TileHashManager hashman;
@@ -362,13 +364,11 @@ public class MapManager {
                         double msecpertile = (double)timeaccum / (double)((rendercnt>0)?rendercnt:1)/(double)activemapcnt;
                         double rendtime = total_render_ns.doubleValue() * 0.000001 / rendercalls.get();
                         if(activemapcnt > 1)
-                            sendMessage(rendertype + " of maps [" + activemaps + "] of '" +
+                            sendMessage(String.format("%s of maps [%s] of '%s' completed - %d tiles rendered each (%.2f msec/map-tile, %.2f msec per render)",
-                               world.world.getName() + "' completed - " + rendercnt + " tiles rendered each (" + String.format("%.2f", msecpertile) + " msec/map-tile, "
+                                    rendertype, activemaps, world.world.getName(), rendercnt, msecpertile, rendtime));
-                               + rendtime +" msec per render)");
                         else
-                            sendMessage(rendertype + " of map '" + activemaps + "' of '" +
+                            sendMessage(String.format("%s of map '%s' of '%s' completed - %d tiles rendered (%.2f msec/map-tile, %.2f msec per render)",
-                                 world.world.getName() + "' completed - " + rendercnt + " tiles rendered (" + String.format("%.2f", msecpertile) + " msec/tile. "
+                                    rendertype, activemaps, world.world.getName(), rendercnt, msecpertile, rendtime));
-                                 + rendtime +" msec per render)");
 
                     }                	
                     found.clear();
@@ -584,13 +584,11 @@ public class MapManager {
                             double rendtime = total_render_ns.doubleValue() * 0.000001 / rendercalls.get();
                             double msecpertile = (double)timeaccum / (double)rendercnt / (double)activemapcnt;
                             if(activemapcnt > 1) 
-                                sendMessage(rendertype + " of maps [" + activemaps + "] of '" +
+                                sendMessage(String.format("%s of maps [%s] of '%s' in progress - %d tiles rendered each (%.2f msec/map-tile, %.2f msec per render)",
-                                               w.getName() + "' in progress - " + rendercnt + " tiles rendered each (" + String.format("%.2f", msecpertile) + " msec/map-tile, "
+                                        rendertype, activemaps, world.world.getName(), rendercnt, msecpertile, rendtime));
-                                               + rendtime +" msec per render)");
                             else
-                                sendMessage(rendertype + " of map '" + activemaps + "' of '" +
+                                sendMessage(String.format("%s of map '%s' of '%s' in progress - %d tiles rendered (%.2f msec/tile, %.2f msec per render)",
-                                               w.getName() + "' in progress - " + rendercnt + " tiles rendered (" + String.format("%.2f", msecpertile) + " msec/tile. "
+                                        rendertype, activemaps, world.world.getName(), rendercnt, msecpertile, rendtime));
-                                               + rendtime +" msec per render)");
                         }
                     }
                 }
@@ -1161,7 +1159,7 @@ public class MapManager {
         		return null;
         	}
             if(delay)
-                try { Thread.sleep(50); } catch (InterruptedException ix) {}
+                try { Thread.sleep(25); } catch (InterruptedException ix) {}
     	}
         return c;
     }
@@ -1198,36 +1196,37 @@ public class MapManager {
                 if((prefix != null) && !k.startsWith(prefix))
                     continue;
                 MapStats ms = mapstats.get(k);
-                sender.sendMessage("  " + k + ": processed=" + ms.loggedcnt + ", rendered=" + ms.renderedcnt + 
+                sender.sendMessage(String.format("  %s: processed=%d, rendered=%d, updated=%d, transparent=%d",
-                               ", updated=" + ms.updatedcnt + ", transparent=" + ms.transparentcnt);
+                        k, ms.loggedcnt, ms.renderedcnt, ms.updatedcnt, ms.transparentcnt));
                 tot.loggedcnt += ms.loggedcnt;
                 tot.renderedcnt += ms.renderedcnt;
                 tot.updatedcnt += ms.updatedcnt;
                 tot.transparentcnt += ms.transparentcnt;
             }
         }
-        sender.sendMessage("  TOTALS: processed=" + tot.loggedcnt + ", rendered=" + tot.renderedcnt + 
+        sender.sendMessage(String.format("  TOTALS: processed=%d, rendered=%d, updated=%d, transparent=%d",
-                           ", updated=" + tot.updatedcnt + ", transparent=" + tot.transparentcnt);
+                tot.loggedcnt, tot.renderedcnt, tot.updatedcnt, tot.transparentcnt));
-        sender.sendMessage("  Triggered update queue size: " + tileQueue.size());
+        sender.sendMessage(String.format("  Triggered update queue size: %d", tileQueue.size()));
         String act = "";
         for(String wn : active_renders.keySet())
         	act += wn + " ";
-        sender.sendMessage("  Active render jobs: " + act);
+        sender.sendMessage(String.format("  Active render jobs: %s", act));
         /* Chunk load stats */
         sender.sendMessage("Chunk Loading Statistics:");
-        sender.sendMessage("  Cache hit rate: " + sscache.getHitRate() + "%");
+        sender.sendMessage(String.format("  Cache hit rate: %.2f%%", sscache.getHitRate()));
         int setcnt = chunk_caches_attempted.get();
-        sender.sendMessage("  Chunk sets: created=" + chunk_caches_created.get() + ", attempted=" + chunk_caches_attempted.get());
+        sender.sendMessage(String.format("  Chunk sets: created=%d, attempted=%d", chunk_caches_created.get(), chunk_caches_attempted.get()));
         int readcnt = chunks_read.get();
-        sender.sendMessage("  Chunk: loaded=" + readcnt + ", attempted=" + chunks_attempted.get());
+        sender.sendMessage(String.format("  Chunk: loaded=%d, attempted=%d", readcnt, chunks_attempted.get()));
         double ns = total_loadtime_ns.doubleValue() * 0.000001;    /* Convert to milliseconds */
         double chunkloadns = total_chunk_cache_loadtime_ns.doubleValue() * 0.000001;
         if(readcnt == 0) readcnt = 1;
         if(setcnt == 0) setcnt = 1;
-        sender.sendMessage("  Chunk load times: " + ns + " msec (" + (ns / readcnt) + " msec/chunk)");
+        sender.sendMessage(String.format("  Chunk load times: %.2f msec (%.2f msec/chunk)", ns, (ns / readcnt)));
-        sender.sendMessage("  Chunk set load times: " + chunkloadns + " msec (" + (chunkloadns / setcnt) + " msec/set)");
+        sender.sendMessage(String.format("  Chunk set load times: %.2f msec (%.2f msec/set)", chunkloadns, (chunkloadns / setcnt)));
-        sender.sendMessage("  Chunk set delay times: " + (chunkloadns-ns) + " msec (" + ((chunkloadns-ns) / setcnt) + " msec/set)");
+        sender.sendMessage(String.format("  Chunk set delay times: %.2f msec (%.2f msec/set)", chunkloadns-ns, ((chunkloadns-ns) / setcnt)));
-        sender.sendMessage("  Chunk set exceptions: " + total_exceptions.get());
+        sender.sendMessage(String.format("  Chunk set exceptions: %d", total_exceptions.get()));
+        sender.sendMessage(String.format("  World tick list processing calls: %d", ticklistcalls.get()));
     }
     /**
      * Print trigger statistics command
@@ -1269,6 +1268,7 @@ public class MapManager {
             total_loadtime_ns.set(0);
             total_chunk_cache_loadtime_ns.set(0);
             total_exceptions.set(0);
+            ticklistcalls.set(0);
         }
         sscache.resetStats();
         sender.sendMessage("Tile Render Statistics reset");
@@ -1339,4 +1339,9 @@ public class MapManager {
     boolean getPauseUpdateRenders() {
         return pauseupdaterenders;
     }
+    
+    public void incExtraTickList() {
+        ticklistcalls.incrementAndGet();
+    }
+
 }

src/main/java/org/dynmap/utils/NewMapChunkCache.java

@@ -6,10 +6,10 @@ import java.lang.reflect.Method;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.ListIterator;
+import java.util.TreeSet;
 
 import org.bukkit.World;
 import org.bukkit.Chunk;
-import org.bukkit.World.Environment;
 import org.bukkit.block.Biome;
 import org.bukkit.entity.Entity;
 import org.bukkit.ChunkSnapshot;
@@ -28,15 +28,16 @@ public class NewMapChunkCache implements MapChunkCache {
     private static Method poppreservedchunk = null;
     private static Method gethandle = null;
     private static Method removeentities = null;
-    private static Method getworldchunkmgr = null;
-    private static Method getbiomedata = null;
     private static Method getworldhandle = null;    
     private static Field  chunkbiome = null;
-    private static boolean canusebiomefix = false;
+    private static Field ticklist = null;
-    private static boolean biomefixtested = false;
+    private static Method processticklist = null;
-    private static boolean biomefixneeded = false;
+
+    private static final int MAX_PROCESSTICKS = 20;
+    private static final int MAX_TICKLIST = 1000;
 
     private World w;
+    private Object craftworld;
     private List<DynmapChunk> chunks;
     private ListIterator<DynmapChunk> iterator;
     private int x_min, x_max, z_min, z_max;
@@ -45,11 +46,12 @@ public class NewMapChunkCache implements MapChunkCache {
     private HiddenChunkStyle hidestyle = HiddenChunkStyle.FILL_AIR;
     private List<VisibilityLimit> visible_limits = null;
     private List<VisibilityLimit> hidden_limits = null;
-    private DynmapWorld.AutoGenerateOption generateopt;
     private boolean do_generate = false;
     private boolean do_save = false;
     private boolean isempty = true;
     private ChunkSnapshot[] snaparray; /* Index = (x-x_min) + ((z-z_min)*x_dim) */
+    private Biome[][] snapbiomes;   /* Biome cache - getBiome() is expensive */
+    private TreeSet<?> ourticklist;
     
     private int chunks_read;    /* Number of chunks actually loaded */
     private int chunks_attempted;   /* Number of chunks attempted to load */
@@ -109,7 +111,16 @@ public class NewMapChunkCache implements MapChunkCache {
             return snap.getBlockEmittedLight(bx, y, bz);
         }
         public final Biome getBiome() {
-            return snap.getBiome(bx, bz);
+            Biome[] b = snapbiomes[chunkindex];
+            if(b == null) {
+                b = snapbiomes[chunkindex] = new Biome[256];
+            }
+            int off = bx + (bz << 4);
+            Biome bio = b[off];
+            if(bio == null) {
+                bio = b[off] = snap.getBiome(bx, bz);
+            }
+            return bio;
         }
         public double getRawBiomeTemperature() {
             return snap.getRawBiomeTemperature(bx, bz);
@@ -359,22 +370,6 @@ public class NewMapChunkCache implements MapChunkCache {
             } catch (NoSuchMethodException nsmx) {
             }
                         
-            /* Get WorldChunkManager.b(float[],int,int,int,int) and WorldChunkManager.a(float[],int,int,int,int) */
-            try {
-                Class c = Class.forName("net.minecraft.server.WorldChunkManager");
-                Class biomebasearray = Class.forName("[Lnet.minecraft.server.BiomeBase;");
-                getbiomedata = c.getDeclaredMethod("a", new Class[] { biomebasearray, int.class, int.class, int.class, int.class });
-            } catch (ClassNotFoundException cnfx) {
-            } catch (NoSuchMethodException nsmx) {
-            }
-            
-            /* getWorldChunkManager() */
-            try {
-                Class c = Class.forName("net.minecraft.server.World");
-                getworldchunkmgr = c.getDeclaredMethod("getWorldChunkManager", new Class[0]);
-            } catch (ClassNotFoundException cnfx) {
-            } catch (NoSuchMethodException nsmx) {
-            }
             /* Get CraftChunkSnapshot.biome field */
             try {
                 Class c = Class.forName("org.bukkit.craftbukkit.CraftChunkSnapshot");
@@ -383,20 +378,37 @@ public class NewMapChunkCache implements MapChunkCache {
             } catch (ClassNotFoundException cnfx) {
             } catch (NoSuchFieldException nsmx) {
             }
+            /* ticklist for World */
+            try {
+                Class c = Class.forName("net.minecraft.server.World");
+                try {
+                    ticklist = c.getDeclaredField("K"); /* 1.0.0 */
+                } catch (NoSuchFieldException nsfx) {
+                    ticklist = c.getDeclaredField("N"); /* 1.8.1 */
+                }
+                ticklist.setAccessible(true);
+                if(ticklist.getType().isAssignableFrom(TreeSet.class) == false)
+                    ticklist = null;
+                processticklist = c.getDeclaredMethod("a", new Class[] { boolean.class } );
+            } catch (ClassNotFoundException cnfx) {
+            } catch (NoSuchFieldException nsmx) {
+            } catch (NoSuchMethodException nsmx) {
+            }
 
             init = true;
-            if((getworldchunkmgr != null) && (getbiomedata != null) && (getworldhandle != null) && (chunkbiome != null)) {
-                canusebiomefix = true;
-            }
-            else {
-                biomefixtested = true;
-                biomefixneeded = false;
         }
     }
-    }
+    @SuppressWarnings({ "rawtypes" })
-    @SuppressWarnings({ "unchecked", "rawtypes" })
     public void setChunks(World w, List<DynmapChunk> chunks) {
         this.w = w;
+        if((getworldhandle != null) && (craftworld == null)) {
+            try {
+                craftworld = getworldhandle.invoke(w);   /* World.getHandle() */
+                if(ticklist != null)
+                    ourticklist = (TreeSet)ticklist.get(craftworld);
+            } catch (Exception x) {
+            }
+        }
         this.chunks = chunks;
         /* Compute range */
         if(chunks.size() == 0) {
@@ -423,6 +435,7 @@ public class NewMapChunkCache implements MapChunkCache {
         }
     
         snaparray = new ChunkSnapshot[x_dim * (z_max-z_min+1)];
+        snapbiomes = new Biome[x_dim * (z_max-z_min+1)][];
     }
 
     public int loadChunks(int max_to_load) {
@@ -431,6 +444,10 @@ public class NewMapChunkCache implements MapChunkCache {
         if(iterator == null)
             iterator = chunks.listIterator();
 
+        if(checkTickList() == false) { /* Tick processing is behind? */
+            max_to_load = 1;
+        }
+        
         DynmapPlugin.setIgnoreChunkLoads(true);
         //boolean isnormral = w.getEnvironment() == Environment.NORMAL;
         // Load the required chunks.
@@ -492,10 +509,6 @@ public class NewMapChunkCache implements MapChunkCache {
                     else
                         ss = w.getEmptyChunkSnapshot(chunk.x, chunk.z, biome, biomeraw);
                     if(ss != null) {
-                        if((!biomefixtested) && biome) /* Test for biome fix */
-                            testIfBiomeFixNeeded(w, ss);
-                        if(biomefixneeded && biome)  /* If needed, apply it */
-                            doBiomeFix(w, ss);
                         MapManager.mapman.sscache.putSnapshot(w.getName(), chunk.x, chunk.z, ss, blockdata, biome, biomeraw, highesty);
                     }
                 }
@@ -560,42 +573,6 @@ public class NewMapChunkCache implements MapChunkCache {
 
         return cnt;
     }
-    /**
-     * Test if biome fix needed, using loaded snapshot
-     */
-    private boolean testIfBiomeFixNeeded(World w, ChunkSnapshot ss) {
-        if(biomefixtested == false) {
-            biomefixtested = true;
-            for(int i = 0; (!biomefixneeded) && (i < 16); i++) {
-                for(int j = 0; j < 16; j++) {
-                    if(w.getBiome((ss.getX()<<4)+i, (ss.getZ()<<4)+j) != ss.getBiome(i, j)) {   /* Mismatch? */
-                        biomefixneeded = true;
-                        Log.info("Biome Snapshot fix active");
-                        break;
-                    }
-                }
-            }
-        }
-        return biomefixneeded;
-    }
-    /**
-     * Use biome fix to patch snapshot data
-     */
-    private void doBiomeFix(World w, ChunkSnapshot ss) {
-        if(biomefixneeded && canusebiomefix) {
-            try {
-                Object wh = getworldhandle.invoke(w);   /* World.getHandle() */
-                Object wcm = getworldchunkmgr.invoke(wh);   /* CraftWorld.getWorldChunkManager() */
-                Object biomefield = chunkbiome.get(ss); /* Get ss.biome */
-                if(biomefield != null) {
-                    getbiomedata.invoke(wcm, biomefield, (int)(ss.getX()<<4), (int)(ss.getZ()<<4), 16, 16); /* Get biome data */
-                }
-            } catch (InvocationTargetException itx) {
-            } catch (IllegalArgumentException e) {
-            } catch (IllegalAccessException e) {
-            }
-        }
-    }
     /**
      * Test if done loading
      */
@@ -689,7 +666,6 @@ public class NewMapChunkCache implements MapChunkCache {
             Log.severe("Cannot setAutoGenerateVisibleRanges() without visible ranges defined");
             return;
         }
-        this.generateopt = generateopt;
         this.do_generate = (generateopt != DynmapWorld.AutoGenerateOption.NONE);
         this.do_save = (generateopt == DynmapWorld.AutoGenerateOption.PERMANENT);
     }
@@ -767,4 +743,23 @@ public class NewMapChunkCache implements MapChunkCache {
     public long getExceptionCount() {
         return exceptions;
     }
+    
+    private boolean checkTickList() {
+        boolean isok = true;
+        if((ourticklist != null) && (processticklist != null)) {
+            int cnt = 0;
+            while((cnt < MAX_PROCESSTICKS) && (ourticklist.size() > MAX_TICKLIST)) {
+                try {
+                    processticklist.invoke(craftworld, true);
+                } catch (Exception x) {
+                }
+                cnt++;
+                MapManager.mapman.incExtraTickList();
+            }
+            if(cnt >= MAX_PROCESSTICKS) {   /* If still behind, delay processing */
+                isok = false;
+            }
+        }
+        return isok;
+    }
 }