Enhancing intent-perf logging

Fixing defect in distributed app mgmt
Reducing DB manager heartbeat aggressiveness

Change-Id: I9ba948a2b2166625c56566502143c0d27f9a2c44

@@ -55,9 +55,12 @@ import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 
 import static com.google.common.base.Preconditions.checkState;
+import static java.lang.String.format;
 import static org.apache.felix.scr.annotations.ReferenceCardinality.MANDATORY_UNARY;
 import static org.onlab.util.Tools.delay;
 import static org.onlab.util.Tools.groupedThreads;
+import static org.onosproject.net.intent.IntentEvent.Type.INSTALLED;
+import static org.onosproject.net.intent.IntentEvent.Type.WITHDRAWN;
 import static org.slf4j.LoggerFactory.getLogger;
 
 /**
@@ -119,23 +122,24 @@ public class IntentPerfInstaller {
         // we will need to discard the first few results for priming and warmup
         listener = new Listener();
         intentService.addListener(listener);
+
+        long delay = System.currentTimeMillis() % REPORT_PERIOD;
         reportTimer = new Timer("onos-intent-perf-reporter");
         reportTimer.scheduleAtFixedRate(new TimerTask() {
             @Override
             public void run() {
                 listener.report();
             }
-        }, REPORT_PERIOD, REPORT_PERIOD);
+        }, delay, REPORT_PERIOD);
 
         stopped = false;
         worker.submit(() -> {
-            delay(2000);
+            delay(2000); // take a breath to start
             createIntents(NUM_KEYS, 2); //FIXME
             prime();
             while (!stopped) {
                 cycle();
-                // TODO delay if required
-                delay(600);
+                delay(800); // take a breath
             }
         });
 
@@ -186,7 +190,6 @@ public class IntentPerfInstaller {
     }
 
     private void createIntents(int numberOfKeys, int pathLength) {
-
         Iterator<Device> deviceItr = deviceService.getAvailableDevices().iterator();
 
         Device ingressDevice = null;
@@ -238,12 +241,11 @@ public class IntentPerfInstaller {
 
     class Listener implements IntentListener {
 
-
-        private Map<IntentEvent.Type, Counter> counters;
+        private final Map<IntentEvent.Type, Counter> counters;
+        private final Counter runningTotal = new Counter();
 
         public Listener() {
             counters = initCounters();
-
         }
 
         private Map<IntentEvent.Type, Counter> initCounters() {
@@ -263,18 +265,21 @@ public class IntentPerfInstaller {
 
         public void report() {
             StringBuilder stringBuilder = new StringBuilder();
-            double total = counters.get(IntentEvent.Type.INSTALLED).throughput() +
-                    counters.get(IntentEvent.Type.WITHDRAWN).throughput();
+            Counter installed = counters.get(INSTALLED);
+            Counter withdrawn = counters.get(WITHDRAWN);
+            double current = installed.throughput() + withdrawn.throughput();
+            runningTotal.add(installed.total() + withdrawn.total());
             for (IntentEvent.Type type : IntentEvent.Type.values()) {
                 stringBuilder.append(printCounter(type)).append("; ");
             }
-            stringBuilder.append(String.format("TOTAL=%.2f", total));
-            log.info("Intent Throughput:\n{}", stringBuilder);
+            log.info("Throughput: OVERALL={}; CURRENT={}; {}",
+                     format("%.2f", runningTotal.throughput()),
+                     format("%.2f", current), stringBuilder);
         }
 
         private String printCounter(IntentEvent.Type event) {
             Counter counter = counters.get(event);
-            String result = String.format("%s=%.2f", event, counter.throughput());
+            String result = format("%s=%.2f", event, counter.throughput());
             counter.reset();
             return result;
         }

@@ -148,7 +148,7 @@ public class ApplicationArchive
      *                                                  archive stream or store
      *                                                  the application archive
      */
-    public ApplicationDescription saveApplication(InputStream stream) {
+    public synchronized ApplicationDescription saveApplication(InputStream stream) {
         try (InputStream ais = stream) {
             byte[] cache = toByteArray(ais);
             InputStream bis = new ByteArrayInputStream(cache);
@@ -190,7 +190,7 @@ public class ApplicationArchive
      *
      * @param appName application name
      */
-    public void purgeApplication(String appName) {
+    public synchronized void purgeApplication(String appName) {
         File appDir = new File(appsDir, appName);
         try {
             Tools.removeDirectory(appDir);
@@ -209,7 +209,7 @@ public class ApplicationArchive
      * @param appName application name
      * @return application archive stream
      */
-    public InputStream getApplicationInputStream(String appName) {
+    public synchronized InputStream getApplicationInputStream(String appName) {
         try {
             File appFile = appFile(appName, appName + ".zip");
             return new FileInputStream(appFile.exists() ? appFile : appFile(appName, APP_XML));

@@ -104,8 +104,8 @@ public class DatabaseManager implements StorageService {
                     .withReceiveBufferSize(32768)
                     .withSendBufferSize(8192)
                     .withThreads(1))
-            .withElectionTimeout(300)
-            .withHeartbeatInterval(150)
+            .withElectionTimeout(3000)
+            .withHeartbeatInterval(1500)
             .withMembers(activeNodeUris)
             .withLocalMember(localNodeUri);
 
@@ -114,8 +114,8 @@ public class DatabaseManager implements StorageService {
         partitionMap.forEach((name, nodes) -> {
             Set<String> replicas = nodes.stream().map(this::nodeToUri).collect(Collectors.toSet());
             DatabaseConfig partitionConfig = new DatabaseConfig()
-                            .withElectionTimeout(300)
-                            .withHeartbeatInterval(150)
+                            .withElectionTimeout(3000)
+                            .withHeartbeatInterval(1500)
                             .withConsistency(Consistency.STRONG)
                             .withLog(new FileLog()
                                     .withDirectory(logDir)

@@ -4,7 +4,7 @@
 # -----------------------------------------------------------------------------
 
 #export JAVA_HOME=${JAVA_HOME:-/usr/lib/jvm/java-7-openjdk-amd64/}
-export JAVA_OPTS="${JAVA_OPTS:--Xms256m -Xmx2048m}"
+export JAVA_OPTS="${JAVA_OPTS:--Xms256m -Xmx2g}"
 
 ONOS_HOME=/opt/onos
 

+#!/bin/bash
+# -----------------------------------------------------------------------------
+# Scrapes intent performance numbers from the remote ONOS log file.
+# -----------------------------------------------------------------------------
+
+[ ! -d "$ONOS_ROOT" ] && echo "ONOS_ROOT is not defined" >&2 && exit 1
+. $ONOS_ROOT/tools/build/envDefaults
+
+nodes=$(env | sort | egrep "OC[0-9]+" | cut -d= -f2)
+
+for node in $nodes; do
+    echo "fetching from ${node}..."
+    ssh $ONOS_USER@${node} "
+        grep 'Throughput: OVERALL=' $ONOS_INSTALL_DIR/log/karaf.log \
+            | sed 's/ | INFO .*\: OVERALL=/|/;s/\; INSTALL_REQ=.*//;s/\; CURRENT=/|/' | cut -c12-
+    " > ${node}.perf.log
+done