Index: trunk/src/org/openstreetmap/josm/actions/MergeLayerAction.java =================================================================== --- trunk/src/org/openstreetmap/josm/actions/MergeLayerAction.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/actions/MergeLayerAction.java (revision 15755) @@ -24,4 +24,5 @@ import org.openstreetmap.josm.tools.Logging; import org.openstreetmap.josm.tools.Shortcut; +import org.openstreetmap.josm.tools.Stopwatch; import org.openstreetmap.josm.tools.Utils; @@ -81,5 +82,5 @@ return MainApplication.worker.submit(() -> { - final long start = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); for (int i = sortedLayers.size() - 2; i >= 0; i--) { @@ -89,5 +90,5 @@ } - Logging.info(tr("{0} completed in {1}", actionName, Utils.getDurationString(System.currentTimeMillis() - start))); + Logging.info(tr("{0} completed in {1}", actionName, stopwatch)); }); } @@ -95,5 +96,5 @@ return MainApplication.worker.submit(() -> { - final long start = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); boolean layerMerged = false; for (final Layer sourceLayer: sourceLayers) { @@ -113,5 +114,5 @@ if (layerMerged) { getLayerManager().setActiveLayer(targetLayer); - Logging.info(tr("{0} completed in {1}", actionName, Utils.getDurationString(System.currentTimeMillis() - start))); + Logging.info(tr("{0} completed in {1}", actionName, stopwatch)); } }); Index: trunk/src/org/openstreetmap/josm/data/osm/DatasetConsistencyTest.java =================================================================== --- trunk/src/org/openstreetmap/josm/data/osm/DatasetConsistencyTest.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/data/osm/DatasetConsistencyTest.java (revision 15755) @@ -10,5 +10,5 @@ import org.openstreetmap.josm.tools.JosmRuntimeException; import org.openstreetmap.josm.tools.Logging; -import org.openstreetmap.josm.tools.Utils; +import org.openstreetmap.josm.tools.Stopwatch; /** @@ -46,5 +46,5 @@ */ public void checkReferrers() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); // It's also error when referred primitive's dataset is null but it's already covered by referredPrimitiveNotInDataset check for (Way way : dataSet.getWays()) { @@ -67,5 +67,5 @@ } } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -74,5 +74,5 @@ */ public void checkCompleteWaysWithIncompleteNodes() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); for (Way way : dataSet.getWays()) { if (way.isUsable()) { @@ -84,5 +84,5 @@ } } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -91,5 +91,5 @@ */ public void checkCompleteNodesWithoutCoordinates() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); for (Node node : dataSet.getNodes()) { if (!node.isIncomplete() && node.isVisible() && !node.isLatLonKnown()) { @@ -97,5 +97,5 @@ } } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -104,5 +104,5 @@ */ public void searchNodes() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); dataSet.getReadLock().lock(); try { @@ -116,5 +116,5 @@ dataSet.getReadLock().unlock(); } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -123,5 +123,5 @@ */ public void searchWays() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); dataSet.getReadLock().lock(); try { @@ -134,5 +134,5 @@ dataSet.getReadLock().unlock(); } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -155,5 +155,5 @@ */ public void referredPrimitiveNotInDataset() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); for (Way way : dataSet.getWays()) { for (Node node : way.getNodes()) { @@ -167,5 +167,5 @@ } } - printElapsedTime(startTime); + printElapsedTime(stopwatch); } @@ -174,5 +174,5 @@ */ public void checkZeroNodesWays() { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); for (Way way : dataSet.getWays()) { if (way.isUsable() && way.getNodesCount() == 0) { @@ -182,14 +182,13 @@ } } - printElapsedTime(startTime); - } - - private void printElapsedTime(long startTime) { + printElapsedTime(stopwatch); + } + + private void printElapsedTime(Stopwatch stopwatch) { if (Logging.isDebugEnabled()) { StackTraceElement item = Thread.currentThread().getStackTrace()[2]; String operation = getClass().getSimpleName() + '.' + item.getMethodName(); - long elapsedTime = System.currentTimeMillis() - startTime; Logging.debug(tr("Test ''{0}'' completed in {1}", - operation, Utils.getDurationString(elapsedTime))); + operation, stopwatch)); } } @@ -200,5 +199,5 @@ public void runTest() { try { - long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); referredPrimitiveNotInDataset(); checkReferrers(); @@ -208,5 +207,5 @@ searchWays(); checkZeroNodesWays(); - printElapsedTime(startTime); + printElapsedTime(stopwatch); if (errorCount > MAX_ERRORS) { writer.println((errorCount - MAX_ERRORS) + " more..."); Index: trunk/src/org/openstreetmap/josm/data/validation/OsmValidator.java =================================================================== --- trunk/src/org/openstreetmap/josm/data/validation/OsmValidator.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/data/validation/OsmValidator.java (revision 15755) @@ -79,5 +79,5 @@ import org.openstreetmap.josm.tools.AlphanumComparator; import org.openstreetmap.josm.tools.Logging; -import org.openstreetmap.josm.tools.Utils; +import org.openstreetmap.josm.tools.Stopwatch; /** @@ -609,11 +609,8 @@ if (!testsInitialized) { Logging.debug("Initializing validator tests"); - final long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); initializeTests(getTests()); testsInitialized = true; - if (Logging.isDebugEnabled()) { - final long elapsedTime = System.currentTimeMillis() - startTime; - Logging.debug("Initializing validator tests completed in {0}", Utils.getDurationString(elapsedTime)); - } + Logging.debug("Initializing validator tests completed in {0}", stopwatch); } } Index: trunk/src/org/openstreetmap/josm/data/validation/Test.java =================================================================== --- trunk/src/org/openstreetmap/josm/data/validation/Test.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/data/validation/Test.java (revision 15755) @@ -28,5 +28,5 @@ import org.openstreetmap.josm.tools.GBC; import org.openstreetmap.josm.tools.Logging; -import org.openstreetmap.josm.tools.Utils; +import org.openstreetmap.josm.tools.Stopwatch; /** @@ -75,5 +75,5 @@ /** the start time to compute elapsed time when test finishes */ - protected long startTime; + protected Stopwatch stopwatch; private boolean showElementCount; @@ -154,5 +154,5 @@ */ public void initialize() throws Exception { - this.startTime = -1; + this.stopwatch = Stopwatch.createStarted(); } @@ -168,5 +168,5 @@ Logging.debug(startMessage); this.errors = new ArrayList<>(30); - this.startTime = System.currentTimeMillis(); + this.stopwatch = Stopwatch.createStarted(); } @@ -197,8 +197,6 @@ progressMonitor.finishTask(); progressMonitor = null; - if (startTime > 0) { - // fix #11567 where elapsedTime is < 0 - long elapsedTime = Math.max(0, System.currentTimeMillis() - startTime); - Logging.debug(tr("Test ''{0}'' completed in {1}", getName(), Utils.getDurationString(elapsedTime))); + if (stopwatch.elapsed() > 0) { + Logging.debug(tr("Test ''{0}'' completed in {1}", getName(), stopwatch)); } } Index: trunk/src/org/openstreetmap/josm/gui/SplashScreen.java =================================================================== --- trunk/src/org/openstreetmap/josm/gui/SplashScreen.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/gui/SplashScreen.java (revision 15755) @@ -42,4 +42,5 @@ import org.openstreetmap.josm.tools.ImageProvider; import org.openstreetmap.josm.tools.Logging; +import org.openstreetmap.josm.tools.Stopwatch; import org.openstreetmap.josm.tools.Utils; @@ -150,10 +151,10 @@ private static class MeasurableTask extends Task { private final String name; - private final long start; + private final Stopwatch stopwatch; private String duration = ""; MeasurableTask(String name) { this.name = name; - this.start = System.currentTimeMillis(); + this.stopwatch = Stopwatch.createStarted(); } @@ -162,7 +163,6 @@ throw new IllegalStateException("This task has already been finished: " + name); } - long time = System.currentTimeMillis() - start; - if (time >= 0) { - duration = tr(" ({0})", Utils.getDurationString(time)); + if (stopwatch.elapsed() >= 0) { + duration = tr(" ({0})", stopwatch); } } Index: trunk/src/org/openstreetmap/josm/gui/layer/gpx/GpxDrawHelper.java =================================================================== --- trunk/src/org/openstreetmap/josm/gui/layer/gpx/GpxDrawHelper.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/gui/layer/gpx/GpxDrawHelper.java (revision 15755) @@ -58,4 +58,5 @@ import org.openstreetmap.josm.tools.JosmRuntimeException; import org.openstreetmap.josm.tools.Logging; +import org.openstreetmap.josm.tools.Stopwatch; import org.openstreetmap.josm.tools.Utils; @@ -420,5 +421,5 @@ public void drawAll(Graphics2D g, MapView mv, List visibleSegments, Bounds clipBounds) { - final long timeStart = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); checkCache(); @@ -487,11 +488,9 @@ // show some debug info if (Logging.isDebugEnabled() && !visibleSegments.isEmpty()) { - final long timeDiff = System.currentTimeMillis() - timeStart; - Logging.debug("gpxdraw::draw takes " + - Utils.getDurationString(timeDiff) + + stopwatch + "(" + "segments= " + visibleSegments.size() + - ", per 10000 = " + Utils.getDurationString(10_000 * timeDiff / visibleSegments.size()) + + ", per 10000 = " + Utils.getDurationString(10_000 * stopwatch.elapsed() / visibleSegments.size()) + ")" ); Index: trunk/src/org/openstreetmap/josm/gui/mappaint/MapPaintStyles.java =================================================================== --- trunk/src/org/openstreetmap/josm/gui/mappaint/MapPaintStyles.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/gui/mappaint/MapPaintStyles.java (revision 15755) @@ -29,4 +29,5 @@ import org.openstreetmap.josm.tools.ListenerList; import org.openstreetmap.josm.tools.Logging; +import org.openstreetmap.josm.tools.Stopwatch; import org.openstreetmap.josm.tools.Utils; @@ -321,5 +322,5 @@ private static void loadStyleForFirstTime(StyleSource source) { - final long startTime = System.currentTimeMillis(); + final Stopwatch stopwatch = Stopwatch.createStarted(); source.loadStyleSource(); if (Config.getPref().getBoolean("mappaint.auto_reload_local_styles", true) && source.isLocal()) { @@ -331,6 +332,5 @@ } if (Logging.isDebugEnabled() || !source.isValid()) { - final long elapsedTime = System.currentTimeMillis() - startTime; - String message = "Initializing map style " + source.url + " completed in " + Utils.getDurationString(elapsedTime); + String message = "Initializing map style " + source.url + " completed in " + stopwatch; if (!source.isValid()) { Logging.warn(message + " (" + source.getErrors().size() + " errors, " + source.getWarnings().size() + " warnings)"); Index: trunk/src/org/openstreetmap/josm/gui/tagging/presets/TaggingPresetReader.java =================================================================== --- trunk/src/org/openstreetmap/josm/gui/tagging/presets/TaggingPresetReader.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/gui/tagging/presets/TaggingPresetReader.java (revision 15755) @@ -47,4 +47,5 @@ import org.openstreetmap.josm.tools.I18n; import org.openstreetmap.josm.tools.Logging; +import org.openstreetmap.josm.tools.Stopwatch; import org.openstreetmap.josm.tools.Utils; import org.openstreetmap.josm.tools.XmlObjectParser; @@ -353,5 +354,5 @@ Collection tp; Logging.debug("Reading presets from {0}", source); - long startTime = System.currentTimeMillis(); + Stopwatch stopwatch = Stopwatch.createStarted(); try ( CachedFile cf = new CachedFile(source).setHttpAccept(PRESET_MIME_TYPES); @@ -368,5 +369,5 @@ } if (Logging.isDebugEnabled()) { - Logging.debug("Presets read in {0}", Utils.getDurationString(System.currentTimeMillis() - startTime)); + Logging.debug("Presets read in {0}", stopwatch); } return tp; Index: trunk/src/org/openstreetmap/josm/tools/Stopwatch.java =================================================================== --- trunk/src/org/openstreetmap/josm/tools/Stopwatch.java (revision 15755) +++ trunk/src/org/openstreetmap/josm/tools/Stopwatch.java (revision 15755) @@ -0,0 +1,46 @@ +// License: GPL. For details, see LICENSE file. +package org.openstreetmap.josm.tools; + +/** + * Measures elapsed time in milliseconds + * + * @see Stopwatch in Guava + * @since 15755 + */ +public final class Stopwatch { + private final long start; + + private Stopwatch(long start) { + this.start = start; + } + + /** + * Creates and starts a stopwatch + * + * @return the started stopwatch + */ + public static Stopwatch createStarted() { + return new Stopwatch(System.currentTimeMillis()); + } + + /** + * Returns the elapsed milliseconds + * + * @return the elapsed milliseconds + */ + public long elapsed() { + return System.currentTimeMillis() - start; + } + + /** + * Formats the duration since start as string + * + * @return the duration since start as string + * @see Utils#getDurationString(long) + */ + @Override + public String toString() { + // fix #11567 where elapsedTime is < 0 + return Utils.getDurationString(Math.max(0, elapsed())); + } +} Index: trunk/src/org/openstreetmap/josm/tools/XmlUtils.java =================================================================== --- trunk/src/org/openstreetmap/josm/tools/XmlUtils.java (revision 15754) +++ trunk/src/org/openstreetmap/josm/tools/XmlUtils.java (revision 15755) @@ -84,10 +84,8 @@ */ public static Document parseSafeDOM(InputStream is) throws ParserConfigurationException, IOException, SAXException { - long start = System.currentTimeMillis(); + Stopwatch stopwatch = Stopwatch.createStarted(); Logging.debug("Starting DOM parsing of {0}", is); Document result = newSafeDOMBuilder().parse(is); - if (Logging.isDebugEnabled()) { - Logging.debug("DOM parsing done in {0}", Utils.getDurationString(System.currentTimeMillis() - start)); - } + Logging.debug("DOM parsing done in {0}", stopwatch); return result; } @@ -117,10 +115,8 @@ */ public static void parseSafeSAX(InputSource is, DefaultHandler dh) throws ParserConfigurationException, SAXException, IOException { - long start = System.currentTimeMillis(); + Stopwatch stopwatch = Stopwatch.createStarted(); Logging.debug("Starting SAX parsing of {0} using {1}", is, dh); newSafeSAXParser().parse(is, dh); - if (Logging.isDebugEnabled()) { - Logging.debug("SAX parsing done in {0}", Utils.getDurationString(System.currentTimeMillis() - start)); - } + Logging.debug("SAX parsing done in {0}", stopwatch); }