WT-3346 create JSON output for latency sampling. (#3450)

Added a script to merge workgen and WT outputs. Make workgen_stat.sh script agnostic as to what analyze tool to run.

6 files changed, 142 insertions, 4 deletions

diff --git a/bench/workgen/runner/workgen_stat.sh b/bench/workgen/runner/workgen_stat.sh
new file mode 100755
index 00000000000..1739c29859e
--- /dev/null
+++ b/bench/workgen/runner/workgen_stat.sh
@@ -0,0 +1,75 @@
+#!/bin/bash
+#
+# workgen_stat.sh - combine JSON time series output from WT and workgen.
+#
+Usage() {
+    cat <<EOF
+Usage: $0 [ options ]
+Options:
+    -h <WT_home_directory>     # set the WiredTiger home directory
+    -e <analyzer_name>         # run analyzer on the combined files
+    -o <output_file>           # output file for result 
+
+At least one of '-t2' or '-o' must be selected.
+EOF
+    exit 1
+}
+
+Filter() {
+    sed -e 's/"version" *: *"[^"]*",//' "$@"
+}
+
+wthome=.
+outfile=
+analyze=
+
+while [ "$#" != 0 ]; do
+    arg="$1"
+    shift
+    case "$arg" in
+        -h )
+            if [ $# = 0 ]; then
+                Usage
+            fi
+            wthome="$1"
+            shift
+            ;;
+        -o )
+            if [ $# = 0 ]; then
+                Usage
+            fi
+            outfile="$1"
+            shift
+            ;;
+        -e )
+            if [ $# = 0 ]; then
+                Usage
+            fi
+            analyze="$1"
+            shift
+            ;;
+    esac
+done
+if [ ! -d "$wthome" ]; then
+    echo "$wthome: WT home directory does not exist"
+    exit 1
+fi
+if [ ! -f "$wthome/WiredTiger.wt" ]; then
+    echo "$wthome: directory is not a WiredTiger home directory"
+    exit 1
+fi
+if [ "$outfile" = '' ]; then
+   if [ "$analyze" = false ]; then
+       Usage
+   fi
+   outfile="$wthome/stat_tmp.json"
+fi
+(cd $wthome; Filter WiredTigerStat.* sample.json) | sort > $outfile
+if [ "$analyze" != '' ]; then
+    sysname=`uname -s`
+    if [ "$sysname" = Darwin ]; then
+        open -a "$analyze" "$outfile"
+    else
+        "$analyze" "$outfile"
+    fi
+fi
diff --git a/bench/workgen/workgen.cxx b/bench/workgen/workgen.cxx
index c56acfd2989..880b8ca6467 100644
--- a/bench/workgen/workgen.cxx
+++ b/bench/workgen/workgen.cxx
@@ -267,16 +267,18 @@ int ContextInternal::create_all() {
 }
 
 Monitor::Monitor(WorkloadRunner &wrunner) :
-    _errno(0), _exception(), _wrunner(wrunner), _stop(false), _handle() {}
+    _errno(0), _exception(), _wrunner(wrunner), _stop(false), _handle(),
+    _out(NULL), _json(NULL) {}
 Monitor::~Monitor() {}
 
 int Monitor::run() {
     struct timespec t;
     struct tm *tm, _tm;
-    char time_buf[64];
+    char time_buf[64], version[100];
     Stats prev_totals;
     WorkloadOptions *options = &_wrunner._workload->options;
     uint64_t latency_max = (uint64_t)options->max_latency;
+    bool first;
 
     (*_out) << "#time,"
             << "totalsec,"
@@ -295,6 +297,8 @@ int Monitor::run() {
             << "update maximum latency(uS)"
             << std::endl;
 
+    first = true;
+    workgen_version(version, sizeof(version));
     Stats prev_interval;
     while (!_stop) {
         for (int i = 0; i < options->sample_interval && !_stop; i++)
@@ -337,6 +341,32 @@ int Monitor::run() {
                 << "," << interval.update.max_latency
                 << std::endl;
 
+        if (_json != NULL) {
+#define	WORKGEN_TIMESTAMP_JSON		"%Y-%m-%dT%H:%M:%S.000Z"
+            (void)strftime(time_buf, sizeof(time_buf),
+              WORKGEN_TIMESTAMP_JSON, tm);
+
+#define TRACK_JSON(name, t)                                        \
+            "\"" << (name) << "\":{"                               \
+            << "\"ops per sec\":" << ((t).ops / interval_secs)     \
+            << ",\"average latency\":" << (t).average_latency()    \
+            << ",\"min latency\":" << (t).min_latency              \
+            << ",\"max latency\":" << (t).max_latency              \
+            << "}"
+
+            (*_json) << "{";
+            if (first) {
+                (*_json) << "\"version\":\"" << version << "\",";
+                first = false;
+            }
+            (*_json) << "\"localTime\":\"" << time_buf
+                     << "\",\"workgen\":{"
+                     << TRACK_JSON("read", interval.read) << ","
+                     << TRACK_JSON("insert", interval.insert) << ","
+                     << TRACK_JSON("update", interval.update)
+                     << "}}" << std::endl;
+        }
+
         uint64_t read_max = interval.read.max_latency;
         uint64_t insert_max = interval.read.max_latency;
         uint64_t update_max = interval.read.max_latency;
@@ -1315,8 +1345,8 @@ TableInternal::TableInternal(const TableInternal &other) : _tint(other._tint),
 TableInternal::~TableInternal() {}
 
 WorkloadOptions::WorkloadOptions() : max_latency(0),
-    report_file("workload.stat"), report_interval(0),
-    run_time(0), sample_interval(0), sample_rate(1),
+    report_file("workload.stat"), report_interval(0), run_time(0),
+    sample_file("sample.json"), sample_interval(0), sample_rate(1),
     _options() {
     _options.add_int("max_latency", max_latency,
       "prints warning if any latency measured exceeds this number of "
@@ -1329,6 +1359,11 @@ WorkloadOptions::WorkloadOptions() : max_latency(0),
       "The file name is relative to the connection's home directory. "
       "When set to the empty string, stdout is used.");
     _options.add_int("run_time", run_time, "total workload seconds");
+    _options.add_string("sample_file", sample_file,
+      "file name for collecting latency output in a JSON-like format, "
+      "enabled by the report_interval option. "
+      "The file name is relative to the connection's home directory. "
+      "When set to the empty string, no JSON is emitted.");
     _options.add_int("sample_interval", sample_interval,
       "performance logging every interval seconds, 0 to disable");
     _options.add_int("sample_rate", sample_rate,
@@ -1492,6 +1527,7 @@ int WorkloadRunner::run_all() {
     WorkloadOptions *options = &_workload->options;
     Monitor monitor(*this);
     std::ofstream monitor_out;
+    std::ofstream monitor_json;
     std::ostream &out = *_report_out;
     WT_DECL_RET;
 
@@ -1510,6 +1546,12 @@ int WorkloadRunner::run_all() {
         open_report_file(monitor_out, "monitor", "monitor output file");
         monitor._out = &monitor_out;
 
+        if (!options->sample_file.empty()) {
+            open_report_file(monitor_json, options->sample_file.c_str(),
+              "sample JSON output file");
+            monitor._json = &monitor_json;
+        }
+
         if ((ret = pthread_create(&monitor._handle, NULL, monitor_main,
           &monitor)) != 0) {
             std::cerr << "monitor thread failed err=" << ret << std::endl;
@@ -1588,6 +1630,10 @@ int WorkloadRunner::run_all() {
                       << std::endl;
         if (exception == NULL && !monitor._exception._str.empty())
             exception = &monitor._exception;
+
+        monitor_out.close();
+        if (!options->sample_file.empty())
+            monitor_json.close();
     }
 
     // issue the final report
diff --git a/bench/workgen/workgen.h b/bench/workgen/workgen.h
index c1ae01ed5a4..c7be8ee0035 100644
--- a/bench/workgen/workgen.h
+++ b/bench/workgen/workgen.h
@@ -358,6 +358,7 @@ struct WorkloadOptions {
     int run_time;
     int sample_interval;
     int sample_rate;
+    std::string sample_file;
 
     WorkloadOptions();
     WorkloadOptions(const WorkloadOptions &other);
diff --git a/bench/workgen/workgen_func.c b/bench/workgen/workgen_func.c
index 2e1271a515e..5ce2146a8e4 100644
--- a/bench/workgen/workgen_func.c
+++ b/bench/workgen/workgen_func.c
@@ -87,3 +87,16 @@ workgen_u64_to_string_zf(uint64_t n, char *buf, size_t len)
 {
 	u64_to_string_zf(n, buf, len);
 }
+
+#define	WORKGEN_VERSION_PREFIX	"workgen-"
+extern void
+workgen_version(char *buf, size_t len)
+{
+	size_t prefix_len;
+
+	prefix_len = strlen(WORKGEN_VERSION_PREFIX);
+	(void)strncpy(buf, WORKGEN_VERSION_PREFIX, len);
+	if (len > prefix_len)
+		(void)strncpy(&buf[prefix_len], WIREDTIGER_VERSION_STRING,
+		    len - prefix_len);
+}
diff --git a/bench/workgen/workgen_func.h b/bench/workgen/workgen_func.h
index 20ebf2632cc..ec7ecf0a504 100644
--- a/bench/workgen/workgen_func.h
+++ b/bench/workgen/workgen_func.h
@@ -42,3 +42,5 @@ extern void
 workgen_random_free(struct workgen_random_state *rnd_state);
 extern void
 workgen_u64_to_string_zf(uint64_t n, char *buf, size_t len);
+extern void
+workgen_version(char *buf, size_t len);
diff --git a/bench/workgen/workgen_int.h b/bench/workgen/workgen_int.h
index 01fb727691b..9283aea1d7b 100644
--- a/bench/workgen/workgen_int.h
+++ b/bench/workgen/workgen_int.h
@@ -146,6 +146,7 @@ struct Monitor {
     volatile bool _stop;
     pthread_t _handle;
     std::ostream *_out;
+    std::ostream *_json;
 
     Monitor(WorkloadRunner &wrunner);
     ~Monitor();