diff --git a/common/src/main/java/net/rptools/lib/StringUtil.java b/common/src/main/java/net/rptools/lib/StringUtil.java index f7ad9e2cad..bd0a917063 100644 --- a/common/src/main/java/net/rptools/lib/StringUtil.java +++ b/common/src/main/java/net/rptools/lib/StringUtil.java @@ -19,6 +19,7 @@ import java.util.ArrayList; import java.util.Arrays; import java.util.List; +import java.util.concurrent.TimeUnit; import java.util.regex.Pattern; /** @@ -28,6 +29,18 @@ public class StringUtil { private static NumberFormat nf = NumberFormat.getNumberInstance(); private static final int MIN_FRACTION_DIGITS = 0; + public static String formatTimeUnit(TimeUnit unit) { + return switch (unit) { + case NANOSECONDS -> "ns"; + case MICROSECONDS -> "μs"; + case MILLISECONDS -> "ms"; + case SECONDS -> "s"; + case MINUTES -> "m"; + case HOURS -> "h"; + case DAYS -> "d"; + }; + } + public static String formatDecimal(double value) { String result1; result1 = nf.format(value); // On a separate line to allow for breakpoints diff --git a/src/main/java/net/rptools/lib/CodeTimer.java b/src/main/java/net/rptools/lib/CodeTimer.java index 810fddebe5..b3132f716c 100644 --- a/src/main/java/net/rptools/lib/CodeTimer.java +++ b/src/main/java/net/rptools/lib/CodeTimer.java @@ -14,18 +14,23 @@ */ package net.rptools.lib; +import java.awt.EventQueue; import java.util.ArrayList; import java.util.LinkedHashMap; import java.util.List; import java.util.Map; +import java.util.concurrent.TimeUnit; import net.rptools.maptool.client.AppState; import net.rptools.maptool.client.MapTool; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; public class CodeTimer { private static final ThreadLocal ROOT_TIMER = ThreadLocal.withInitial(() -> new CodeTimer("")); private static final ThreadLocal> timerStack = ThreadLocal.withInitial(ArrayList::new); + private static final Logger log = LogManager.getLogger(CodeTimer.class); @FunctionalInterface public interface TimedSection { @@ -49,11 +54,7 @@ public static void using(String name, TimedSection ca final var lastTimer = stack.removeLast(); assert lastTimer == timer : "Timer stack is corrupted"; - if (timer.isEnabled()) { - String results = timer.toString(); - MapTool.getProfilingNoteFrame().addText(results); - } - timer.clear(); + timer.complete(); } } @@ -62,23 +63,38 @@ public static CodeTimer get() { return stack.isEmpty() ? ROOT_TIMER.get() : stack.getLast(); } - private final Map counterMap = new LinkedHashMap<>(); - private final Map timeMap = new LinkedHashMap<>(); + private enum TimerEventType { + Start, + Stop + } + + private record TimerEvent(TimerEventType type, long timeNs, String id, Object[] parameters) {} + + private record CounterEvent(long amount, String id) {} + + private ArrayList timerEvents = new ArrayList<>(100); + private ArrayList counterEvents = new ArrayList<>(100); + private final String name; private long threshold = 1; + private TimeUnit reportingUnit = TimeUnit.MILLISECONDS; private boolean enabled; - public CodeTimer(String n) { + private CodeTimer(String n) { name = n; enabled = true; } - public boolean isEnabled() { - return enabled; + public void setThreshold(long threshold) { + this.threshold = TimeUnit.NANOSECONDS.convert(threshold, TimeUnit.MILLISECONDS); } - public void setThreshold(long threshold) { - this.threshold = threshold; + public void setThreshold(long threshold, TimeUnit timeUnit) { + this.threshold = TimeUnit.NANOSECONDS.convert(threshold, timeUnit); + } + + public void setReportingUnit(TimeUnit reportingUnit) { + this.reportingUnit = reportingUnit; } public void setEnabled(boolean enabled) { @@ -90,62 +106,95 @@ public void increment(String id) { } public void increment(String id, int amount) { - counterMap.merge(id, amount, Integer::sum); + if (!enabled) { + return; + } + counterEvents.add(new CounterEvent(amount, id)); } public void start(String id, Object... parameters) { if (!enabled) { return; } - if (parameters.length > 0) { - id = String.format(id, parameters); - } - - Timer timer = timeMap.computeIfAbsent(id, key -> new Timer()); - timer.start(); + timerEvents.add(new TimerEvent(TimerEventType.Start, System.nanoTime(), id, parameters)); } public void stop(String id, Object... parameters) { if (!enabled) { return; } - if (parameters.length > 0) { - id = String.format(id, parameters); - } + timerEvents.add(new TimerEvent(TimerEventType.Stop, System.nanoTime(), id, parameters)); + } - Timer timer = timeMap.get(id); - if (timer == null) { - throw new IllegalArgumentException("Could not find timer id: " + id); + private void complete() { + if (!enabled) { + return; } - timer.stop(); - } - public void clear() { - timeMap.clear(); - counterMap.clear(); + var name = this.name; + var reportingUnit = this.reportingUnit; + var threshold = this.threshold; + var timerEvents = this.timerEvents; + var counterEvents = this.counterEvents; + this.timerEvents = new ArrayList<>(); + this.counterEvents = new ArrayList<>(); + + EventQueue.invokeLater( + () -> { + String results = getResults(name, reportingUnit, threshold, timerEvents, counterEvents); + MapTool.getProfilingNoteFrame().addText(results); + }); } - @Override - public String toString() { - StringBuilder builder = new StringBuilder(100); + private static String getResults( + String name, + TimeUnit reportingUnit, + long threshold, + List timerEvents, + List counterEvents) { + final Map counterMap = new LinkedHashMap<>(); + // Maps timer names to start times. + final Map timeMap = new LinkedHashMap<>(); + + // Count up all the timing events. + for (var event : timerEvents) { + var id = String.format(event.id(), event.parameters()); + var timer = timeMap.computeIfAbsent(id, Timer::new); + switch (event.type()) { + case Start -> timer.startAt(event.timeNs()); + case Stop -> timer.stopAt(event.timeNs()); + } + } + // Count up all the counter events. + for (var event : counterEvents) { + counterMap.merge(event.id(), event.amount(), Long::sum); + } + + StringBuilder builder = new StringBuilder(100); builder .append("Timer ") .append(name) .append(" (") .append(timeMap.size()) .append(" elements)\n"); - var i = -1; for (var entry : timeMap.entrySet()) { ++i; var id = entry.getKey(); - long elapsed = entry.getValue().getElapsed() / 1_000_000; + long elapsed = entry.getValue().elapsedNs; if (elapsed < threshold) { continue; } - builder.append(String.format(" %3d. %6d ms %s\n", i, elapsed, id)); + + builder.append( + String.format( + " %3d. %6d %s %s\n", + i, + reportingUnit.convert(elapsed, TimeUnit.NANOSECONDS), + StringUtil.formatTimeUnit(reportingUnit), + id)); } if (!counterMap.isEmpty()) { @@ -164,29 +213,29 @@ public String toString() { return builder.toString(); } - private static class Timer { - long elapsed; - long start = -1; + private static final class Timer { + String name; + long elapsedNs = 0; + long startTimeNs = -1; - private long getTime() { - return System.nanoTime(); + public Timer(String name) { + this.name = name; } - public void start() { - start = getTime(); - } - - public void stop() { - elapsed += (getTime() - start); - start = -1; + public void startAt(long timeNs) { + if (startTimeNs >= 0) { + log.warn("Invalid timer state: attempted to start timer {} that was already started", name); + } + startTimeNs = timeNs; } - public long getElapsed() { - long time = elapsed; - if (start > 0) { - time += (getTime() - start); + public void stopAt(long timeNs) { + if (startTimeNs < 0) { + log.warn("Invalid timer state: attempted to stop timer {} that was not started", name); + return; } - return time; + elapsedNs += (timeNs - startTimeNs); + startTimeNs = -1; } } } diff --git a/src/main/java/net/rptools/maptool/client/swing/NoteFrame.java b/src/main/java/net/rptools/maptool/client/swing/NoteFrame.java index 99e6899403..248deeab9b 100644 --- a/src/main/java/net/rptools/maptool/client/swing/NoteFrame.java +++ b/src/main/java/net/rptools/maptool/client/swing/NoteFrame.java @@ -17,6 +17,7 @@ import java.awt.BorderLayout; import java.awt.Color; import java.awt.Dimension; +import java.awt.Font; import java.awt.event.WindowEvent; import javax.swing.BorderFactory; import javax.swing.JButton; @@ -24,11 +25,10 @@ import javax.swing.JPanel; import javax.swing.JScrollPane; import javax.swing.JTextArea; -import javax.swing.text.JTextComponent; import net.rptools.maptool.language.I18N; public class NoteFrame extends JFrame { - private JTextComponent noteArea; + private JTextArea noteArea; private JButton clearButton; private JButton closeButton; @@ -43,10 +43,12 @@ private void initUI() { add(BorderLayout.SOUTH, createButtonBar()); } - private JTextComponent getNoteArea() { + private JTextArea getNoteArea() { if (noteArea == null) { noteArea = new JTextArea(); noteArea.setBorder(BorderFactory.createLineBorder(Color.black)); + noteArea.setFont(new Font(Font.MONOSPACED, Font.PLAIN, noteArea.getFont().getSize())); + noteArea.setEditable(false); } return noteArea; } @@ -78,7 +80,8 @@ private JButton getCloseButton() { } public synchronized void addText(String text) { - getNoteArea().setText(getNoteArea().getText() + text + "\n"); + getNoteArea().append(text); + getNoteArea().append("\n"); getNoteArea().setCaretPosition(getNoteArea().getText().length()); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/gdx/GdxRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/gdx/GdxRenderer.java index 0289e28b69..e465a4072a 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/gdx/GdxRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/gdx/GdxRenderer.java @@ -39,6 +39,7 @@ import java.text.NumberFormat; import java.util.*; import java.util.List; +import java.util.concurrent.TimeUnit; import java.util.zip.Deflater; import javax.swing.*; import net.rptools.lib.AwtUtil; @@ -127,7 +128,6 @@ public class GdxRenderer extends ApplicationAdapter { private BitmapFont normalFont; private BitmapFont boldFont; private float boldFontScale = 0; - private final CodeTimer timer = new CodeTimer("GdxRenderer.renderZone"); /** Used by render layers to compose the layer prior to blending. */ private FrameBuffer backBuffer; @@ -368,7 +368,14 @@ public void render() { ensureTtfFont(); ScreenUtils.clear(Color.BLACK); try { - doRendering(); + CodeTimer.using( + "GdxRenderer.renderZone", + timer -> { + timer.setThreshold(10); + timer.setThreshold(1, TimeUnit.MICROSECONDS); + timer.setReportingUnit(TimeUnit.MICROSECONDS); + doRendering(); + }); } catch (Exception ex) { log.warn("Error while rendering", ex); } @@ -407,6 +414,8 @@ private void loadAssets() { } private void doRendering() { + CodeTimer timer = CodeTimer.get(); + batch.enableBlending(); // Framebuffer is premultiplied. Assume source textures are as well (can be changed for // operations that require something else). @@ -418,7 +427,6 @@ private void doRendering() { if (zoneCache == null || !renderZone) return; - initializeTimer(); if (zoneCache.getZoneRenderer() == null) return; setScale(viewModel.getZoneScale()); @@ -455,24 +463,6 @@ private void doRendering() { hudTextRenderer.drawString("Draws: " + batch.renderCalls, width - 30, 16); batch.end(); - collectTimerResults(); - } - - private void collectTimerResults() { - if (timer.isEnabled()) { - String results = timer.toString(); - MapTool.getProfilingNoteFrame().addText(results); - if (log.isDebugEnabled()) { - log.debug(results); - } - timer.clear(); - } - } - - private void initializeTimer() { - timer.setEnabled(AppState.isCollectProfilingData() || log.isDebugEnabled()); - timer.clear(); - timer.setThreshold(10); } public void invalidateCurrentViewCache() { @@ -481,6 +471,8 @@ public void invalidateCurrentViewCache() { } private void renderZone(PlayerView view) { + CodeTimer timer = CodeTimer.get(); + if (!prerender(view)) { return; } @@ -680,6 +672,8 @@ private void renderZone(PlayerView view) { * @return {@code true} if rendering should proceed. */ private boolean prerender(PlayerView view) { + CodeTimer timer = CodeTimer.get(); + if (viewModel.getLoadingStatus().isPresent() || MapTool.getCampaign().isBeingSerialized()) { return false; } @@ -857,19 +851,17 @@ private void renderRenderables() { } private void renderFog(PlayerView view) { + CodeTimer timer = CodeTimer.get(); + var zoneView = zoneCache.getZoneView(); timer.start("renderFog-visibleArea"); Area visibleArea = zoneView.getVisibleArea(view); timer.stop("renderFog-visibleArea"); - String msg = null; - if (timer.isEnabled()) { - msg = "renderFog-combined(" + (view.isUsingTokenView() ? view.getTokens().size() : 0) + ")"; - } - timer.start(msg); + timer.start("renderFog-combined(%d)", view.isUsingTokenView() ? view.getTokens().size() : 0); Area exposedArea = zoneView.getExposedArea(view); - timer.stop(msg); + timer.stop("renderFog-combined(%d)", view.isUsingTokenView() ? view.getTokens().size() : 0); Area softFogArea; Area clearArea; @@ -935,6 +927,8 @@ private void setProjectionMatrix(Matrix4 matrix) { } private void renderLabels(PlayerView view) { + CodeTimer timer = CodeTimer.get(); + timer.start("labels-1"); for (Label label : zoneCache.getZone().getLabels()) { @@ -1187,6 +1181,7 @@ private void showBlockedMoves(ZonePoint zp, double angle, Sprite image, float si } private void renderLumensOverlay(PlayerView view, float overlayAlpha) { + CodeTimer timer = CodeTimer.get(); final var disjointLumensLevels = zoneCache.getZoneView().getDisjointObscuredLumensLevels(view); BlendFunction.SRC_ONLY.applyToBatch(batch); @@ -1251,6 +1246,7 @@ private void renderLumensOverlay(PlayerView view, float overlayAlpha) { } private void renderLights(PlayerView view) { + CodeTimer timer = CodeTimer.get(); if (AppState.isShowLights()) { timer.start("renderLights:getLights"); final var drawableLights = zoneCache.getZoneView().getDrawableLights(view); @@ -1290,6 +1286,7 @@ private void renderLumens(PlayerView view) { } private void renderAuras(PlayerView view) { + CodeTimer timer = CodeTimer.get(); timer.start("renderAuras:getAuras"); final var drawableAuras = zoneCache.getZoneView().getDrawableAuras(view); timer.stop("renderAuras:getAuras"); @@ -1311,6 +1308,7 @@ private void renderLightOverlay( float alpha, BlendFunction lightBlending, boolean premultipy) { + CodeTimer timer = CodeTimer.get(); // Set up a buffer image for lights to be drawn onto before the map timer.start("renderLightOverlay:allocateBuffer"); ScreenUtils.clear(Color.CLEAR); @@ -1365,6 +1363,7 @@ private void renderBoard() { } private void renderDrawables(List drawables) { + CodeTimer timer = CodeTimer.get(); timer.start("drawableBackground"); drawnElementRenderer.render(batch, zoneCache.getZone(), drawables); timer.stop("drawableBackground"); @@ -1389,6 +1388,8 @@ private void fillViewportWith(ZoneCache.GdxPaint paint) { } private void renderTokens(List tokenList, PlayerView view, boolean figuresOnly) { + CodeTimer timer = CodeTimer.get(); + if (tokenList.isEmpty() || visibleScreenArea == null) { return; } @@ -1798,6 +1799,8 @@ private void renderTokens(List tokenList, PlayerView view, boolean figure } private void prepareTokenSprite(Sprite image, Token token, java.awt.Rectangle footprintBounds) { + CodeTimer timer = CodeTimer.get(); + image.setRotation(0); // Tokens are centered on the image center point @@ -2049,6 +2052,8 @@ private void paintClipped(FrameBuffer buffer, Sprite image, Area bounds, Area cl } private void renderPath(Path path, TokenFootprint footprint) { + CodeTimer timer = CodeTimer.get(); + if (path == null) { return; } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DarknessRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DarknessRenderer.java index cc7134ac0f..361714ebcf 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DarknessRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DarknessRenderer.java @@ -32,7 +32,7 @@ public class DarknessRenderer { private final ZoneView zoneView; public DarknessRenderer(RenderHelper renderHelper, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("DarknessRenderer"); this.zoneView = zoneView; } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DebugRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DebugRenderer.java index 36711a7c48..24fcfdbc2c 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DebugRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/DebugRenderer.java @@ -26,7 +26,7 @@ public class DebugRenderer { private final Color[] palette; public DebugRenderer(RenderHelper renderHelper) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("DebugRenderer"); palette = new Color[] {Color.red, Color.green, Color.blue, Color.magenta, Color.orange, Color.yellow}; } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/FogRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/FogRenderer.java index 10f4e17e7e..70716bcd66 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/FogRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/FogRenderer.java @@ -31,14 +31,14 @@ public class FogRenderer { private final ZoneView zoneView; public FogRenderer(RenderHelper renderHelper, Zone zone, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("FogRenderer"); this.zone = zone; this.zoneView = zoneView; } public void render(Graphics2D g, PlayerView view) { var timer = CodeTimer.get(); - timer.start("renderFog"); + timer.start("FogRenderer-renderFog"); try { if (!zone.hasFog()) { return; @@ -47,7 +47,7 @@ public void render(Graphics2D g, PlayerView view) { this.renderHelper.bufferedRender( g, AlphaComposite.SrcOver, worldG -> renderWorld(worldG, view)); } finally { - timer.stop("renderFog"); + timer.stop("FogRenderer-renderFog"); } } @@ -61,16 +61,10 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { Area visibleArea = zoneView.getVisibleArea(view); timer.stop("renderFog-getVisibleArea"); - String msg = null; - if (timer.isEnabled()) { - msg = - "renderFog-getExposedArea(" - + (view.isUsingTokenView() ? view.getTokens().size() : 0) - + ")"; - } - timer.start(msg); + var tokenCount = view.isUsingTokenView() ? view.getTokens().size() : 0; + timer.start("renderFog-getExposedArea(%d)", tokenCount); Area exposedArea = zoneView.getExposedArea(view); - timer.stop(msg); + timer.stop("renderFog-getExposedArea(%d)", tokenCount); // Hard FOW is cleared by exposed areas. The exposed area itself has two regions: the visible // area (rendered clear) and the soft FOW area (rendered translucent). But if vision is off, @@ -88,32 +82,32 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { var originalClip = worldG.getClip(); - timer.start("renderFog-hardFow"); + timer.start("FogRenderer-renderFog:hardFow"); // Fill. This will be cleared out later to produce soft fog and clear visible area. worldG.setPaint(zone.getFogPaint().getPaint()); // JFJ this fixes the GM exposed area view. worldG.setComposite(AlphaComposite.getInstance(AlphaComposite.SRC, view.isGMView() ? .6f : 1f)); var bounds = originalClip.getBounds(); worldG.fillRect(bounds.x, bounds.y, bounds.width, bounds.height); - timer.stop("renderFog-hardFow"); + timer.stop("FogRenderer-renderFog:hardFow"); - timer.start("renderFog-softFow"); + timer.start("FogRenderer-renderFog:softFow"); if (!softFogArea.isEmpty()) { worldG.setComposite(AlphaComposite.getInstance(AlphaComposite.SRC)); worldG.setColor(new Color(0, 0, 0, AppPreferences.fogOverlayOpacity.get())); worldG.fill(softFogArea); } - timer.stop("renderFog-softFow"); + timer.stop("FogRenderer-renderFog:softFow"); - timer.start("renderFog-exposedArea"); + timer.start("FogRenderer-renderFog:exposedArea"); if (!clearArea.isEmpty()) { // Now fill in the visible area. worldG.setComposite(AlphaComposite.getInstance(AlphaComposite.CLEAR)); worldG.fill(clearArea); } - timer.stop("renderFog-exposedArea"); + timer.stop("FogRenderer-renderFog:exposedArea"); - timer.start("renderFog-outline"); + timer.start("FogRenderer-renderFog:outline"); // If there is no boundary between soft fog and visible area, there is no need for an outline. if (!softFogArea.isEmpty() && !clearArea.isEmpty()) { worldG.setComposite(AlphaComposite.Src); @@ -122,6 +116,6 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { worldG.setColor(Color.BLACK); worldG.draw(clearArea); } - timer.stop("renderFog-outline"); + timer.stop("FogRenderer-renderFog:outline"); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/HaloRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/HaloRenderer.java index f48b5dbf56..7f1f0deb8f 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/HaloRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/HaloRenderer.java @@ -39,7 +39,7 @@ public class HaloRenderer { // endregion public HaloRenderer(RenderHelper renderHelper, Zone zone) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("HaloRenderer"); this.zone = zone; new MapToolEventBus().getMainEventBus().register(this); diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LightsRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LightsRenderer.java index b55fefe6ee..81749f131a 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LightsRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LightsRenderer.java @@ -40,14 +40,14 @@ public class LightsRenderer { private final ZoneView zoneView; public LightsRenderer(RenderHelper renderHelper, Zone zone, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("LightsRenderer"); this.zone = zone; this.zoneView = zoneView; } public void renderAuras(Graphics2D g2d, PlayerView view) { var timer = CodeTimer.get(); - timer.start("renderAuras"); + timer.start("LightsRenderer-renderAuras"); try { final var drawableAuras = zoneView.getDrawableAuras(view); if (drawableAuras.isEmpty()) { @@ -63,13 +63,13 @@ public void renderAuras(Graphics2D g2d, PlayerView view) { AlphaComposite.SrcOver, worldG -> renderWorld(worldG, view, drawableAuras, lightBlending, overlayFillColor)); } finally { - timer.stop("renderAuras"); + timer.stop("LightsRenderer-renderAuras"); } } public void renderLights(Graphics2D g2d, PlayerView view) { var timer = CodeTimer.get(); - timer.start("renderLights"); + timer.start("LightsRenderer-renderLights"); try { if (!AppState.isShowLights()) { return; @@ -99,7 +99,7 @@ public void renderLights(Graphics2D g2d, PlayerView view) { renderWorld( worldG, view, drawableLights, LightingComposite.BlendedLights, overlayFillColor)); } finally { - timer.stop("renderLights"); + timer.stop("LightsRenderer-renderLights"); } } @@ -120,23 +120,23 @@ private void renderWorld( worldG.fillRect(bounds.x, bounds.y, bounds.width, bounds.height); if (!view.isGMView()) { - timer.start("renderLightOverlay:setClip"); + timer.start("LightsRenderer-renderLightOverlay:setClip"); var clip = new Area(originalClip); clip.intersect(visibleArea); worldG.setClip(clip); - timer.stop("renderLightOverlay:setClip"); + timer.stop("LightsRenderer-renderLightOverlay:setClip"); } worldG.setComposite(lightBlending); // Draw lights onto the buffer image so the map doesn't affect how they blend - timer.start("renderLightOverlay:drawLights"); + timer.start("LightsRenderer-renderLightOverlay:drawLights"); for (var light : lights) { worldG.setPaint(light.getPaint().getPaint()); - timer.start("renderLightOverlay:fillLight"); + timer.start("LightsRenderer-renderLightOverlay:fillLight"); worldG.fill(light.getArea()); - timer.stop("renderLightOverlay:fillLight"); + timer.stop("LightsRenderer-renderLightOverlay:fillLight"); } - timer.stop("renderLightOverlay:drawLights"); + timer.stop("LightsRenderer-renderLightOverlay:drawLights"); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LumensRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LumensRenderer.java index 627a25575c..584dcd46b3 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LumensRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/LumensRenderer.java @@ -38,14 +38,14 @@ public class LumensRenderer { private final ZoneView zoneView; public LumensRenderer(RenderHelper renderHelper, Zone zone, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("LumensRenderer"); this.zone = zone; this.zoneView = zoneView; } public void render(Graphics2D g2d, PlayerView view) { var timer = CodeTimer.get(); - timer.start("renderLumensOverlay"); + timer.start("LumensRenderer-renderLumensOverlay"); try { if (!AppState.isShowLumensOverlay()) { return; @@ -53,7 +53,7 @@ public void render(Graphics2D g2d, PlayerView view) { renderHelper.bufferedRender(g2d, AlphaComposite.SrcOver, worldG -> renderWorld(worldG, view)); } finally { - timer.stop("renderLumensOverlay"); + timer.stop("LumensRenderer-renderLumensOverlay"); } } @@ -76,16 +76,16 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { worldG.fillRect(bounds.x, bounds.y, bounds.width, bounds.height); if (!view.isGMView()) { - timer.start("renderLumensOverlay:setClip"); + timer.start("LumensRenderer-renderLumensOverlay:setClip"); Area clip = new Area(originalClip); clip.intersect(visibleArea); worldG.setClip(clip); - timer.stop("renderLumensOverlay:setClip"); + timer.stop("LumensRenderer-renderLumensOverlay:setClip"); } worldG.setComposite(AlphaComposite.Src.derive(overlayOpacity)); - timer.start("renderLumensOverlay:drawLumens"); + timer.start("LumensRenderer-renderLumensOverlay:drawLumens"); for (final var lumensLevel : disjointLumensLevels) { final var lumensStrength = lumensLevel.lumensStrength(); @@ -112,7 +112,7 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { worldG.setPaint(new Color(0.f, 0.f, 0.f, 1.f)); worldG.fill(lumensLevel.darknessArea()); - timer.stop("renderLumensOverlay:drawLights:fillArea"); + timer.stop("LumensRenderer-renderLumensOverlay:drawLights:fillArea"); } // Now draw borders around each region if configured. @@ -123,13 +123,13 @@ private void renderWorld(Graphics2D worldG, PlayerView view) { worldG.setComposite(AlphaComposite.SrcOver); worldG.setPaint(new Color(0.f, 0.f, 0.f, 1.f)); for (final var lumensLevel : disjointLumensLevels) { - timer.start("renderLumensOverlay:drawLights:drawArea"); + timer.start("LumensRenderer-renderLumensOverlay:drawLights:drawArea"); worldG.draw(lumensLevel.lightArea()); worldG.draw(lumensLevel.darknessArea()); - timer.stop("renderLumensOverlay:drawLights:drawArea"); + timer.stop("LumensRenderer-renderLumensOverlay:drawLights:drawArea"); } } - timer.stop("renderLumensOverlay:drawLumens"); + timer.stop("LumensRenderer-renderLumensOverlay:drawLumens"); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/RenderHelper.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/RenderHelper.java index b0864f474f..698fde66c8 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/RenderHelper.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/RenderHelper.java @@ -35,73 +35,89 @@ *

Also optionally renders onto an intermediate buffer. */ public class RenderHelper { + private final String timerPrefix; private final ZoneRenderer renderer; private final BufferedImagePool tempBufferPool; - public RenderHelper(ZoneRenderer renderer, BufferedImagePool tempBufferPool) { + private RenderHelper( + ZoneRenderer renderer, BufferedImagePool tempBufferPool, String timerPrefix) { this.renderer = renderer; this.tempBufferPool = tempBufferPool; + this.timerPrefix = timerPrefix; + } + + public RenderHelper(ZoneRenderer renderer, BufferedImagePool tempBufferPool) { + this(renderer, tempBufferPool, "RenderHelper"); } public ImageObserver getImageObserver() { return renderer; } + public RenderHelper withTimerPrefix(String timerPrefix) { + return new RenderHelper(renderer, tempBufferPool, timerPrefix); + } + private void doRender(Graphics2D g, Consumer render) { var timer = CodeTimer.get(); - timer.start("RenderHelper-useAA"); + timer.start("%s-useAA", timerPrefix); SwingUtil.useAntiAliasing(g); - timer.stop("RenderHelper-useAA"); + timer.stop("%s-useAA", timerPrefix); - timer.start("RenderHelper-setTransform"); + timer.start("%s-setTransform", timerPrefix); Scale scale = renderer.getZoneScale(); AffineTransform af = new AffineTransform(); af.translate(scale.getOffsetX(), scale.getOffsetY()); af.scale(scale.getScale(), scale.getScale()); g.setTransform(af); - timer.stop("RenderHelper-setTransform"); + timer.stop("%s-setTransform", timerPrefix); - timer.start("RenderHelper-render"); + timer.start("%s-render", timerPrefix); render.accept(g); - timer.stop("RenderHelper-render"); + timer.stop("%s-render", timerPrefix); } public void render(Graphics2D g, Consumer render) { var timer = CodeTimer.get(); - timer.start("RenderHelper-createContext"); + timer.start("%s-createContext", timerPrefix); g = (Graphics2D) g.create(); - timer.stop("RenderHelper-createContext"); + timer.stop("%s-createContext", timerPrefix); try { - timer.start("RenderHelper-doRender"); + timer.start("%s-doRender", timerPrefix); doRender(g, render); } finally { - timer.stop("RenderHelper-doRender"); - timer.start("RenderHelper-disposeContext"); + timer.stop("%s-doRender", timerPrefix); + timer.start("%s-disposeContext", timerPrefix); g.dispose(); - timer.stop("RenderHelper-disposeContext"); + timer.stop("%s-disposeContext", timerPrefix); } } public void bufferedRender(Graphics2D g, Composite blitComposite, Consumer render) { var timer = CodeTimer.get(); - timer.start("RenderHelper-acquireBuffer"); if (tempBufferPool.getWidth() == renderer.getWidth() && tempBufferPool.getHeight() == renderer.getHeight()) { // This case only holds during regular rendering. Other rendering, such as screenshots, may // have different dimensions. + timer.start("%s-acquireBuffer", timerPrefix); try (final var entry = tempBufferPool.acquire()) { var buffer = entry.get(); + timer.stop("%s-acquireBuffer", timerPrefix); + bufferedRender(buffer, g, blitComposite, render); } } else { + timer.start("%s-acquireBuffer", timerPrefix); var buffer = GraphicsEnvironment.getLocalGraphicsEnvironment() .getDefaultScreenDevice() .getDefaultConfiguration() .createCompatibleImage( renderer.getWidth(), renderer.getHeight(), Transparency.TRANSLUCENT); + timer.stop("%s-acquireBuffer", timerPrefix); + bufferedRender(buffer, g, blitComposite, render); } } @@ -118,7 +134,7 @@ private void bufferedRender( buffG.dispose(); } - timer.start("RenderHelper-blit"); + timer.start("%s-blit", timerPrefix); g = (Graphics2D) g.create(); try { g.setComposite(blitComposite); @@ -126,6 +142,6 @@ private void bufferedRender( } finally { g.dispose(); } - timer.stop("RenderHelper-blit"); + timer.stop("%s-blit", timerPrefix); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/SelectionRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/SelectionRenderer.java index b5ee5c0f03..2f0837dde0 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/SelectionRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/SelectionRenderer.java @@ -34,7 +34,7 @@ public class SelectionRenderer { private final ZoneView zoneView; public SelectionRenderer(RenderHelper renderHelper, ZoneViewModel viewModel, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("SelectionRenderer"); this.viewModel = viewModel; this.zoneView = zoneView; } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/VisionOverlayRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/VisionOverlayRenderer.java index c6e8bdfeb3..69921f11bd 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/VisionOverlayRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/VisionOverlayRenderer.java @@ -38,14 +38,14 @@ public class VisionOverlayRenderer { private final ZoneView zoneView; public VisionOverlayRenderer(RenderHelper renderHelper, Zone zone, ZoneView zoneView) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("VisionOverlayRenderer"); this.zone = zone; this.zoneView = zoneView; } public void render(Graphics2D g, PlayerView view, Token tokenUnderMouse) { var timer = CodeTimer.get(); - timer.start("renderVisionOverlay"); + timer.start("VisionOverlayRenderer-renderVisionOverlay"); try { if (tokenUnderMouse == null) { return; @@ -62,7 +62,7 @@ public void render(Graphics2D g, PlayerView view, Token tokenUnderMouse) { this.renderHelper.render(g, worldG -> renderWorld(worldG, view, tokenUnderMouse)); } finally { - timer.stop("renderVisionOverlay"); + timer.stop("VisionOverlayRenderer-renderVisionOverlay"); } } diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/ZoneRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/ZoneRenderer.java index 62012aa5c0..51e3687710 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/ZoneRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/ZoneRenderer.java @@ -31,6 +31,7 @@ import java.text.NumberFormat; import java.util.*; import java.util.List; +import java.util.concurrent.TimeUnit; import java.util.stream.Collectors; import javax.annotation.Nonnull; import javax.annotation.Nullable; @@ -704,7 +705,8 @@ public void paintComponent(Graphics g) { CodeTimer.using( "ZoneRenderer.renderZone", timer -> { - timer.setThreshold(10); + timer.setThreshold(1, TimeUnit.MICROSECONDS); + timer.setReportingUnit(TimeUnit.MICROSECONDS); if (!viewModel.isUsingGdxRenderer()) { timer.start("paintComponent"); diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/FacingArrowRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/FacingArrowRenderer.java index 4ca0d80eb2..fcc99fe3bb 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/FacingArrowRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/FacingArrowRenderer.java @@ -60,7 +60,7 @@ public class FacingArrowRenderer { } public FacingArrowRenderer(RenderHelper renderHelper, Zone zone) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("FacingArrowRenderer"); this.zone = zone; for (int i = 0; i <= 90; i++) { figureFillColours.add(new Color(1 - 0.5f / 90f * i, 1 - 0.5f / 90f * i, 0)); diff --git a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/TokenRenderer.java b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/TokenRenderer.java index 582316134e..010d76a595 100644 --- a/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/TokenRenderer.java +++ b/src/main/java/net/rptools/maptool/client/ui/zone/renderer/tokenRender/TokenRenderer.java @@ -43,7 +43,7 @@ public class TokenRenderer { private final Zone zone; public TokenRenderer(RenderHelper renderHelper, Zone zone) { - this.renderHelper = renderHelper; + this.renderHelper = renderHelper.withTimerPrefix("TokenRenderer"); this.zone = zone; }