From 674c648130f4d986fd9156fac68afcd92af9a527 Mon Sep 17 00:00:00 2001
From: Gaetan Boismal <gaetan.boismal@forgerock.com>
Date: Mon, 08 Feb 2016 09:16:33 +0000
Subject: [PATCH] OPENDJ-2550 RateTool: Improve error output

---
 opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/PerformanceRunner.java |  202 +++++++++++++++++++++++++++-----------------------
 opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/AddRate.java           |    2 
 opendj-sdk/opendj-ldap-toolkit/src/main/resources/com/forgerock/opendj/ldap/tools/tools.properties  |    3 
 3 files changed, 112 insertions(+), 95 deletions(-)

diff --git a/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/AddRate.java b/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/AddRate.java
index 5cb887e..0123071 100644
--- a/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/AddRate.java
+++ b/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/AddRate.java
@@ -264,7 +264,7 @@
                         throw new IllegalStateException();
                     }
                 } else if (!purgeEnabled) {
-                    stopRequested = true;
+                    stopTool();
                 }
             }
         }
diff --git a/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/PerformanceRunner.java b/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/PerformanceRunner.java
index c857085..f0d575d 100644
--- a/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/PerformanceRunner.java
+++ b/opendj-sdk/opendj-ldap-toolkit/src/main/java/com/forgerock/opendj/ldap/tools/PerformanceRunner.java
@@ -46,6 +46,9 @@
 import java.util.Map.Entry;
 import java.util.Queue;
 import java.util.concurrent.ConcurrentSkipListMap;
+import java.util.concurrent.Executors;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.atomic.AtomicLong;
 
@@ -255,6 +258,10 @@
         private final boolean isScriptFriendly = app.isScriptFriendly();
         private MultiColumnPrinter printer;
 
+
+        private long totalStatTimeMs;
+        private long gcDurationMs;
+
         public StatsThread(final String... additionalColumns) {
             super("Stats Thread");
 
@@ -364,62 +371,59 @@
             out.println();
         }
 
+        private void printTitle() {
+            printResultsTitle();
+        }
+
+        private void initStats() {
+            totalStatTimeMs = System.currentTimeMillis();
+            gcDurationMs = getGCDuration();
+        }
+
         @Override
         public void run() {
-            printResultsTitle();
+            lastStatTimeMs = totalStatTimeMs;
+            totalStatTimeMs = System.currentTimeMillis();
 
-            long totalStatTimeMs = System.currentTimeMillis();
-            long gcDurationMs = getGCDuration();
+            lastGCDurationMs = gcDurationMs;
+            gcDurationMs = getGCDuration();
+            final long gcIntervalDurationMs = gcDurationMs - lastGCDurationMs;
 
-            while (!stopRequested) {
-                try {
-                    sleep(statsInterval);
-                } catch (final InterruptedException ie) {
-                    // Ignore.
-                }
-                lastStatTimeMs = totalStatTimeMs;
-                totalStatTimeMs = System.currentTimeMillis();
+            computeStatsForInterval(totalStatTimeMs, gcIntervalDurationMs);
+            final long intervalResultCount = intervalSuccessCount + intervalFailedCount;
 
-                lastGCDurationMs = gcDurationMs;
-                gcDurationMs = getGCDuration();
-                final long gcIntervalDurationMs = gcDurationMs - lastGCDurationMs;
+            final String[] printableStats = new String[numColumns];
+            Arrays.fill(printableStats, "-");
+            printableStats[0] = getDivisionResult(intervalResultCount, intervalDurationSec, 1);
+            printableStats[1] = getDivisionResult(totalResultCount, totalDurationSec, 1);
 
-                computeStatsForInterval(totalStatTimeMs, gcIntervalDurationMs);
-                final long intervalResultCount = intervalSuccessCount + intervalFailedCount;
+            final long intervalWaitTimeMs = NANOSECONDS.toMillis(intervalWaitTimeNs) - gcIntervalDurationMs;
+            printableStats[2] = getDivisionResult(intervalWaitTimeMs, intervalResultCount, 3);
 
-                final String[] printableStats = new String[numColumns];
-                Arrays.fill(printableStats, "-");
-                printableStats[0] = getDivisionResult(intervalResultCount, intervalDurationSec, 1);
-                printableStats[1] = getDivisionResult(totalResultCount, totalDurationSec, 1);
+            final long totalWaitTimeMs = NANOSECONDS.toMillis(totalWaitTimeNs) - gcDurationMs;
+            printableStats[3] = getDivisionResult(totalWaitTimeMs, totalResultCount, 3);
 
-                final long intervalWaitTimeMs = NANOSECONDS.toMillis(intervalWaitTimeNs) - gcIntervalDurationMs;
-                printableStats[2] = getDivisionResult(intervalWaitTimeMs, intervalResultCount, 3);
+            int i = 4;
+            final List<Long> computedPercentiles = eTimesBuckets.getPercentile(percentiles, totalOperationCount);
+            for (int j = computedPercentiles.size() - 1; j >= 0; j--) {
+                printableStats[i++] = getDivisionResult(computedPercentiles.get(j) , 1000.0, 2);
+            }
+            i = 4 + percentiles.length;
+            printableStats[i++] = intervalFailedCount == 0
+                                  ? "0.0"
+                                  : getDivisionResult(intervalFailedCount, intervalDurationSec, 1);
+            if (isAsync) {
+                printableStats[i++] = getDivisionResult(intervalOperationCount, intervalResultCount, 1);
+            }
 
-                final long totalWaitTimeMs = NANOSECONDS.toMillis(totalWaitTimeNs) - gcDurationMs;
-                printableStats[3] = getDivisionResult(totalWaitTimeMs, totalResultCount, 3);
+            for (final String column : getAdditionalColumns()) {
+                printableStats[i++] = column;
+            }
 
-                int i = 4;
-                final List<Long> computedPercentiles = eTimesBuckets.getPercentile(percentiles, totalOperationCount);
-                for (int j = computedPercentiles.size() - 1; j >= 0; j--) {
-                    printableStats[i++] = getDivisionResult(computedPercentiles.get(j) , 1000.0, 2);
-                }
-                i = 4 + percentiles.length;
-                printableStats[i++] = intervalFailedCount == 0
-                                      ? "0.0"
-                                      : getDivisionResult(intervalFailedCount, intervalDurationSec, 1);
-                if (isAsync) {
-                    printableStats[i++] = getDivisionResult(intervalOperationCount, intervalResultCount, 1);
-                }
-
-                for (final String column : getAdditionalColumns()) {
-                    printableStats[i++] = column;
-                }
-
-                if (isScriptFriendly) {
-                    printScriptFriendlyStats(printableStats);
-                } else {
-                    printer.printRow(printableStats);
-                }
+            if (isScriptFriendly) {
+                printScriptFriendlyStats(printableStats);
+            } else {
+                printer.printRow(printableStats);
             }
         }
 
@@ -491,7 +495,7 @@
         }
 
         void performStopOperations() {
-            stopRequested = true;
+            stopTool();
         }
 
         @Override
@@ -566,37 +570,14 @@
 
             while (!stopRequested && !localStopRequested
                     && (maxIterations <= 0 || count < maxIterations)) {
-                if (this.connection == null) {
-                    try {
-                        connection = connectionFactory.getConnectionAsync().getOrThrow();
-                    } catch (final InterruptedException e) {
-                        // Ignore and check stop requested
-                        continue;
-                    } catch (final LdapException e) {
-                        app.errPrintln(LocalizableMessage.raw(e.getResult().getDiagnosticMessage()));
-                        if (e.getCause() != null && app.isVerbose()) {
-                            e.getCause().printStackTrace(app.getErrorStream());
-                        }
-                        stopRequested = true;
-                        break;
-                    }
-                } else {
-                    connection = this.connection;
-                    if (!noRebind && bindRequest != null) {
-                        try {
-                            connection.bindAsync(bindRequest).getOrThrow();
-                        } catch (final InterruptedException e) {
-                            // Ignore and check stop requested
-                            continue;
-                        } catch (final LdapException e) {
-                            app.errPrintln(LocalizableMessage.raw(e.getResult().toString()));
-                            if (e.getCause() != null && app.isVerbose()) {
-                                e.getCause().printStackTrace(app.getErrorStream());
-                            }
-                            stopRequested = true;
-                            break;
-                        }
-                    }
+                try {
+                    connection = getConnectionToUse();
+                } catch (final InterruptedException e) {
+                    // Ignore and check stop requested
+                    continue;
+                } catch (final LdapException e) {
+                    handleConnectionError(false, e);
+                    break;
                 }
 
                 long startTimeNs = System.nanoTime();
@@ -609,9 +590,9 @@
                         // Ignore and check stop requested
                         continue;
                     } catch (final LdapException e) {
-                        if (e.getCause() instanceof IOException) {
+                        if (!stopRequested && e.getCause() instanceof IOException) {
                             e.getCause().printStackTrace(app.getErrorStream());
-                            stopRequested = true;
+                            stopTool(e);
                             break;
                         }
                         // Ignore. Handled by result handler
@@ -640,6 +621,18 @@
             }
         }
 
+        private Connection getConnectionToUse() throws InterruptedException, LdapException {
+            if (this.connection == null) {
+                return connectionFactory.getConnectionAsync().getOrThrow();
+            } else {
+                final Connection resultConnection = this.connection;
+                if (!noRebind && bindRequest != null) {
+                    resultConnection.bindAsync(bindRequest).getOrThrow();
+                }
+                return resultConnection;
+            }
+        }
+
         void incrementIterationCount() {
             count++;
         }
@@ -674,7 +667,8 @@
 
     int numThreads;
     int numConnections;
-    volatile boolean stopRequested;
+    private boolean stopRequested;
+
     private volatile boolean isWarmingUp;
     private int targetThroughput;
     private int maxIterations;
@@ -685,7 +679,7 @@
     private boolean isAsync;
     private boolean noRebind;
     private BindRequest bindRequest;
-    private int statsInterval;
+    private int statsIntervalMs;
     private final IntegerArgument numThreadsArgument;
     private final IntegerArgument maxDurationArgument;
     private final IntegerArgument statsIntervalArgument;
@@ -700,6 +694,8 @@
     protected final IntegerArgument warmUpArgument;
 
     private final List<Thread> workerThreads = new ArrayList<>();
+    private final ScheduledExecutorService statThreadScheduler = Executors.newSingleThreadScheduledExecutor();
+    private StatsThread statsThread;
 
     PerformanceRunner(final PerformanceRunnerOptions options) throws ArgumentException {
         ArgumentParser argParser = options.getArgumentParser();
@@ -820,12 +816,11 @@
     @Override
     public synchronized void handleConnectionError(final boolean isDisconnectNotification, final LdapException error) {
         if (!stopRequested) {
-            app.errPrintln(LocalizableMessage.raw("Error occurred on one or more connections: "
-                    + error.getResult()));
+            app.errPrintln(ERROR_RATE_TOOLS_CAN_NOT_GET_CONNECTION.get(error.getMessage()));
             if (error.getCause() != null && app.isVerbose()) {
                 error.getCause().printStackTrace(app.getErrorStream());
             }
-            stopRequested = true;
+            stopTool(error);
         }
     }
 
@@ -840,7 +835,7 @@
         warmUpDuration = warmUpArgument.getIntValue() * 1000L;
         maxIterations = maxIterationsArgument.getIntValue() / numConnections / numThreads;
         maxDurationTime = maxDurationArgument.getIntValue() * 1000L;
-        statsInterval = statsIntervalArgument.getIntValue() * 1000;
+        statsIntervalMs = statsIntervalArgument.getIntValue() * 1000;
         targetThroughput = targetThroughputArgument.getIntValue();
 
         isAsync = asyncArgument.isPresent();
@@ -904,8 +899,7 @@
                 newEndTimerThread(maxDurationTime).start();
             }
 
-            final StatsThread statsThread = newStatsThread();
-
+            statsThread = newStatsThread();
             if (isWarmingUp) {
                 if (!app.isScriptFriendly()) {
                     app.println(INFO_TOOL_WARMING_UP.get(warmUpDuration / 1000));
@@ -915,14 +909,16 @@
                 isWarmingUp = false;
             }
 
-            statsThread.start();
+            statsThread.printTitle();
+            statsThread.initStats();
+            statThreadScheduler.scheduleAtFixedRate(
+                    statsThread, statsIntervalMs, statsIntervalMs, TimeUnit.MILLISECONDS);
             joinAllWorkerThreads();
-            stopRequested = true;
-            statsThread.join();
+            stopTool();
         } catch (final InterruptedException e) {
-            stopRequested = true;
+            stopTool(e);
         } catch (final LdapException e) {
-            stopRequested = true;
+            stopTool(e);
             printErrorMessage(app, e);
             return e.getResult().getResultCode().intValue();
         } finally {
@@ -938,6 +934,26 @@
         }
     }
 
+    synchronized void stopTool() {
+        stopTool(null);
+    }
+
+    synchronized void stopTool(final Exception e) {
+        if (!stopRequested) {
+            stopRequested = true;
+            statThreadScheduler.shutdown();
+            if (e == null) {
+                // If stats thread is printing stats, wait for it to finish.
+                try {
+                    statThreadScheduler.awaitTermination(50, TimeUnit.MILLISECONDS);
+                } catch (InterruptedException ignored) {
+                    // Do nothing.
+                }
+                statsThread.run();
+            }
+        }
+    }
+
     void setBindRequest(final BindRequest request) {
         this.bindRequest = request;
     }
diff --git a/opendj-sdk/opendj-ldap-toolkit/src/main/resources/com/forgerock/opendj/ldap/tools/tools.properties b/opendj-sdk/opendj-ldap-toolkit/src/main/resources/com/forgerock/opendj/ldap/tools/tools.properties
index 827f83f..d318ea6 100755
--- a/opendj-sdk/opendj-ldap-toolkit/src/main/resources/com/forgerock/opendj/ldap/tools/tools.properties
+++ b/opendj-sdk/opendj-ldap-toolkit/src/main/resources/com/forgerock/opendj/ldap/tools/tools.properties
@@ -22,7 +22,7 @@
 #
 #
 #      Copyright 2010 Sun Microsystems, Inc.
-#      Portions copyright 2012-2015 ForgeRock AS.
+#      Portions copyright 2012-2016 ForgeRock AS.
 #
 #
 # Utility messages
@@ -138,6 +138,7 @@
 INFO_ARGPARSER_USAGE_JAVA_SCRIPTNAME=Usage:  %s  {options}
 INFO_ARGPARSER_USAGE_TRAILINGARGS={trailing-arguments}
 INFO_ARGPARSER_USAGE_DEFAULT_VALUE=Default value: %s
+ERROR_RATE_TOOLS_CAN_NOT_GET_CONNECTION=%s\nThe tool is going to stop.
 #
 # Extension messages
 #

--
Gitblit v1.10.0