From c8dcb9584e1ea77c9b967d2bec5d167c7df410f0 Mon Sep 17 00:00:00 2001 From: Ryan Schneider Date: Sat, 2 Jun 2018 06:26:47 -0400 Subject: [PATCH 1/6] rpc: use HTTP request context as top-level context (#16861) --- rpc/http.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/rpc/http.go b/rpc/http.go index feaa7348c4..fe5e4b3093 100644 --- a/rpc/http.go +++ b/rpc/http.go @@ -181,7 +181,7 @@ func (srv *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { // All checks passed, create a codec that reads direct from the request body // untilEOF and writes the response to w and order the server to process a // single request. - ctx := context.Background() + ctx := r.Context() ctx = context.WithValue(ctx, "remote", r.RemoteAddr) ctx = context.WithValue(ctx, "scheme", r.Proto) ctx = context.WithValue(ctx, "local", r.Host) From 3f33a7c8ceeefd769a68bbcc2ed3e4ce74ddaef8 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Mon, 4 Jun 2018 09:32:32 +0200 Subject: [PATCH 2/6] consensus/ethash: reduce keccak hash allocations (#16857) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Use Read instead of Sum to avoid internal allocations and copying the state. name old time/op new time/op delta CacheGeneration-8 764ms ± 1% 579ms ± 1% -24.22% (p=0.000 n=20+17) SmallDatasetGeneration-8 75.2ms ±12% 60.6ms ±10% -19.37% (p=0.000 n=20+20) HashimotoLight-8 1.58ms ±11% 1.55ms ± 8% ~ (p=0.322 n=20+19) HashimotoFullSmall-8 4.90µs ± 1% 4.88µs ± 1% -0.31% (p=0.013 n=19+18) --- consensus/ethash/algorithm.go | 23 +++++++++++++++++------ 1 file changed, 17 insertions(+), 6 deletions(-) diff --git a/consensus/ethash/algorithm.go b/consensus/ethash/algorithm.go index 905a7b1ea7..fa1c2c8246 100644 --- a/consensus/ethash/algorithm.go +++ b/consensus/ethash/algorithm.go @@ -94,14 +94,25 @@ func calcDatasetSize(epoch int) uint64 { // reused between hash runs instead of requiring new ones to be created. type hasher func(dest []byte, data []byte) -// makeHasher creates a repetitive hasher, allowing the same hash data structures -// to be reused between hash runs instead of requiring new ones to be created. -// The returned function is not thread safe! +// makeHasher creates a repetitive hasher, allowing the same hash data structures to +// be reused between hash runs instead of requiring new ones to be created. The returned +// function is not thread safe! func makeHasher(h hash.Hash) hasher { + // sha3.state supports Read to get the sum, use it to avoid the overhead of Sum. + // Read alters the state but we reset the hash before every operation. + type readerHash interface { + hash.Hash + Read([]byte) (int, error) + } + rh, ok := h.(readerHash) + if !ok { + panic("can't find Read method on hash") + } + outputLen := rh.Size() return func(dest []byte, data []byte) { - h.Write(data) - h.Sum(dest[:0]) - h.Reset() + rh.Reset() + rh.Write(data) + rh.Read(dest[:outputLen]) } } From 143c4341d8a2231deade6d7341c668d609bd3486 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Mon, 4 Jun 2018 10:47:43 +0300 Subject: [PATCH 3/6] core, eth, trie: streaming GC for the trie cache (#16810) * core, eth, trie: streaming GC for the trie cache * trie: track memcache statistics --- core/blockchain.go | 42 +++++----- eth/api_tracer.go | 8 +- eth/config.go | 2 +- trie/database.go | 188 +++++++++++++++++++++++++++++++++++++++++---- 4 files changed, 202 insertions(+), 38 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index f74a0f5b27..3eee75df71 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -674,7 +674,7 @@ func (bc *BlockChain) Stop() { for !bc.triegc.Empty() { triedb.Dereference(bc.triegc.PopItem().(common.Hash), common.Hash{}) } - if size := triedb.Size(); size != 0 { + if size, _ := triedb.Size(); size != 0 { log.Error("Dangling trie nodes after full cleanup") } } @@ -916,33 +916,29 @@ func (bc *BlockChain) WriteBlockWithState(block *types.Block, receipts []*types. bc.triegc.Push(root, -float32(block.NumberU64())) if current := block.NumberU64(); current > triesInMemory { + // If we exceeded our memory allowance, flush matured singleton nodes to disk + var ( + nodes, imgs = triedb.Size() + limit = common.StorageSize(bc.cacheConfig.TrieNodeLimit) * 1024 * 1024 + ) + if nodes > limit || imgs > 4*1024*1024 { + triedb.Cap(limit - ethdb.IdealBatchSize) + } // Find the next state trie we need to commit header := bc.GetHeaderByNumber(current - triesInMemory) chosen := header.Number.Uint64() - // Only write to disk if we exceeded our memory allowance *and* also have at - // least a given number of tries gapped. - var ( - size = triedb.Size() - limit = common.StorageSize(bc.cacheConfig.TrieNodeLimit) * 1024 * 1024 - ) - if size > limit || bc.gcproc > bc.cacheConfig.TrieTimeLimit { + // If we exceeded out time allowance, flush an entire trie to disk + if bc.gcproc > bc.cacheConfig.TrieTimeLimit { // If we're exceeding limits but haven't reached a large enough memory gap, // warn the user that the system is becoming unstable. - if chosen < lastWrite+triesInMemory { - switch { - case size >= 2*limit: - log.Warn("State memory usage too high, committing", "size", size, "limit", limit, "optimum", float64(chosen-lastWrite)/triesInMemory) - case bc.gcproc >= 2*bc.cacheConfig.TrieTimeLimit: - log.Info("State in memory for too long, committing", "time", bc.gcproc, "allowance", bc.cacheConfig.TrieTimeLimit, "optimum", float64(chosen-lastWrite)/triesInMemory) - } - } - // If optimum or critical limits reached, write to disk - if chosen >= lastWrite+triesInMemory || size >= 2*limit || bc.gcproc >= 2*bc.cacheConfig.TrieTimeLimit { - triedb.Commit(header.Root, true) - lastWrite = chosen - bc.gcproc = 0 + if chosen < lastWrite+triesInMemory && bc.gcproc >= 2*bc.cacheConfig.TrieTimeLimit { + log.Info("State in memory for too long, committing", "time", bc.gcproc, "allowance", bc.cacheConfig.TrieTimeLimit, "optimum", float64(chosen-lastWrite)/triesInMemory) } + // Flush an entire trie and restart the counters + triedb.Commit(header.Root, true) + lastWrite = chosen + bc.gcproc = 0 } // Garbage collect anything below our required write retention for !bc.triegc.Empty() { @@ -1181,7 +1177,9 @@ func (bc *BlockChain) insertChain(chain types.Blocks) (int, []interface{}, []*ty } stats.processed++ stats.usedGas += usedGas - stats.report(chain, i, bc.stateCache.TrieDB().Size()) + + cache, _ := bc.stateCache.TrieDB().Size() + stats.report(chain, i, cache) } // Append a single chain head event if we've progressed the chain if lastCanon != nil && bc.CurrentBlock().Hash() == lastCanon.Hash() { diff --git a/eth/api_tracer.go b/eth/api_tracer.go index 45a819022a..61f5c71d64 100644 --- a/eth/api_tracer.go +++ b/eth/api_tracer.go @@ -251,7 +251,8 @@ func (api *PrivateDebugAPI) traceChain(ctx context.Context, start, end *types.Bl // Print progress logs if long enough time elapsed if time.Since(logged) > 8*time.Second { if number > origin { - log.Info("Tracing chain segment", "start", origin, "end", end.NumberU64(), "current", number, "transactions", traced, "elapsed", time.Since(begin), "memory", database.TrieDB().Size()) + nodes, imgs := database.TrieDB().Size() + log.Info("Tracing chain segment", "start", origin, "end", end.NumberU64(), "current", number, "transactions", traced, "elapsed", time.Since(begin), "memory", nodes+imgs) } else { log.Info("Preparing state for chain trace", "block", number, "start", origin, "elapsed", time.Since(begin)) } @@ -298,6 +299,8 @@ func (api *PrivateDebugAPI) traceChain(ctx context.Context, start, end *types.Bl // Dereference all past tries we ourselves are done working with database.TrieDB().Dereference(proot, common.Hash{}) proot = root + + // TODO(karalabe): Do we need the preimages? Won't they accumulate too much? } }() @@ -526,7 +529,8 @@ func (api *PrivateDebugAPI) computeStateDB(block *types.Block, reexec uint64) (* database.TrieDB().Dereference(proot, common.Hash{}) proot = root } - log.Info("Historical state regenerated", "block", block.NumberU64(), "elapsed", time.Since(start), "size", database.TrieDB().Size()) + nodes, imgs := database.TrieDB().Size() + log.Info("Historical state regenerated", "block", block.NumberU64(), "elapsed", time.Since(start), "nodes", nodes, "preimages", imgs) return statedb, nil } diff --git a/eth/config.go b/eth/config.go index dd7f42c7d9..426d2bf1ef 100644 --- a/eth/config.go +++ b/eth/config.go @@ -47,7 +47,7 @@ var DefaultConfig = Config{ LightPeers: 100, DatabaseCache: 768, TrieCache: 256, - TrieTimeout: 5 * time.Minute, + TrieTimeout: 60 * time.Minute, GasPrice: big.NewInt(18 * params.Shannon), TxPool: core.DefaultTxPoolConfig, diff --git a/trie/database.go b/trie/database.go index da36e72f98..76a6cf79db 100644 --- a/trie/database.go +++ b/trie/database.go @@ -23,6 +23,21 @@ import ( "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/ethdb" "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" +) + +var ( + memcacheFlushTimeTimer = metrics.NewRegisteredResettingTimer("trie/memcache/flush/time", nil) + memcacheFlushNodesMeter = metrics.NewRegisteredMeter("trie/memcache/flush/nodes", nil) + memcacheFlushSizeMeter = metrics.NewRegisteredMeter("trie/memcache/flush/size", nil) + + memcacheGCTimeTimer = metrics.NewRegisteredResettingTimer("trie/memcache/gc/time", nil) + memcacheGCNodesMeter = metrics.NewRegisteredMeter("trie/memcache/gc/nodes", nil) + memcacheGCSizeMeter = metrics.NewRegisteredMeter("trie/memcache/gc/size", nil) + + memcacheCommitTimeTimer = metrics.NewRegisteredResettingTimer("trie/memcache/commit/time", nil) + memcacheCommitNodesMeter = metrics.NewRegisteredMeter("trie/memcache/commit/nodes", nil) + memcacheCommitSizeMeter = metrics.NewRegisteredMeter("trie/memcache/commit/size", nil) ) // secureKeyPrefix is the database key prefix used to store trie node preimages. @@ -46,15 +61,22 @@ type DatabaseReader interface { type Database struct { diskdb ethdb.Database // Persistent storage for matured trie nodes - nodes map[common.Hash]*cachedNode // Data and references relationships of a node - preimages map[common.Hash][]byte // Preimages of nodes from the secure trie - seckeybuf [secureKeyLength]byte // Ephemeral buffer for calculating preimage keys + nodes map[common.Hash]*cachedNode // Data and references relationships of a node + oldest common.Hash // Oldest tracked node, flush-list head + newest common.Hash // Newest tracked node, flush-list tail + + preimages map[common.Hash][]byte // Preimages of nodes from the secure trie + seckeybuf [secureKeyLength]byte // Ephemeral buffer for calculating preimage keys gctime time.Duration // Time spent on garbage collection since last commit gcnodes uint64 // Nodes garbage collected since last commit gcsize common.StorageSize // Data storage garbage collected since last commit - nodesSize common.StorageSize // Storage size of the nodes cache + flushtime time.Duration // Time spent on data flushing since last commit + flushnodes uint64 // Nodes flushed since last commit + flushsize common.StorageSize // Data storage flushed since last commit + + nodesSize common.StorageSize // Storage size of the nodes cache (exc. flushlist) preimagesSize common.StorageSize // Storage size of the preimages cache lock sync.RWMutex @@ -66,6 +88,9 @@ type cachedNode struct { blob []byte // Cached data block of the trie node parents int // Number of live nodes referencing this one children map[common.Hash]int // Children referenced by this nodes + + flushPrev common.Hash // Previous node in the flush-list + flushNext common.Hash // Next node in the flush-list } // NewDatabase creates a new trie database to store ephemeral trie content before @@ -96,12 +121,20 @@ func (db *Database) Insert(hash common.Hash, blob []byte) { // insert is the private locked version of Insert. func (db *Database) insert(hash common.Hash, blob []byte) { + // If the node's already cached, skip if _, ok := db.nodes[hash]; ok { return } db.nodes[hash] = &cachedNode{ - blob: common.CopyBytes(blob), - children: make(map[common.Hash]int), + blob: common.CopyBytes(blob), + children: make(map[common.Hash]int), + flushPrev: db.newest, + } + // Update the flush-list endpoints + if db.oldest == (common.Hash{}) { + db.oldest, db.newest = hash, hash + } else { + db.nodes[db.newest].flushNext, db.newest = hash, hash } db.nodesSize += common.StorageSize(common.HashLength + len(blob)) } @@ -208,6 +241,10 @@ func (db *Database) Dereference(child common.Hash, parent common.Hash) { db.gcsize += storage - db.nodesSize db.gctime += time.Since(start) + memcacheGCTimeTimer.Update(time.Since(start)) + memcacheGCSizeMeter.Mark(int64(storage - db.nodesSize)) + memcacheGCNodesMeter.Mark(int64(nodes - len(db.nodes))) + log.Debug("Dereferenced trie from memory database", "nodes", nodes-len(db.nodes), "size", storage-db.nodesSize, "time", time.Since(start), "gcnodes", db.gcnodes, "gcsize", db.gcsize, "gctime", db.gctime, "livenodes", len(db.nodes), "livesize", db.nodesSize) } @@ -221,7 +258,7 @@ func (db *Database) dereference(child common.Hash, parent common.Hash) { if node.children[child] == 0 { delete(node.children, child) } - // If the node does not exist, it's a previously committed node. + // If the child does not exist, it's a previously committed node. node, ok := db.nodes[child] if !ok { return @@ -229,6 +266,14 @@ func (db *Database) dereference(child common.Hash, parent common.Hash) { // If there are no more references to the child, delete it and cascade node.parents-- if node.parents == 0 { + // Remove the node from the flush-list + if child == db.oldest { + db.oldest = node.flushNext + } else { + db.nodes[node.flushPrev].flushNext = node.flushNext + db.nodes[node.flushNext].flushPrev = node.flushPrev + } + // Dereference all children and delete the node for hash := range node.children { db.dereference(hash, child) } @@ -237,6 +282,107 @@ func (db *Database) dereference(child common.Hash, parent common.Hash) { } } +// Cap iteratively flushes old but still referenced trie nodes until the total +// memory usage goes below the given threshold. +func (db *Database) Cap(limit common.StorageSize) error { + // Create a database batch to flush persistent data out. It is important that + // outside code doesn't see an inconsistent state (referenced data removed from + // memory cache during commit but not yet in persistent storage). This is ensured + // by only uncaching existing data when the database write finalizes. + db.lock.RLock() + + nodes, storage, start := len(db.nodes), db.nodesSize, time.Now() + batch := db.diskdb.NewBatch() + + // db.nodesSize only contains the useful data in the cache, but when reporting + // the total memory consumption, the maintenance metadata is also needed to be + // counted. For every useful node, we track 2 extra hashes as the flushlist. + size := db.nodesSize + common.StorageSize(len(db.nodes)*2*common.HashLength) + + // If the preimage cache got large enough, push to disk. If it's still small + // leave for later to deduplicate writes. + flushPreimages := db.preimagesSize > 4*1024*1024 + if flushPreimages { + for hash, preimage := range db.preimages { + if err := batch.Put(db.secureKey(hash[:]), preimage); err != nil { + log.Error("Failed to commit preimage from trie database", "err", err) + db.lock.RUnlock() + return err + } + if batch.ValueSize() > ethdb.IdealBatchSize { + if err := batch.Write(); err != nil { + db.lock.RUnlock() + return err + } + batch.Reset() + } + } + } + // Keep committing nodes from the flush-list until we're below allowance + oldest := db.oldest + for size > limit && oldest != (common.Hash{}) { + // Fetch the oldest referenced node and push into the batch + node := db.nodes[oldest] + if err := batch.Put(oldest[:], node.blob); err != nil { + db.lock.RUnlock() + return err + } + // If we exceeded the ideal batch size, commit and reset + if batch.ValueSize() >= ethdb.IdealBatchSize { + if err := batch.Write(); err != nil { + log.Error("Failed to write flush list to disk", "err", err) + db.lock.RUnlock() + return err + } + batch.Reset() + } + // Iterate to the next flush item, or abort if the size cap was achieved. Size + // is the total size, including both the useful cached data (hash -> blob), as + // well as the flushlist metadata (2*hash). When flushing items from the cache, + // we need to reduce both. + size -= common.StorageSize(3*common.HashLength + len(node.blob)) + oldest = node.flushNext + } + // Flush out any remainder data from the last batch + if err := batch.Write(); err != nil { + log.Error("Failed to write flush list to disk", "err", err) + db.lock.RUnlock() + return err + } + db.lock.RUnlock() + + // Write successful, clear out the flushed data + db.lock.Lock() + defer db.lock.Unlock() + + if flushPreimages { + db.preimages = make(map[common.Hash][]byte) + db.preimagesSize = 0 + } + for db.oldest != oldest { + node := db.nodes[db.oldest] + delete(db.nodes, db.oldest) + db.oldest = node.flushNext + + db.nodesSize -= common.StorageSize(common.HashLength + len(node.blob)) + } + if db.oldest != (common.Hash{}) { + db.nodes[db.oldest].flushPrev = common.Hash{} + } + db.flushnodes += uint64(nodes - len(db.nodes)) + db.flushsize += storage - db.nodesSize + db.flushtime += time.Since(start) + + memcacheFlushTimeTimer.Update(time.Since(start)) + memcacheFlushSizeMeter.Mark(int64(storage - db.nodesSize)) + memcacheFlushNodesMeter.Mark(int64(nodes - len(db.nodes))) + + log.Debug("Persisted nodes from memory database", "nodes", nodes-len(db.nodes), "size", storage-db.nodesSize, "time", time.Since(start), + "flushnodes", db.flushnodes, "flushsize", db.flushsize, "flushtime", db.flushtime, "livenodes", len(db.nodes), "livesize", db.nodesSize) + + return nil +} + // Commit iterates over all the children of a particular node, writes them out // to disk, forcefully tearing down all references in both directions. // @@ -266,7 +412,7 @@ func (db *Database) Commit(node common.Hash, report bool) error { } } // Move the trie itself into the batch, flushing if enough data is accumulated - nodes, storage := len(db.nodes), db.nodesSize+db.preimagesSize + nodes, storage := len(db.nodes), db.nodesSize if err := db.commit(node, batch); err != nil { log.Error("Failed to commit trie from trie database", "err", err) db.lock.RUnlock() @@ -289,15 +435,20 @@ func (db *Database) Commit(node common.Hash, report bool) error { db.uncache(node) + memcacheCommitTimeTimer.Update(time.Since(start)) + memcacheCommitSizeMeter.Mark(int64(storage - db.nodesSize)) + memcacheCommitNodesMeter.Mark(int64(nodes - len(db.nodes))) + logger := log.Info if !report { logger = log.Debug } - logger("Persisted trie from memory database", "nodes", nodes-len(db.nodes), "size", storage-db.nodesSize, "time", time.Since(start), + logger("Persisted trie from memory database", "nodes", nodes-len(db.nodes)+int(db.flushnodes), "size", storage-db.nodesSize+db.flushsize, "time", time.Since(start)+db.flushtime, "gcnodes", db.gcnodes, "gcsize", db.gcsize, "gctime", db.gctime, "livenodes", len(db.nodes), "livesize", db.nodesSize) // Reset the garbage collection statistics db.gcnodes, db.gcsize, db.gctime = 0, 0, 0 + db.flushnodes, db.flushsize, db.flushtime = 0, 0, 0 return nil } @@ -317,7 +468,7 @@ func (db *Database) commit(hash common.Hash, batch ethdb.Batch) error { if err := batch.Put(hash[:], node.blob); err != nil { return err } - // If we've reached an optimal match size, commit and start over + // If we've reached an optimal batch size, commit and start over if batch.ValueSize() >= ethdb.IdealBatchSize { if err := batch.Write(); err != nil { return err @@ -337,7 +488,14 @@ func (db *Database) uncache(hash common.Hash) { if !ok { return } - // Otherwise uncache the node's subtries and remove the node itself too + // Node still exists, remove it from the flush-list + if hash == db.oldest { + db.oldest = node.flushNext + } else { + db.nodes[node.flushPrev].flushNext = node.flushNext + db.nodes[node.flushNext].flushPrev = node.flushPrev + } + // Uncache the node's subtries and remove the node itself too for child := range node.children { db.uncache(child) } @@ -347,9 +505,13 @@ func (db *Database) uncache(hash common.Hash) { // Size returns the current storage size of the memory cache in front of the // persistent database layer. -func (db *Database) Size() common.StorageSize { +func (db *Database) Size() (common.StorageSize, common.StorageSize) { db.lock.RLock() defer db.lock.RUnlock() - return db.nodesSize + db.preimagesSize + // db.nodesSize only contains the useful data in the cache, but when reporting + // the total memory consumption, the maintenance metadata is also needed to be + // counted. For every useful node, we track 2 extra hashes as the flushlist. + var flushlistSize = common.StorageSize(len(db.nodes) * 2 * common.HashLength) + return db.nodesSize + flushlistSize, db.preimagesSize } From 17f80cc2e2d22e3ab78d6e60c5b90d61a04ea3b2 Mon Sep 17 00:00:00 2001 From: Martin Holst Swende Date: Mon, 4 Jun 2018 11:41:55 +0200 Subject: [PATCH 4/6] rpc: set timeouts for http server, see #16859 --- rpc/http.go | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/rpc/http.go b/rpc/http.go index fe5e4b3093..6388d68961 100644 --- a/rpc/http.go +++ b/rpc/http.go @@ -165,7 +165,12 @@ func NewHTTPServer(cors []string, vhosts []string, srv *Server) *http.Server { // Wrap the CORS-handler within a host-handler handler := newCorsHandler(srv, cors) handler = newVHostHandler(vhosts, handler) - return &http.Server{Handler: handler} + return &http.Server{ + Handler: handler, + ReadTimeout: 5 * time.Second, + WriteTimeout: 10 * time.Second, + IdleTimeout: 120 * time.Second, + } } // ServeHTTP serves JSON-RPC requests over HTTP. From be2aec092d9c24c24b8d22d684ed0d11653c3cfc Mon Sep 17 00:00:00 2001 From: Anton Evangelatov Date: Mon, 4 Jun 2018 13:05:16 +0300 Subject: [PATCH 5/6] metrics: expvar support for ResettingTimer (#16878) * metrics: expvar support for ResettingTimer * metrics: use integers for percentiles; remove Overall * metrics: fix edge-case panic for index-out-of-range --- metrics/exp/exp.go | 13 ++++ metrics/resetting_timer.go | 2 +- metrics/resetting_timer_test.go | 110 ++++++++++++++++++++++++++++++++ node/api.go | 30 +++++++++ 4 files changed, 154 insertions(+), 1 deletion(-) diff --git a/metrics/exp/exp.go b/metrics/exp/exp.go index c19d00a94d..625ffd4e8a 100644 --- a/metrics/exp/exp.go +++ b/metrics/exp/exp.go @@ -134,6 +134,17 @@ func (exp *exp) publishTimer(name string, metric metrics.Timer) { exp.getFloat(name + ".mean-rate").Set(t.RateMean()) } +func (exp *exp) publishResettingTimer(name string, metric metrics.ResettingTimer) { + t := metric.Snapshot() + ps := t.Percentiles([]float64{50, 75, 95, 99}) + exp.getInt(name + ".count").Set(int64(len(t.Values()))) + exp.getFloat(name + ".mean").Set(t.Mean()) + exp.getInt(name + ".50-percentile").Set(ps[0]) + exp.getInt(name + ".75-percentile").Set(ps[1]) + exp.getInt(name + ".95-percentile").Set(ps[2]) + exp.getInt(name + ".99-percentile").Set(ps[3]) +} + func (exp *exp) syncToExpvar() { exp.registry.Each(func(name string, i interface{}) { switch i.(type) { @@ -149,6 +160,8 @@ func (exp *exp) syncToExpvar() { exp.publishMeter(name, i.(metrics.Meter)) case metrics.Timer: exp.publishTimer(name, i.(metrics.Timer)) + case metrics.ResettingTimer: + exp.publishResettingTimer(name, i.(metrics.ResettingTimer)) default: panic(fmt.Sprintf("unsupported type for '%s': %T", name, i)) } diff --git a/metrics/resetting_timer.go b/metrics/resetting_timer.go index 57bcb31343..f33a9f8aa0 100644 --- a/metrics/resetting_timer.go +++ b/metrics/resetting_timer.go @@ -210,7 +210,7 @@ func (t *ResettingTimerSnapshot) calc(percentiles []float64) { // poor man's math.Round(x): // math.Floor(x + 0.5) indexOfPerc := int(math.Floor(((abs / 100.0) * float64(count)) + 0.5)) - if pct >= 0 { + if pct >= 0 && indexOfPerc > 0 { indexOfPerc -= 1 // index offset=0 } thresholdBoundary = t.values[indexOfPerc] diff --git a/metrics/resetting_timer_test.go b/metrics/resetting_timer_test.go index 58fd47f352..77c49dc386 100644 --- a/metrics/resetting_timer_test.go +++ b/metrics/resetting_timer_test.go @@ -104,3 +104,113 @@ func TestResettingTimer(t *testing.T) { } } } + +func TestResettingTimerWithFivePercentiles(t *testing.T) { + tests := []struct { + values []int64 + start int + end int + wantP05 int64 + wantP20 int64 + wantP50 int64 + wantP95 int64 + wantP99 int64 + wantMean float64 + wantMin int64 + wantMax int64 + }{ + { + values: []int64{}, + start: 1, + end: 11, + wantP05: 1, wantP20: 2, wantP50: 5, wantP95: 10, wantP99: 10, + wantMin: 1, wantMax: 10, wantMean: 5.5, + }, + { + values: []int64{}, + start: 1, + end: 101, + wantP05: 5, wantP20: 20, wantP50: 50, wantP95: 95, wantP99: 99, + wantMin: 1, wantMax: 100, wantMean: 50.5, + }, + { + values: []int64{1}, + start: 0, + end: 0, + wantP05: 1, wantP20: 1, wantP50: 1, wantP95: 1, wantP99: 1, + wantMin: 1, wantMax: 1, wantMean: 1, + }, + { + values: []int64{0}, + start: 0, + end: 0, + wantP05: 0, wantP20: 0, wantP50: 0, wantP95: 0, wantP99: 0, + wantMin: 0, wantMax: 0, wantMean: 0, + }, + { + values: []int64{}, + start: 0, + end: 0, + wantP05: 0, wantP20: 0, wantP50: 0, wantP95: 0, wantP99: 0, + wantMin: 0, wantMax: 0, wantMean: 0, + }, + { + values: []int64{1, 10}, + start: 0, + end: 0, + wantP05: 1, wantP20: 1, wantP50: 1, wantP95: 10, wantP99: 10, + wantMin: 1, wantMax: 10, wantMean: 5.5, + }, + } + for ind, tt := range tests { + timer := NewResettingTimer() + + for i := tt.start; i < tt.end; i++ { + tt.values = append(tt.values, int64(i)) + } + + for _, v := range tt.values { + timer.Update(time.Duration(v)) + } + + snap := timer.Snapshot() + + ps := snap.Percentiles([]float64{5, 20, 50, 95, 99}) + + val := snap.Values() + + if len(val) > 0 { + if tt.wantMin != val[0] { + t.Fatalf("%d: min: got %d, want %d", ind, val[0], tt.wantMin) + } + + if tt.wantMax != val[len(val)-1] { + t.Fatalf("%d: max: got %d, want %d", ind, val[len(val)-1], tt.wantMax) + } + } + + if tt.wantMean != snap.Mean() { + t.Fatalf("%d: mean: got %.2f, want %.2f", ind, snap.Mean(), tt.wantMean) + } + + if tt.wantP05 != ps[0] { + t.Fatalf("%d: p05: got %d, want %d", ind, ps[0], tt.wantP05) + } + + if tt.wantP20 != ps[1] { + t.Fatalf("%d: p20: got %d, want %d", ind, ps[1], tt.wantP20) + } + + if tt.wantP50 != ps[2] { + t.Fatalf("%d: p50: got %d, want %d", ind, ps[2], tt.wantP50) + } + + if tt.wantP95 != ps[3] { + t.Fatalf("%d: p95: got %d, want %d", ind, ps[3], tt.wantP95) + } + + if tt.wantP99 != ps[4] { + t.Fatalf("%d: p99: got %d, want %d", ind, ps[4], tt.wantP99) + } + } +} diff --git a/node/api.go b/node/api.go index da9da5bd72..989d3884ac 100644 --- a/node/api.go +++ b/node/api.go @@ -338,6 +338,21 @@ func (api *PublicDebugAPI) Metrics(raw bool) (map[string]interface{}, error) { }, } + case metrics.ResettingTimer: + t := metric.Snapshot() + ps := t.Percentiles([]float64{5, 20, 50, 80, 95}) + root[name] = map[string]interface{}{ + "Measurements": len(t.Values()), + "Mean": time.Duration(t.Mean()).String(), + "Percentiles": map[string]interface{}{ + "5": time.Duration(ps[0]).String(), + "20": time.Duration(ps[1]).String(), + "50": time.Duration(ps[2]).String(), + "80": time.Duration(ps[3]).String(), + "95": time.Duration(ps[4]).String(), + }, + } + default: root[name] = "Unknown metric type" } @@ -373,6 +388,21 @@ func (api *PublicDebugAPI) Metrics(raw bool) (map[string]interface{}, error) { }, } + case metrics.ResettingTimer: + t := metric.Snapshot() + ps := t.Percentiles([]float64{5, 20, 50, 80, 95}) + root[name] = map[string]interface{}{ + "Measurements": len(t.Values()), + "Mean": time.Duration(t.Mean()).String(), + "Percentiles": map[string]interface{}{ + "5": time.Duration(ps[0]).String(), + "20": time.Duration(ps[1]).String(), + "50": time.Duration(ps[2]).String(), + "80": time.Duration(ps[3]).String(), + "95": time.Duration(ps[4]).String(), + }, + } + default: root[name] = "Unknown metric type" } From a20cc75b4a2982917db83370cadd40e26d1b35b6 Mon Sep 17 00:00:00 2001 From: rjl493456442 Date: Fri, 25 May 2018 15:48:16 +0800 Subject: [PATCH 6/6] cmd/geth: cap cache allowance --- cmd/geth/main.go | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/cmd/geth/main.go b/cmd/geth/main.go index 09d9c493d1..edf2a557a7 100644 --- a/cmd/geth/main.go +++ b/cmd/geth/main.go @@ -19,12 +19,16 @@ package main import ( "fmt" + "math" "os" "runtime" + godebug "runtime/debug" "sort" + "strconv" "strings" "time" + "github.com/elastic/gosigar" "github.com/ethereum/go-ethereum/accounts" "github.com/ethereum/go-ethereum/accounts/keystore" "github.com/ethereum/go-ethereum/cmd/utils" @@ -188,6 +192,22 @@ func init() { if err := debug.Setup(ctx); err != nil { return err } + // Cap the cache allowance and tune the garbage colelctor + var mem gosigar.Mem + if err := mem.Get(); err == nil { + allowance := int(mem.Total / 1024 / 1024 / 3) + if cache := ctx.GlobalInt(utils.CacheFlag.Name); cache > allowance { + log.Warn("Sanitizing cache to Go's GC limits", "provided", cache, "updated", allowance) + ctx.GlobalSet(utils.CacheFlag.Name, strconv.Itoa(allowance)) + } + } + // Ensure Go's GC ignores the database cache for trigger percentage + cache := ctx.GlobalInt(utils.CacheFlag.Name) + gogc := math.Max(20, math.Min(100, 100/(float64(cache)/1024))) + + log.Debug("Sanitizing Go's GC trigger", "percent", int(gogc)) + godebug.SetGCPercent(int(gogc)) + // Start system runtime metrics collection go metrics.CollectProcessMetrics(3 * time.Second)