PerfTest.java

/**
 * Licensed to the Apache Software Foundation (ASF) under one
 * or more contributor license agreements.  See the NOTICE file
 * distributed with this work for additional information
 * regarding copyright ownership.  The ASF licenses this file
 * to you under the Apache License, Version 2.0 (the
 * "License"); you may not use this file except in compliance
 * with the License.  You may obtain a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

package org.apache.metron.statistics;

import java.lang.invoke.MethodHandles;
import java.util.HashMap;
import java.util.Map;
import org.apache.commons.lang3.RandomStringUtils;
import org.apache.commons.math3.stat.descriptive.DescriptiveStatistics;
import org.apache.commons.math3.stat.descriptive.StatisticalSummary;
import org.json.simple.JSONObject;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class PerfTest {

  private static final Logger LOG = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());

  private static final double NANO_TO_MILLIS = 1e6;
  private static final String PATH = "/foo/bar/baz";

  public interface Operation {

    void run();
  }

  @Test
  public void calcTimes() {
    Map<String, Object> smallMap = new HashMap<>();
    for (int i = 0; i < 10; i++) {
      smallMap.put("key" + i, RandomStringUtils.randomAlphabetic(10));
    }
    Map<String, Object> largeMap = new HashMap<>();
    for (int i = 0; i < 500; i++) {
      largeMap.put("key" + i, RandomStringUtils.randomAlphabetic(1000));
    }
    JSONObject largeObject = new JSONObject(largeMap);
    JSONObject smallObject = new JSONObject(smallMap);

    int reps = 1000;

    StatisticalSummary summary = runTrial(reps, () -> {
      LOG.trace("Writing message {} to path: {}", smallObject.toJSONString(), PATH);
    });
    printSummary(String.format("Small object %s times", reps), summary);

    summary = runTrial(reps, () -> {
      LOG.trace("Writing message {} to path: {}", largeObject.toJSONString(), PATH);
    });
    printSummary(String.format("Large object %s times", reps), summary);

    summary = runTrial(reps, () -> {
      LOG.trace("Writing message {} to path: {}", "hello", PATH);
    });
    printSummary(String.format("Simple string %s times", reps), summary);
  }

  private StatisticalSummary runTrial(int reps, Operation operation) {
    DescriptiveStatistics stats = new DescriptiveStatistics();

    long trialTime = timeOperation(() -> {
      for (int i = 0; i < reps; i++) {
        long time = timeOperation(operation);
        stats.addValue(time / NANO_TO_MILLIS);
      }
    });
    System.out.println("Total trial time (ms): " + (trialTime / NANO_TO_MILLIS));
    return stats;
  }

  private long timeOperation(Operation o) {
    final long start = System.nanoTime();
    o.run();
    final long finish = System.nanoTime();
    return finish - start;
  }

  private void printSummary(String desc, StatisticalSummary summary) {
    final String border = "===============================";
    System.out.println(border);
    System.out.println(desc);
    System.out.println(summary.toString());
    System.out.println(border);
  }

}

results

/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/bin/java -ea -Didea.test.cyclic.buffer.size=1048576 "-javaagent:/Applications/IntelliJ IDEA CE.app/Contents/lib/idea_rt.jar=54813:/Applications/IntelliJ IDEA CE.app/Contents/bin" -Dfile.encoding=UTF-8 -classpath "/Applications/IntelliJ IDEA CE.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA CE.app/Contents/plugins/junit/lib/junit-rt.jar:/Applications/IntelliJ IDEA CE.app/Contents/plugins/junit/lib/junit5-rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/jaccess.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/packager.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/lib/tools.jar:/Users/mmiklavcic/devprojects/metron/metron-analytics/metron-statistics/target/test-classes:/Users/mmiklavcic/devprojects/metron/metron-analytics/metron-statistics/target/classes:/Users/mmiklavcic/.m2/repository/com/esotericsoftware/kryo/3.0.3/kryo-3.0.3.jar:/Users/mmiklavcic/.m2/repository/com/esotericsoftware/reflectasm/1.10.1/reflectasm-1.10.1.jar:/Users/mmiklavcic/.m2/repository/com/esotericsoftware/minlog/1.3.0/minlog-1.3.0.jar:/Users/mmiklavcic/.m2/repository/org/objenesis/objenesis/2.1/objenesis-2.1.jar:/Users/mmiklavcic/devprojects/metron/metron-platform/metron-common/target/classes:/Users/mmiklavcic/devprojects/metron/metron-analytics/metron-maas-common/target/classes:/Users/mmiklavcic/.m2/repository/org/apache/curator/curator-x-discovery/2.7.1/curator-x-discovery-2.7.1.jar:/Users/mmiklavcic/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.9.13/jackson-core-asl-1.9.13.jar:/Users/mmiklavcic/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.9.13/jackson-mapper-asl-1.9.13.jar:/Users/mmiklavcic/devprojects/metron/metron-platform/metron-zookeeper/target/classes:/Users/mmiklavcic/.m2/repository/commons-validator/commons-validator/1.5.1/commons-validator-1.5.1.jar:/Users/mmiklavcic/.m2/repository/commons-digester/commons-digester/1.8.1/commons-digester-1.8.1.jar:/Users/mmiklavcic/.m2/repository/commons-logging/commons-logging/1.2/commons-logging-1.2.jar:/Users/mmiklavcic/.m2/repository/commons-collections/commons-collections/3.2.2/commons-collections-3.2.2.jar:/Users/mmiklavcic/.m2/repository/com/opencsv/opencsv/3.7/opencsv-3.7.jar:/Users/mmiklavcic/.m2/repository/com/googlecode/json-simple/json-simple/1.1.1/json-simple-1.1.1.jar:/Users/mmiklavcic/.m2/repository/org/antlr/antlr4-runtime/4.5/antlr4-runtime-4.5.jar:/Users/mmiklavcic/.m2/repository/org/abego/treelayout/org.abego.treelayout.core/1.0.1/org.abego.treelayout.core-1.0.1.jar:/Users/mmiklavcic/.m2/repository/com/codahale/metrics/metrics-core/3.0.2/metrics-core-3.0.2.jar:/Users/mmiklavcic/.m2/repository/com/codahale/metrics/metrics-graphite/3.0.2/metrics-graphite-3.0.2.jar:/Users/mmiklavcic/.m2/repository/commons-configuration/commons-configuration/1.10/commons-configuration-1.10.jar:/Users/mmiklavcic/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar:/Users/mmiklavcic/.m2/repository/org/krakenapps/kraken-pcap/1.7.1/kraken-pcap-1.7.1.jar:/Users/mmiklavcic/.m2/repository/org/krakenapps/kraken-api/2.1.1/kraken-api-2.1.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/curator/curator-client/2.7.1/curator-client-2.7.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/zookeeper/zookeeper/3.4.6/zookeeper-3.4.6.jar:/Users/mmiklavcic/.m2/repository/jline/jline/0.9.94/jline-0.9.94.jar:/Users/mmiklavcic/.m2/repository/io/netty/netty/3.7.0.Final/netty-3.7.0.Final.jar:/Users/mmiklavcic/.m2/repository/org/atteo/classindex/classindex/3.3/classindex-3.3.jar:/Users/mmiklavcic/.m2/repository/org/apache/accumulo/accumulo-start/1.8.0/accumulo-start-1.8.0.jar:/Users/mmiklavcic/.m2/repository/org/apache/hadoop/hadoop-auth/2.7.1/hadoop-auth-2.7.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/directory/server/apacheds-kerberos-codec/2.0.0-M15/apacheds-kerberos-codec-2.0.0-M15.jar:/Users/mmiklavcic/.m2/repository/org/apache/directory/server/apacheds-i18n/2.0.0-M15/apacheds-i18n-2.0.0-M15.jar:/Users/mmiklavcic/.m2/repository/org/apache/directory/api/api-asn1-api/1.0.0-M20/api-asn1-api-1.0.0-M20.jar:/Users/mmiklavcic/.m2/repository/org/apache/directory/api/api-util/1.0.0-M20/api-util-1.0.0-M20.jar:/Users/mmiklavcic/.m2/repository/org/apache/curator/curator-framework/2.7.1/curator-framework-2.7.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/hadoop/hadoop-common/2.7.1/hadoop-common-2.7.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/hadoop/hadoop-annotations/2.7.1/hadoop-annotations-2.7.1.jar:/Users/mmiklavcic/.m2/repository/xmlenc/xmlenc/0.52/xmlenc-0.52.jar:/Users/mmiklavcic/.m2/repository/org/mortbay/jetty/jetty/6.1.26/jetty-6.1.26.jar:/Users/mmiklavcic/.m2/repository/org/mortbay/jetty/jetty-util/6.1.26/jetty-util-6.1.26.jar:/Users/mmiklavcic/.m2/repository/javax/servlet/jsp/jsp-api/2.1/jsp-api-2.1.jar:/Users/mmiklavcic/.m2/repository/com/sun/jersey/jersey-core/1.9/jersey-core-1.9.jar:/Users/mmiklavcic/.m2/repository/com/sun/jersey/jersey-json/1.9/jersey-json-1.9.jar:/Users/mmiklavcic/.m2/repository/org/codehaus/jettison/jettison/1.1/jettison-1.1.jar:/Users/mmiklavcic/.m2/repository/com/sun/xml/bind/jaxb-impl/2.2.3-1/jaxb-impl-2.2.3-1.jar:/Users/mmiklavcic/.m2/repository/javax/xml/bind/jaxb-api/2.2.2/jaxb-api-2.2.2.jar:/Users/mmiklavcic/.m2/repository/javax/xml/stream/stax-api/1.0-2/stax-api-1.0-2.jar:/Users/mmiklavcic/.m2/repository/javax/activation/activation/1.1/activation-1.1.jar:/Users/mmiklavcic/.m2/repository/org/codehaus/jackson/jackson-jaxrs/1.8.3/jackson-jaxrs-1.8.3.jar:/Users/mmiklavcic/.m2/repository/org/codehaus/jackson/jackson-xc/1.8.3/jackson-xc-1.8.3.jar:/Users/mmiklavcic/.m2/repository/com/sun/jersey/jersey-server/1.9/jersey-server-1.9.jar:/Users/mmiklavcic/.m2/repository/net/java/dev/jets3t/jets3t/0.9.0/jets3t-0.9.0.jar:/Users/mmiklavcic/.m2/repository/com/jamesmurty/utils/java-xmlbuilder/0.4/java-xmlbuilder-0.4.jar:/Users/mmiklavcic/.m2/repository/org/apache/avro/avro/1.7.4/avro-1.7.4.jar:/Users/mmiklavcic/.m2/repository/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/Users/mmiklavcic/.m2/repository/org/xerial/snappy/snappy-java/1.0.4.1/snappy-java-1.0.4.1.jar:/Users/mmiklavcic/.m2/repository/com/google/protobuf/protobuf-java/2.5.0/protobuf-java-2.5.0.jar:/Users/mmiklavcic/.m2/repository/com/google/code/gson/gson/2.2.4/gson-2.2.4.jar:/Users/mmiklavcic/.m2/repository/com/jcraft/jsch/0.1.42/jsch-0.1.42.jar:/Users/mmiklavcic/.m2/repository/org/apache/htrace/htrace-core/3.1.0-incubating/htrace-core-3.1.0-incubating.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-compress/1.4.1/commons-compress-1.4.1.jar:/Users/mmiklavcic/.m2/repository/org/tukaani/xz/1.0/xz-1.0.jar:/Users/mmiklavcic/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.7.4/jackson-core-2.7.4.jar:/Users/mmiklavcic/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.7.4/jackson-databind-2.7.4.jar:/Users/mmiklavcic/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.7.4/jackson-annotations-2.7.4.jar:/Users/mmiklavcic/.m2/repository/org/ow2/asm/asm/5.0.3/asm-5.0.3.jar:/Users/mmiklavcic/.m2/repository/commons-beanutils/commons-beanutils/1.8.3/commons-beanutils-1.8.3.jar:/Users/mmiklavcic/.m2/repository/org/reflections/reflections/0.9.10/reflections-0.9.10.jar:/Users/mmiklavcic/.m2/repository/org/javassist/javassist/3.19.0-GA/javassist-3.19.0-GA.jar:/Users/mmiklavcic/.m2/repository/de/javakaffee/kryo-serializers/0.38/kryo-serializers-0.38.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-collections4/4.1/commons-collections4-4.1.jar:/Users/mmiklavcic/.m2/repository/org/jboss/aesh/aesh/0.66.19/aesh-0.66.19.jar:/Users/mmiklavcic/.m2/repository/org/fusesource/jansi/jansi/1.16/jansi-1.16.jar:/Users/mmiklavcic/.m2/repository/com/clearspring/analytics/stream/2.9.5/stream-2.9.5.jar:/Users/mmiklavcic/.m2/repository/it/unimi/dsi/fastutil/7.0.6/fastutil-7.0.6.jar:/Users/mmiklavcic/.m2/repository/com/flipkart/zjsonpatch/zjsonpatch/0.3.4/zjsonpatch-0.3.4.jar:/Users/mmiklavcic/devprojects/metron/metron-stellar/stellar-common/target/classes:/Users/mmiklavcic/.m2/repository/com/github/ben-manes/caffeine/caffeine/2.6.2/caffeine-2.6.2.jar:/Users/mmiklavcic/.m2/repository/com/trendmicro/tlsh/3.7.1/tlsh-3.7.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-lang3/3.2/commons-lang3-3.2.jar:/Users/mmiklavcic/.m2/repository/commons-io/commons-io/2.5/commons-io-2.5.jar:/Users/mmiklavcic/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/Users/mmiklavcic/.m2/repository/commons-net/commons-net/3.1/commons-net-3.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-vfs2/2.1/commons-vfs2-2.1.jar:/Users/mmiklavcic/.m2/repository/commons-codec/commons-codec/1.10/commons-codec-1.10.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-text/1.1/commons-text-1.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/curator/curator-recipes/2.7.1/curator-recipes-2.7.1.jar:/Users/mmiklavcic/.m2/repository/com/google/code/findbugs/jsr305/3.0.0/jsr305-3.0.0.jar:/Users/mmiklavcic/.m2/repository/com/jakewharton/fliptables/fliptables/1.0.2/fliptables-1.0.2.jar:/Users/mmiklavcic/.m2/repository/org/apache/httpcomponents/httpclient/4.3.2/httpclient-4.3.2.jar:/Users/mmiklavcic/.m2/repository/org/apache/httpcomponents/httpcore/4.3.1/httpcore-4.3.1.jar:/Users/mmiklavcic/.m2/repository/org/apache/commons/commons-math3/3.6.1/commons-math3-3.6.1.jar:/Users/mmiklavcic/.m2/repository/com/tdunning/t-digest/3.1/t-digest-3.1.jar:/Users/mmiklavcic/.m2/repository/com/google/guava/guava/12.0/guava-12.0.jar:/Users/mmiklavcic/.m2/repository/org/slf4j/slf4j-api/1.7.7/slf4j-api-1.7.7.jar:/Users/mmiklavcic/.m2/repository/org/slf4j/slf4j-log4j12/1.7.7/slf4j-log4j12-1.7.7.jar:/Users/mmiklavcic/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/Users/mmiklavcic/.m2/repository/junit/junit/4.12/junit-4.12.jar:/Users/mmiklavcic/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar:/Users/mmiklavcic/.m2/repository/org/adrianwalker/multiline-string/0.1.2/multiline-string-0.1.2.jar" com.intellij.rt.execution.junit.JUnitStarter -ideVersion5 -junit4 org.apache.metron.statistics.PerfTest
objc[96601]: Class JavaLaunchHelper is implemented in both /Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/bin/java (0x10eb164c0) and /Library/Java/JavaVirtualMachines/jdk1.8.0_74.jdk/Contents/Home/jre/lib/libinstrument.dylib (0x10eb9a4e0). One of the two will be used. Which one is undefined.
Total trial time (ms): 31.745128
===============================
Small object 1000 times
DescriptiveStatistics:
n: 1000
min: 0.014204
max: 1.317586
mean: 0.025875511000000004
std dev: 0.04601871492242024
median: 0.0205515
skewness: 23.9756466917232
kurtosis: 642.3917888600342

===============================
Total trial time (ms): 52767.209927
===============================
Large object 1000 times
DescriptiveStatistics:
n: 1000
min: 25.876983
max: 1643.27576
mean: 52.74412967599999
std dev: 121.9749336929882
median: 30.491464
skewness: 7.968297938505632
kurtosis: 73.0135603335277

===============================
Total trial time (ms): 0.953987
===============================
Simple string 1000 times
DescriptiveStatistics:
n: 1000
min: 1.42E-4
max: 0.552268
mean: 8.358190000000006E-4
std dev: 0.017531876418312622
median: 1.8E-4
skewness: 31.230383884407406
kurtosis: 982.6373632220426

===============================

Process finished with exit code 0