tmbench: Make sendloop act in one second segments (#110)

* tmbench: Make sendloop act in one second segments

Previous behaviour was to make the sendloop send all its messages
and then time how long that took. (Possibly waiting if too fast)
This has the same operation when too fast, but stops the loop
after one second. This is useful if a large tx amount is specified
and the ping doesn't get executed. Tmbench no longer crashes on
large rates.

* Update Readme

tm-bench/Gopkg.lock

@@ -1,6 +1,12 @@
 # This file is autogenerated, do not edit; changes may be undone by the next 'dep ensure'.
 
 
+[[projects]]
+  branch = "master"
+  name = "github.com/beorn7/perks"
+  packages = ["quantile"]
+  revision = "3a771d992973f24aa725d07868b467d1ddfceafb"
+
 [[projects]]
   branch = "master"
   name = "github.com/btcsuite/btcd"
@@ -24,7 +30,11 @@
   packages = [
     "log",
     "log/level",
-    "log/term"
+    "log/term",
+    "metrics",
+    "metrics/discard",
+    "metrics/internal/lv",
+    "metrics/prometheus"
   ]
   revision = "4dc7be5d2d12881735283bcab7352178e190fc71"
   version = "v0.6.0"
@@ -90,12 +100,54 @@
   packages = ["."]
   revision = "b84e30acd515aadc4b783ad4ff83aff3299bdfe0"
 
+[[projects]]
+  name = "github.com/matttproud/golang_protobuf_extensions"
+  packages = ["pbutil"]
+  revision = "c12348ce28de40eed0136aa2b644d0ee0650e56c"
+  version = "v1.0.1"
+
 [[projects]]
   name = "github.com/pkg/errors"
   packages = ["."]
   revision = "645ef00459ed84a119197bfb8d8205042c6df63d"
   version = "v0.8.0"
 
+[[projects]]
+  name = "github.com/prometheus/client_golang"
+  packages = [
+    "prometheus",
+    "prometheus/promhttp"
+  ]
+  revision = "c5b7fccd204277076155f10851dad72b76a49317"
+  version = "v0.8.0"
+
+[[projects]]
+  branch = "master"
+  name = "github.com/prometheus/client_model"
+  packages = ["go"]
+  revision = "99fa1f4be8e564e8a6b613da7fa6f46c9edafc6c"
+
+[[projects]]
+  branch = "master"
+  name = "github.com/prometheus/common"
+  packages = [
+    "expfmt",
+    "internal/bitbucket.org/ww/goautoneg",
+    "model"
+  ]
+  revision = "7600349dcfe1abd18d72d3a1770870d9800a7801"
+
+[[projects]]
+  branch = "master"
+  name = "github.com/prometheus/procfs"
+  packages = [
+    ".",
+    "internal/util",
+    "nfs",
+    "xfs"
+  ]
+  revision = "7d6f385de8bea29190f15ba9931442a0eaef9af7"
+
 [[projects]]
   branch = "master"
   name = "github.com/rcrowley/go-metrics"
@@ -121,17 +173,6 @@
   ]
   revision = "ae970a0732be3a1f5311da86118d37b9f4bd2a5a"
 
-[[projects]]
-  name = "github.com/tendermint/abci"
-  packages = [
-    "client",
-    "example/code",
-    "example/kvstore",
-    "types"
-  ]
-  revision = "198dccf0ddfd1bb176f87657e3286a05a6ed9540"
-  version = "v0.12.0"
-
 [[projects]]
   branch = "master"
   name = "github.com/tendermint/ed25519"
@@ -145,22 +186,22 @@
 [[projects]]
   name = "github.com/tendermint/go-amino"
   packages = ["."]
-  revision = "ed62928576cfcaf887209dc96142cd79cdfff389"
-  version = "0.9.9"
-
-[[projects]]
-  name = "github.com/tendermint/go-crypto"
-  packages = ["."]
-  revision = "915416979bf70efa4bcbf1c6cd5d64c5fff9fc19"
-  version = "v0.6.2"
+  revision = "2106ca61d91029c931fd54968c2bb02dc96b1412"
+  version = "0.10.1"
 
 [[projects]]
   name = "github.com/tendermint/tendermint"
   packages = [
+    "abci/client",
+    "abci/example/code",
+    "abci/example/kvstore",
+    "abci/types",
     "blockchain",
     "config",
     "consensus",
     "consensus/types",
+    "crypto",
+    "crypto/tmhash",
     "evidence",
     "libs/events",
     "libs/pubsub",
@@ -188,10 +229,11 @@
     "types",
     "version"
   ]
-  revision = "46369a1ab76f274ab47179c4176221842b8207b4"
-  version = "v0.21.0"
+  revision = "aa20c45ae99bb57a8efa2be7b09898e8967d1965"
+  version = "v0.21.1-rc1"
 
 [[projects]]
+  branch = "develop"
   name = "github.com/tendermint/tmlibs"
   packages = [
     "autofile",
@@ -200,10 +242,10 @@
     "db",
     "flowrate",
     "log",
-    "merkle"
+    "merkle",
+    "merkle/tmhash"
   ]
-  revision = "692f1d86a6e2c0efa698fd1e4541b68c74ffaf38"
-  version = "v0.8.4"
+  revision = "56f44670ebd5a4e99e55f3f7d6f4d360ef5f1973"
 
 [[projects]]
   branch = "master"
@@ -231,6 +273,7 @@
     "idna",
     "internal/timeseries",
     "lex/httplex",
+    "netutil",
     "trace"
   ]
   revision = "640f4622ab692b87c2f3a94265e6f579fe38263d"
@@ -289,6 +332,6 @@
 [solve-meta]
   analyzer-name = "dep"
   analyzer-version = 1
-  inputs-digest = "2c828e4ead70fce78ccb4762315619208bb86c4382e427a06857a503b1c902d4"
+  inputs-digest = "65c380641dcebca21a6343c9ea36bab5cbebff696e27c74d0735077f63272248"
   solver-name = "gps-cdcl"
   solver-version = 1

tm-bench/Gopkg.toml

@@ -43,11 +43,11 @@
 
 [[constraint]]
   name = "github.com/tendermint/tendermint"
-  branch = "master"
+  branch = "develop"
 
 [[constraint]]
   name = "github.com/tendermint/tmlibs"
-  branch = "master"
+  branch = "develop"
 
 [prune]
   go-tests = true

tm-bench/README.md

@@ -10,18 +10,17 @@ For example, the following:
 
 will output:
 
-    Stats             Avg        Stdev      Max
-    Txs/sec           833        427        1326     
-    Blocks/sec        0.900      0.300      1
+    Stats          Avg       StdDev     Max      Total     
+    Txs/sec        818       532        1549     9000      
+    Blocks/sec     0.818     0.386      1        9
 
-These stats are derived by sending transactions at the specified rate for the
-specified time. After the specified time, it iterates over all of the blocks
-that were created in that time. The average and stddev per second are computed
-based off of that, by grouping the data by second.
 
 ## Quick Start
 
 [Install Tendermint](https://github.com/tendermint/tendermint#install)
+This currently is setup to work on tendermint's develop branch. Please ensure
+you are on that. (If not, update `tendermint` and `tmlibs` in gopkg.toml to use
+  the master branch.)
 
 then run:
 
@@ -49,6 +48,21 @@ with the last command being in a seperate window.
             Size per tx in bytes
       -v    Verbose output
 
+## How stats are collected
+
+These stats are derived by having each connection send transactions at the
+specified rate (or as close as it can get) for the specified time. After the
+specified time, it iterates over all of the blocks that were created in that
+time. The average and stddev per second are computed based off of that, by
+grouping the data by second.
+
+To send transactions at the specified rate in each connection, we loop
+through the number of transactions. If its too slow, the loop stops at one second.
+If its too fast, we wait until the one second mark ends. The transactions per
+second stat is computed based off of what ends up in the block.
+
+Each of the connections is running via a separate goroutine. 
+
 ## Development
 
     make get_vendor_deps

tm-bench/bench_test.go

@@ -0,0 +1,18 @@
+package main
+
+import (
+	"testing"
+	"time"
+)
+
+func BenchmarkTimingPerTx(b *testing.B) {
+	startTime := time.Now()
+	endTime := startTime.Add(time.Second)
+	for i := 0; i < b.N; i++ {
+		if i%20 == 0 {
+			if time.Now().After(endTime) {
+				continue
+			}
+		}
+	}
+}

tm-bench/main.go

@@ -105,9 +105,9 @@ Examples:
 		txSize,
 		"broadcast_tx_"+broadcastTxMethod,
 	)
-
+	endTime := time.Duration(duration) * time.Second
 	select {
-	case <-time.After(time.Duration(duration) * time.Second):
+	case <-time.After(endTime):
 		for _, t := range transacters {
 			t.Stop()
 		}

tm-bench/transacter.go

@@ -148,6 +148,8 @@ func (t *transacter) sendLoop(connIndex int) {
 		select {
 		case <-txsTicker.C:
 			startTime := time.Now()
+			endTime := startTime.Add(time.Second)
+			numTxSent := t.Rate
 
 			for i := 0; i < t.Rate; i++ {
 				// each transaction embeds connection index, tx number and hash of the hostname
@@ -171,6 +173,15 @@ func (t *transacter) sendLoop(connIndex int) {
 					os.Exit(1)
 				}
 
+				// Time added here is 7.13 ns/op, not significant enough to worry about
+				if i%20 == 0 {
+					if time.Now().After(endTime) {
+						// Plus one accounts for sending this tx
+						numTxSent = i + 1
+						break
+					}
+				}
+
 				txNumber++
 			}
 
@@ -178,7 +189,8 @@ func (t *transacter) sendLoop(connIndex int) {
 			if timeToSend < 1*time.Second {
 				time.Sleep(time.Second - timeToSend)
 			}
-			logger.Info(fmt.Sprintf("sent %d transactions", t.Rate), "took", timeToSend)
+
+			logger.Info(fmt.Sprintf("sent %d transactions", numTxSent), "took", timeToSend)
 		case <-pingsTicker.C:
 			// go-rpc server closes the connection in the absence of pings
 			c.SetWriteDeadline(time.Now().Add(sendTimeout))