From 2aeeb72fa5c4f90d0ab072a361a678c3cdee8e26 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Sat, 27 Jun 2015 18:12:58 +0300 Subject: [PATCH 1/4] cmd/geth, metrics: separate process metric collection, add disk --- cmd/geth/main.go | 24 ++----------------- metrics/disk.go | 9 +++++++ metrics/disk_linux.go | 55 +++++++++++++++++++++++++++++++++++++++++++ metrics/disk_nop.go | 10 ++++++++ metrics/metrics.go | 54 ++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 130 insertions(+), 22 deletions(-) create mode 100644 metrics/disk.go create mode 100644 metrics/disk_linux.go create mode 100644 metrics/disk_nop.go create mode 100644 metrics/metrics.go diff --git a/cmd/geth/main.go b/cmd/geth/main.go index fcf7f27f0..6a52159ea 100644 --- a/cmd/geth/main.go +++ b/cmd/geth/main.go @@ -39,11 +39,11 @@ import ( "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/eth" "github.com/ethereum/go-ethereum/logger" + "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/rpc/codec" "github.com/ethereum/go-ethereum/rpc/comms" "github.com/mattn/go-colorable" "github.com/mattn/go-isatty" - "github.com/rcrowley/go-metrics" ) const ( @@ -288,27 +288,7 @@ JavaScript API. See https://github.com/ethereum/go-ethereum/wiki/Javascipt-Conso return nil } // Start system runtime metrics collection - go func() { - allocs := metrics.GetOrRegisterMeter("system/memory/allocs", metrics.DefaultRegistry) - frees := metrics.GetOrRegisterMeter("system/memory/frees", metrics.DefaultRegistry) - inuse := metrics.GetOrRegisterMeter("system/memory/inuse", metrics.DefaultRegistry) - pauses := metrics.GetOrRegisterMeter("system/memory/pauses", metrics.DefaultRegistry) - - stats := make([]*runtime.MemStats, 2) - for i := 0; i < len(stats); i++ { - stats[i] = new(runtime.MemStats) - } - for i := 1; ; i++ { - runtime.ReadMemStats(stats[i%2]) - - allocs.Mark(int64(stats[i%2].Mallocs - stats[(i-1)%2].Mallocs)) - frees.Mark(int64(stats[i%2].Frees - stats[(i-1)%2].Frees)) - inuse.Mark(int64(stats[i%2].Alloc - stats[(i-1)%2].Alloc)) - pauses.Mark(int64(stats[i%2].PauseTotalNs - stats[(i-1)%2].PauseTotalNs)) - - time.Sleep(3 * time.Second) - } - }() + go metrics.CollectProcessMetrics(3 * time.Second) } func main() { diff --git a/metrics/disk.go b/metrics/disk.go new file mode 100644 index 000000000..1b6c56773 --- /dev/null +++ b/metrics/disk.go @@ -0,0 +1,9 @@ +package metrics + +// DiskStats is the per process disk io stats. +type DiskStats struct { + ReadCount int64 // Number of read operations executed + ReadBytes int64 // Total number of bytes read + WriteCount int64 // Number of write operations executed + WriteBytes int64 // Total number of byte written +} diff --git a/metrics/disk_linux.go b/metrics/disk_linux.go new file mode 100644 index 000000000..82b204534 --- /dev/null +++ b/metrics/disk_linux.go @@ -0,0 +1,55 @@ +// Contains the Linux implementation of process disk IO counter retrieval. + +package metrics + +import ( + "bufio" + "fmt" + "io" + "os" + "strconv" + "strings" +) + +// ReadDiskStats retrieves the disk IO stats belonging to the current process. +func ReadDiskStats(stats *DiskStats) error { + // Open the process disk IO counter file + inf, err := os.Open(fmt.Sprintf("/proc/%d/io", os.Getpid())) + if err != nil { + return err + } + in := bufio.NewReader(inf) + + // Iterate over the IO counter, and extract what we need + for { + // Read the next line and split to key and value + line, err := in.ReadString('\n') + if err != nil { + if err == io.EOF { + return nil + } + return err + } + key, value := "", int64(0) + if parts := strings.Split(line, ":"); len(parts) != 2 { + continue + } else { + key = strings.TrimSpace(parts[0]) + if value, err = strconv.ParseInt(strings.TrimSpace(parts[1]), 10, 64); err != nil { + return err + } + } + // Update the counter based on the key + switch key { + case "syscr": + stats.ReadCount = value + case "syscw": + stats.WriteCount = value + case "rchar": + stats.ReadBytes = value + case "wchar": + stats.WriteBytes = value + } + } + return nil +} diff --git a/metrics/disk_nop.go b/metrics/disk_nop.go new file mode 100644 index 000000000..539ab8d1a --- /dev/null +++ b/metrics/disk_nop.go @@ -0,0 +1,10 @@ +// +build !linux + +package metrics + +import "errors" + +// ReadDiskStats retrieves the disk IO stats belonging to the current process. +func ReadDiskStats(stats *DiskStats) error { + return errors.New("Not implemented") +} diff --git a/metrics/metrics.go b/metrics/metrics.go new file mode 100644 index 000000000..cb0caaae4 --- /dev/null +++ b/metrics/metrics.go @@ -0,0 +1,54 @@ +// Package metrics provides general system and process level metrics collection. +package metrics + +import ( + "runtime" + "time" + + "github.com/ethereum/go-ethereum/logger" + "github.com/ethereum/go-ethereum/logger/glog" + "github.com/rcrowley/go-metrics" +) + +// CollectProcessMetrics periodically collects various metrics about the running +// process. +func CollectProcessMetrics(refresh time.Duration) { + // Create the various data collectors + memstats := make([]*runtime.MemStats, 2) + diskstats := make([]*DiskStats, 2) + for i := 0; i < len(memstats); i++ { + memstats[i] = new(runtime.MemStats) + diskstats[i] = new(DiskStats) + } + // Define the various metrics to collect + memAllocs := metrics.GetOrRegisterMeter("system/memory/allocs", metrics.DefaultRegistry) + memFrees := metrics.GetOrRegisterMeter("system/memory/frees", metrics.DefaultRegistry) + memInuse := metrics.GetOrRegisterMeter("system/memory/inuse", metrics.DefaultRegistry) + memPauses := metrics.GetOrRegisterMeter("system/memory/pauses", metrics.DefaultRegistry) + + var diskReads, diskReadBytes, diskWrites, diskWriteBytes metrics.Meter + if err := ReadDiskStats(diskstats[0]); err == nil { + diskReads = metrics.GetOrRegisterMeter("system/disk/readcount", metrics.DefaultRegistry) + diskReadBytes = metrics.GetOrRegisterMeter("system/disk/readdata", metrics.DefaultRegistry) + diskWrites = metrics.GetOrRegisterMeter("system/disk/writecount", metrics.DefaultRegistry) + diskWriteBytes = metrics.GetOrRegisterMeter("system/disk/writedata", metrics.DefaultRegistry) + } else { + glog.V(logger.Debug).Infof("failed to read disk metrics: %v", err) + } + // Iterate loading the different stats and updating the meters + for i := 1; ; i++ { + runtime.ReadMemStats(memstats[i%2]) + memAllocs.Mark(int64(memstats[i%2].Mallocs - memstats[(i-1)%2].Mallocs)) + memFrees.Mark(int64(memstats[i%2].Frees - memstats[(i-1)%2].Frees)) + memInuse.Mark(int64(memstats[i%2].Alloc - memstats[(i-1)%2].Alloc)) + memPauses.Mark(int64(memstats[i%2].PauseTotalNs - memstats[(i-1)%2].PauseTotalNs)) + + if ReadDiskStats(diskstats[i%2]) == nil { + diskReads.Mark(int64(diskstats[i%2].ReadCount - diskstats[(i-1)%2].ReadCount)) + diskReadBytes.Mark(int64(diskstats[i%2].ReadBytes - diskstats[(i-1)%2].ReadBytes)) + diskWrites.Mark(int64(diskstats[i%2].WriteCount - diskstats[(i-1)%2].WriteCount)) + diskWriteBytes.Mark(int64(diskstats[i%2].WriteBytes - diskstats[(i-1)%2].WriteBytes)) + } + time.Sleep(refresh) + } +} From ccbb56b4f2cdba352eaa859ce3e34f999287f5c0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Sat, 27 Jun 2015 20:03:31 +0300 Subject: [PATCH 2/4] cmd/geth, eth, ethdb: monitor database compactions --- cmd/geth/monitorcmd.go | 2 +- eth/backend.go | 39 ++++++++++------- ethdb/database.go | 97 ++++++++++++++++++++++++++++++++++++------ 3 files changed, 109 insertions(+), 29 deletions(-) diff --git a/cmd/geth/monitorcmd.go b/cmd/geth/monitorcmd.go index fe771b561..05965f009 100644 --- a/cmd/geth/monitorcmd.go +++ b/cmd/geth/monitorcmd.go @@ -285,7 +285,7 @@ func updateChart(metric string, data []float64, base *int, chart *termui.LineCha } // Update the chart's label with the scale units units := dataUnits - if strings.Contains(metric, "/Percentiles/") || strings.Contains(metric, "/pauses/") { + if strings.Contains(metric, "/Percentiles/") || strings.Contains(metric, "/pauses/") || strings.Contains(metric, "/time/") { units = timeUnits } chart.Border.Label = metric diff --git a/eth/backend.go b/eth/backend.go index 0da6f128c..21ec71b10 100644 --- a/eth/backend.go +++ b/eth/backend.go @@ -250,33 +250,42 @@ func New(config *Config) (*Ethereum, error) { return nil, fmt.Errorf("blockchain db err: %v", err) } if db, ok := blockDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/block/Gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/block/Puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/block/Misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/block/Reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/block/Writes", metrics.DefaultRegistry) + db.GetTimer = metrics.GetOrRegisterTimer("eth/db/block/user/gets", metrics.DefaultRegistry) + db.PutTimer = metrics.GetOrRegisterTimer("eth/db/block/user/puts", metrics.DefaultRegistry) + db.MissMeter = metrics.GetOrRegisterMeter("eth/db/block/user/misses", metrics.DefaultRegistry) + db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/block/user/reads", metrics.DefaultRegistry) + db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/block/user/writes", metrics.DefaultRegistry) + db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/time", metrics.DefaultRegistry) + db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/input", metrics.DefaultRegistry) + db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/output", metrics.DefaultRegistry) } stateDb, err := newdb(filepath.Join(config.DataDir, "state")) if err != nil { return nil, fmt.Errorf("state db err: %v", err) } if db, ok := stateDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/state/Gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/state/Puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/state/Misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/state/Reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/state/Writes", metrics.DefaultRegistry) + db.GetTimer = metrics.GetOrRegisterTimer("eth/db/state/user/gets", metrics.DefaultRegistry) + db.PutTimer = metrics.GetOrRegisterTimer("eth/db/state/user/puts", metrics.DefaultRegistry) + db.MissMeter = metrics.GetOrRegisterMeter("eth/db/state/user/misses", metrics.DefaultRegistry) + db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/state/user/reads", metrics.DefaultRegistry) + db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/state/user/writes", metrics.DefaultRegistry) + db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/time", metrics.DefaultRegistry) + db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/input", metrics.DefaultRegistry) + db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/output", metrics.DefaultRegistry) } extraDb, err := newdb(filepath.Join(config.DataDir, "extra")) if err != nil { return nil, fmt.Errorf("extra db err: %v", err) } if db, ok := extraDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/extra/Gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/extra/Puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/extra/Misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/extra/Reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/extra/Writes", metrics.DefaultRegistry) + db.GetTimer = metrics.GetOrRegisterTimer("eth/db/extra/user/gets", metrics.DefaultRegistry) + db.PutTimer = metrics.GetOrRegisterTimer("eth/db/extra/user/puts", metrics.DefaultRegistry) + db.MissMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/misses", metrics.DefaultRegistry) + db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/reads", metrics.DefaultRegistry) + db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/writes", metrics.DefaultRegistry) + db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/time", metrics.DefaultRegistry) + db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/input", metrics.DefaultRegistry) + db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/output", metrics.DefaultRegistry) } nodeDb := filepath.Join(config.DataDir, "nodes") diff --git a/ethdb/database.go b/ethdb/database.go index 8f55d43c3..9ff90d167 100644 --- a/ethdb/database.go +++ b/ethdb/database.go @@ -1,6 +1,8 @@ package ethdb import ( + "strconv" + "strings" "time" "github.com/ethereum/go-ethereum/compression/rle" @@ -19,12 +21,15 @@ type LDBDatabase struct { fn string // filename for reporting db *leveldb.DB // LevelDB instance - GetTimer metrics.Timer // Timer for measuring the database get request counts and latencies - PutTimer metrics.Timer // Timer for measuring the database put request counts and latencies - DelTimer metrics.Timer // Timer for measuring the database delete request counts and latencies - MissMeter metrics.Meter // MEter for measuring the missed database get requests - ReadMeter metrics.Meter // Meter for measuring the database get request data usage - WriteMeter metrics.Meter // Meter for measuring the database put request data usage + GetTimer metrics.Timer // Timer for measuring the database get request counts and latencies + PutTimer metrics.Timer // Timer for measuring the database put request counts and latencies + DelTimer metrics.Timer // Timer for measuring the database delete request counts and latencies + MissMeter metrics.Meter // Meter for measuring the missed database get requests + ReadMeter metrics.Meter // Meter for measuring the database get request data usage + WriteMeter metrics.Meter // Meter for measuring the database put request data usage + CompTimeMeter metrics.Meter // Meter for measuring the total time spent in database compaction + CompReadMeter metrics.Meter // Meter for measuring the data read during compaction + CompWriteMeter metrics.Meter // Meter for measuring the data written during compaction } // NewLDBDatabase returns a LevelDB wrapped object. LDBDatabase does not persist data by @@ -45,6 +50,7 @@ func NewLDBDatabase(file string) (*LDBDatabase, error) { fn: file, db: db, } + go database.meter(3 * time.Second) return database, nil } @@ -53,8 +59,7 @@ func NewLDBDatabase(file string) (*LDBDatabase, error) { func (self *LDBDatabase) Put(key []byte, value []byte) error { // Measure the database put latency, if requested if self.PutTimer != nil { - start := time.Now() - defer self.PutTimer.UpdateSince(start) + defer self.PutTimer.UpdateSince(time.Now()) } // Generate the data to write to disk, update the meter and write dat := rle.Compress(value) @@ -69,8 +74,7 @@ func (self *LDBDatabase) Put(key []byte, value []byte) error { func (self *LDBDatabase) Get(key []byte) ([]byte, error) { // Measure the database get latency, if requested if self.GetTimer != nil { - start := time.Now() - defer self.GetTimer.UpdateSince(start) + defer self.GetTimer.UpdateSince(time.Now()) } // Retrieve the key and increment the miss counter if not found dat, err := self.db.Get(key, nil) @@ -91,8 +95,7 @@ func (self *LDBDatabase) Get(key []byte) ([]byte, error) { func (self *LDBDatabase) Delete(key []byte) error { // Measure the database delete latency, if requested if self.DelTimer != nil { - start := time.Now() - defer self.DelTimer.UpdateSince(start) + defer self.DelTimer.UpdateSince(time.Now()) } // Execute the actual operation return self.db.Delete(key, nil) @@ -111,7 +114,6 @@ func (self *LDBDatabase) Close() { if err := self.Flush(); err != nil { glog.V(logger.Error).Infof("error: flush '%s': %v\n", self.fn, err) } - self.db.Close() glog.V(logger.Error).Infoln("flushed and closed db:", self.fn) } @@ -119,3 +121,72 @@ func (self *LDBDatabase) Close() { func (self *LDBDatabase) LDB() *leveldb.DB { return self.db } + +// meter periodically retrieves internal leveldb counters and reports them to +// the metrics subsystem. +// +// This is how a stats table look like (currently): +// Compactions +// Level | Tables | Size(MB) | Time(sec) | Read(MB) | Write(MB) +// -------+------------+---------------+---------------+---------------+--------------- +// 0 | 0 | 0.00000 | 1.27969 | 0.00000 | 12.31098 +// 1 | 85 | 109.27913 | 28.09293 | 213.92493 | 214.26294 +// 2 | 523 | 1000.37159 | 7.26059 | 66.86342 | 66.77884 +// 3 | 570 | 1113.18458 | 0.00000 | 0.00000 | 0.00000 +func (self *LDBDatabase) meter(refresh time.Duration) { + // Create the counters to store current and previous values + counters := make([][]float64, 2) + for i := 0; i < 2; i++ { + counters[i] = make([]float64, 3) + } + // Iterate ad infinitum and collect the stats + for i := 1; ; i++ { + // Retrieve the database stats + stats, err := self.db.GetProperty("leveldb.stats") + if err != nil { + glog.V(logger.Error).Infof("failed to read database stats: %v", err) + return + } + // Find the compaction table, skip the header + lines := strings.Split(stats, "\n") + for len(lines) > 0 && strings.TrimSpace(lines[0]) != "Compactions" { + lines = lines[1:] + } + if len(lines) <= 3 { + glog.V(logger.Error).Infof("compaction table not found") + return + } + lines = lines[3:] + + // Iterate over all the table rows, and accumulate the entries + for j := 0; j < len(counters[i%2]); j++ { + counters[i%2][j] = 0 + } + for _, line := range lines { + parts := strings.Split(line, "|") + if len(parts) != 6 { + break + } + for idx, counter := range parts[3:] { + if value, err := strconv.ParseFloat(strings.TrimSpace(counter), 64); err != nil { + glog.V(logger.Error).Infof("compaction entry parsing failed: %v", err) + return + } else { + counters[i%2][idx] += value + } + } + } + // Update all the requested meters + if self.CompTimeMeter != nil { + self.CompTimeMeter.Mark(int64((counters[i%2][0] - counters[(i-1)%2][0]) * 1000 * 1000 * 1000)) + } + if self.CompReadMeter != nil { + self.CompReadMeter.Mark(int64((counters[i%2][1] - counters[(i-1)%2][1]) * 1024 * 1024)) + } + if self.CompWriteMeter != nil { + self.CompWriteMeter.Mark(int64((counters[i%2][2] - counters[(i-1)%2][2]) * 1024 * 1024)) + } + // Sleep a bit, then repeat the stats collection + time.Sleep(refresh) + } +} From 01fe97211354d13ecaba8a52c82b808b7a7e8393 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Mon, 29 Jun 2015 16:11:01 +0300 Subject: [PATCH 3/4] cmd, core, eth, metrics, p2p: require enabling metrics --- cmd/geth/main.go | 1 + cmd/geth/monitorcmd.go | 7 +++++- cmd/utils/flags.go | 6 +++++ core/chain_manager.go | 3 ++- eth/backend.go | 51 +++++++++++++++++++++--------------------- eth/fetcher/fetcher.go | 30 ++++++------------------- eth/fetcher/metrics.go | 16 +++++++++++++ metrics/metrics.go | 42 ++++++++++++++++++++++++++++++++++ p2p/metrics.go | 10 ++++----- 9 files changed, 111 insertions(+), 55 deletions(-) create mode 100644 eth/fetcher/metrics.go diff --git a/cmd/geth/main.go b/cmd/geth/main.go index 6a52159ea..3e945687b 100644 --- a/cmd/geth/main.go +++ b/cmd/geth/main.go @@ -272,6 +272,7 @@ JavaScript API. See https://github.com/ethereum/go-ethereum/wiki/Javascipt-Conso utils.LogJSONFlag, utils.PProfEanbledFlag, utils.PProfPortFlag, + utils.MetricsEnabledFlag, utils.SolcPathFlag, utils.GpoMinGasPriceFlag, utils.GpoMaxGasPriceFlag, diff --git a/cmd/geth/monitorcmd.go b/cmd/geth/monitorcmd.go index 05965f009..6a7e1cbb4 100644 --- a/cmd/geth/monitorcmd.go +++ b/cmd/geth/monitorcmd.go @@ -75,7 +75,12 @@ func monitor(ctx *cli.Context) { if len(monitored) == 0 { list := expandMetrics(metrics, "") sort.Strings(list) - utils.Fatalf("No metrics specified.\n\nAvailable:\n - %s", strings.Join(list, "\n - ")) + + if len(list) > 0 { + utils.Fatalf("No metrics specified.\n\nAvailable:\n - %s", strings.Join(list, "\n - ")) + } else { + utils.Fatalf("No metrics specified.\n\nNo metrics collected (--metrics)\n") + } } sort.Strings(monitored) if cols := len(monitored) / ctx.Int(monitorCommandRowsFlag.Name); cols > 6 { diff --git a/cmd/utils/flags.go b/cmd/utils/flags.go index 15a577a07..0d59980ec 100644 --- a/cmd/utils/flags.go +++ b/cmd/utils/flags.go @@ -10,6 +10,8 @@ import ( "path/filepath" "runtime" + "github.com/ethereum/go-ethereum/metrics" + "github.com/codegangsta/cli" "github.com/ethereum/ethash" "github.com/ethereum/go-ethereum/accounts" @@ -187,6 +189,10 @@ var ( Usage: "Port on which the profiler should listen", Value: 6060, } + MetricsEnabledFlag = cli.BoolFlag{ + Name: metrics.MetricsEnabledFlag, + Usage: "Enables metrics collection and reporting", + } // RPC settings RPCEnabledFlag = cli.BoolFlag{ diff --git a/core/chain_manager.go b/core/chain_manager.go index fc1922b3b..480311951 100644 --- a/core/chain_manager.go +++ b/core/chain_manager.go @@ -18,6 +18,7 @@ import ( "github.com/ethereum/go-ethereum/event" "github.com/ethereum/go-ethereum/logger" "github.com/ethereum/go-ethereum/logger/glog" + "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/params" "github.com/ethereum/go-ethereum/pow" "github.com/ethereum/go-ethereum/rlp" @@ -33,7 +34,7 @@ var ( blockHashPre = []byte("block-hash-") blockNumPre = []byte("block-num-") - blockInsertTimer = metrics.GetOrRegisterTimer("core/BlockInsertions", metrics.DefaultRegistry) + blockInsertTimer = metrics.NewTimer("chain/inserts") ) const ( diff --git a/eth/backend.go b/eth/backend.go index 21ec71b10..4644b8a93 100644 --- a/eth/backend.go +++ b/eth/backend.go @@ -11,6 +11,8 @@ import ( "strings" "time" + "github.com/ethereum/go-ethereum/metrics" + "github.com/ethereum/ethash" "github.com/ethereum/go-ethereum/accounts" "github.com/ethereum/go-ethereum/common" @@ -29,7 +31,6 @@ import ( "github.com/ethereum/go-ethereum/p2p/discover" "github.com/ethereum/go-ethereum/p2p/nat" "github.com/ethereum/go-ethereum/whisper" - "github.com/rcrowley/go-metrics" ) const ( @@ -250,42 +251,42 @@ func New(config *Config) (*Ethereum, error) { return nil, fmt.Errorf("blockchain db err: %v", err) } if db, ok := blockDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/block/user/gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/block/user/puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/block/user/misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/block/user/reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/block/user/writes", metrics.DefaultRegistry) - db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/time", metrics.DefaultRegistry) - db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/input", metrics.DefaultRegistry) - db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/block/compact/output", metrics.DefaultRegistry) + db.GetTimer = metrics.NewTimer("eth/db/block/user/gets") + db.PutTimer = metrics.NewTimer("eth/db/block/user/puts") + db.MissMeter = metrics.NewMeter("eth/db/block/user/misses") + db.ReadMeter = metrics.NewMeter("eth/db/block/user/reads") + db.WriteMeter = metrics.NewMeter("eth/db/block/user/writes") + db.CompTimeMeter = metrics.NewMeter("eth/db/block/compact/time") + db.CompReadMeter = metrics.NewMeter("eth/db/block/compact/input") + db.CompWriteMeter = metrics.NewMeter("eth/db/block/compact/output") } stateDb, err := newdb(filepath.Join(config.DataDir, "state")) if err != nil { return nil, fmt.Errorf("state db err: %v", err) } if db, ok := stateDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/state/user/gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/state/user/puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/state/user/misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/state/user/reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/state/user/writes", metrics.DefaultRegistry) - db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/time", metrics.DefaultRegistry) - db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/input", metrics.DefaultRegistry) - db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/state/compact/output", metrics.DefaultRegistry) + db.GetTimer = metrics.NewTimer("eth/db/state/user/gets") + db.PutTimer = metrics.NewTimer("eth/db/state/user/puts") + db.MissMeter = metrics.NewMeter("eth/db/state/user/misses") + db.ReadMeter = metrics.NewMeter("eth/db/state/user/reads") + db.WriteMeter = metrics.NewMeter("eth/db/state/user/writes") + db.CompTimeMeter = metrics.NewMeter("eth/db/state/compact/time") + db.CompReadMeter = metrics.NewMeter("eth/db/state/compact/input") + db.CompWriteMeter = metrics.NewMeter("eth/db/state/compact/output") } extraDb, err := newdb(filepath.Join(config.DataDir, "extra")) if err != nil { return nil, fmt.Errorf("extra db err: %v", err) } if db, ok := extraDb.(*ethdb.LDBDatabase); ok { - db.GetTimer = metrics.GetOrRegisterTimer("eth/db/extra/user/gets", metrics.DefaultRegistry) - db.PutTimer = metrics.GetOrRegisterTimer("eth/db/extra/user/puts", metrics.DefaultRegistry) - db.MissMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/misses", metrics.DefaultRegistry) - db.ReadMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/reads", metrics.DefaultRegistry) - db.WriteMeter = metrics.GetOrRegisterMeter("eth/db/extra/user/writes", metrics.DefaultRegistry) - db.CompTimeMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/time", metrics.DefaultRegistry) - db.CompReadMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/input", metrics.DefaultRegistry) - db.CompWriteMeter = metrics.GetOrRegisterMeter("eth/db/extra/compact/output", metrics.DefaultRegistry) + db.GetTimer = metrics.NewTimer("eth/db/extra/user/gets") + db.PutTimer = metrics.NewTimer("eth/db/extra/user/puts") + db.MissMeter = metrics.NewMeter("eth/db/extra/user/misses") + db.ReadMeter = metrics.NewMeter("eth/db/extra/user/reads") + db.WriteMeter = metrics.NewMeter("eth/db/extra/user/writes") + db.CompTimeMeter = metrics.NewMeter("eth/db/extra/compact/time") + db.CompReadMeter = metrics.NewMeter("eth/db/extra/compact/input") + db.CompWriteMeter = metrics.NewMeter("eth/db/extra/compact/output") } nodeDb := filepath.Join(config.DataDir, "nodes") diff --git a/eth/fetcher/fetcher.go b/eth/fetcher/fetcher.go index 5a1509f89..256b452e1 100644 --- a/eth/fetcher/fetcher.go +++ b/eth/fetcher/fetcher.go @@ -7,13 +7,11 @@ import ( "math/rand" "time" - "github.com/ethereum/go-ethereum/core" - "github.com/ethereum/go-ethereum/common" + "github.com/ethereum/go-ethereum/core" "github.com/ethereum/go-ethereum/core/types" "github.com/ethereum/go-ethereum/logger" "github.com/ethereum/go-ethereum/logger/glog" - "github.com/rcrowley/go-metrics" "gopkg.in/karalabe/cookiejar.v2/collections/prque" ) @@ -99,14 +97,6 @@ type Fetcher struct { // Testing hooks fetchingHook func([]common.Hash) // Method to call upon starting a block fetch importedHook func(*types.Block) // Method to call upon successful block import - - // Runtime metrics - announceMeter metrics.Meter // Counter for metering the inbound announcements - announceTimer metrics.Timer // Counter and timer for metering the announce forwarding - broadcastMeter metrics.Meter // Counter for metering the inbound propagations - broadcastTimer metrics.Timer // Counter and timer for metering the block forwarding - discardMeter metrics.Meter // Counter for metering the discarded blocks - futureMeter metrics.Meter // Counter for metering future blocks } // New creates a block fetcher to retrieve blocks based on hash announcements. @@ -129,12 +119,6 @@ func New(getBlock blockRetrievalFn, validateBlock blockValidatorFn, broadcastBlo chainHeight: chainHeight, insertChain: insertChain, dropPeer: dropPeer, - announceMeter: metrics.GetOrRegisterMeter("eth/sync/RemoteAnnounces", metrics.DefaultRegistry), - announceTimer: metrics.GetOrRegisterTimer("eth/sync/LocalAnnounces", metrics.DefaultRegistry), - broadcastMeter: metrics.GetOrRegisterMeter("eth/sync/RemoteBroadcasts", metrics.DefaultRegistry), - broadcastTimer: metrics.GetOrRegisterTimer("eth/sync/LocalBroadcasts", metrics.DefaultRegistry), - discardMeter: metrics.GetOrRegisterMeter("eth/sync/DiscardedBlocks", metrics.DefaultRegistry), - futureMeter: metrics.GetOrRegisterMeter("eth/sync/FutureBlocks", metrics.DefaultRegistry), } } @@ -246,7 +230,7 @@ func (f *Fetcher) loop() { case notification := <-f.notify: // A block was announced, make sure the peer isn't DOSing us - f.announceMeter.Mark(1) + announceMeter.Mark(1) count := f.announces[notification.origin] + 1 if count > hashLimit { @@ -265,7 +249,7 @@ func (f *Fetcher) loop() { case op := <-f.inject: // A direct block insertion was requested, try and fill any pending gaps - f.broadcastMeter.Mark(1) + broadcastMeter.Mark(1) f.enqueue(op.origin, op.block) case hash := <-f.done: @@ -384,7 +368,7 @@ func (f *Fetcher) enqueue(peer string, block *types.Block) { // Discard any past or too distant blocks if dist := int64(block.NumberU64()) - int64(f.chainHeight()); dist < -maxUncleDist || dist > maxQueueDist { glog.V(logger.Debug).Infof("Peer %s: discarded block #%d [%x], distance %d", peer, block.NumberU64(), hash.Bytes()[:4], dist) - f.discardMeter.Mark(1) + discardMeter.Mark(1) return } // Schedule the block for future importing @@ -423,11 +407,11 @@ func (f *Fetcher) insert(peer string, block *types.Block) { switch err := f.validateBlock(block, parent); err { case nil: // All ok, quickly propagate to our peers - f.broadcastTimer.UpdateSince(block.ReceivedAt) + broadcastTimer.UpdateSince(block.ReceivedAt) go f.broadcastBlock(block, true) case core.BlockFutureErr: - f.futureMeter.Mark(1) + futureMeter.Mark(1) // Weird future block, don't fail, but neither propagate default: @@ -442,7 +426,7 @@ func (f *Fetcher) insert(peer string, block *types.Block) { return } // If import succeeded, broadcast the block - f.announceTimer.UpdateSince(block.ReceivedAt) + announceTimer.UpdateSince(block.ReceivedAt) go f.broadcastBlock(block, false) // Invoke the testing hook if needed diff --git a/eth/fetcher/metrics.go b/eth/fetcher/metrics.go new file mode 100644 index 000000000..e46e3c0fb --- /dev/null +++ b/eth/fetcher/metrics.go @@ -0,0 +1,16 @@ +// Contains the metrics collected by the fetcher. + +package fetcher + +import ( + "github.com/ethereum/go-ethereum/metrics" +) + +var ( + announceMeter = metrics.NewMeter("eth/sync/RemoteAnnounces") + announceTimer = metrics.NewTimer("eth/sync/LocalAnnounces") + broadcastMeter = metrics.NewMeter("eth/sync/RemoteBroadcasts") + broadcastTimer = metrics.NewTimer("eth/sync/LocalBroadcasts") + discardMeter = metrics.NewMeter("eth/sync/DiscardedBlocks") + futureMeter = metrics.NewMeter("eth/sync/FutureBlocks") +) diff --git a/metrics/metrics.go b/metrics/metrics.go index cb0caaae4..33004ee3b 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -2,7 +2,9 @@ package metrics import ( + "os" "runtime" + "strings" "time" "github.com/ethereum/go-ethereum/logger" @@ -10,9 +12,49 @@ import ( "github.com/rcrowley/go-metrics" ) +// MetricsEnabledFlag is the CLI flag name to use to enable metrics collections. +var MetricsEnabledFlag = "metrics" + +// enabled is the flag specifying if metrics are enable or not. +var enabled = false + +// Init enables or disables the metrics system. Since we need this to run before +// any other code gets to create meters and timers, we'll actually do an ugly hack +// and peek into the command line args for the metrics flag. +func init() { + for _, arg := range os.Args { + if strings.TrimLeft(arg, "-") == MetricsEnabledFlag { + glog.V(logger.Info).Infof("Enabling metrics collection") + enabled = true + } + } +} + +// NewMeter create a new metrics Meter, either a real one of a NOP stub depending +// on the metrics flag. +func NewMeter(name string) metrics.Meter { + if !enabled { + return new(metrics.NilMeter) + } + return metrics.GetOrRegisterMeter(name, metrics.DefaultRegistry) +} + +// NewTimer create a new metrics Timer, either a real one of a NOP stub depending +// on the metrics flag. +func NewTimer(name string) metrics.Timer { + if !enabled { + return new(metrics.NilTimer) + } + return metrics.GetOrRegisterTimer(name, metrics.DefaultRegistry) +} + // CollectProcessMetrics periodically collects various metrics about the running // process. func CollectProcessMetrics(refresh time.Duration) { + // Short circuit if the metrics system is disabled + if !enabled { + return + } // Create the various data collectors memstats := make([]*runtime.MemStats, 2) diskstats := make([]*DiskStats, 2) diff --git a/p2p/metrics.go b/p2p/metrics.go index fbe5b1e90..4b519e438 100644 --- a/p2p/metrics.go +++ b/p2p/metrics.go @@ -5,14 +5,14 @@ package p2p import ( "net" - "github.com/rcrowley/go-metrics" + "github.com/ethereum/go-ethereum/metrics" ) var ( - ingressConnectMeter = metrics.GetOrRegisterMeter("p2p/InboundConnects", metrics.DefaultRegistry) - ingressTrafficMeter = metrics.GetOrRegisterMeter("p2p/InboundTraffic", metrics.DefaultRegistry) - egressConnectMeter = metrics.GetOrRegisterMeter("p2p/OutboundConnects", metrics.DefaultRegistry) - egressTrafficMeter = metrics.GetOrRegisterMeter("p2p/OutboundTraffic", metrics.DefaultRegistry) + ingressConnectMeter = metrics.NewMeter("p2p/InboundConnects") + ingressTrafficMeter = metrics.NewMeter("p2p/InboundTraffic") + egressConnectMeter = metrics.NewMeter("p2p/OutboundConnects") + egressTrafficMeter = metrics.NewMeter("p2p/OutboundTraffic") ) // meteredConn is a wrapper around a network TCP connection that meters both the From 5f3792c2a750dd95adeccbd5cf0cb19ecddfb43f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C3=A9ter=20Szil=C3=A1gyi?= Date: Mon, 29 Jun 2015 16:18:34 +0300 Subject: [PATCH 4/4] cmd/geth: decent error message if metrics are disabled --- cmd/geth/monitorcmd.go | 2 +- core/chain_manager.go | 1 - 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/cmd/geth/monitorcmd.go b/cmd/geth/monitorcmd.go index 6a7e1cbb4..6593b3614 100644 --- a/cmd/geth/monitorcmd.go +++ b/cmd/geth/monitorcmd.go @@ -79,7 +79,7 @@ func monitor(ctx *cli.Context) { if len(list) > 0 { utils.Fatalf("No metrics specified.\n\nAvailable:\n - %s", strings.Join(list, "\n - ")) } else { - utils.Fatalf("No metrics specified.\n\nNo metrics collected (--metrics)\n") + utils.Fatalf("No metrics collected by geth (--%s).\n", utils.MetricsEnabledFlag.Name) } } sort.Strings(monitored) diff --git a/core/chain_manager.go b/core/chain_manager.go index 480311951..7c78b6bb7 100644 --- a/core/chain_manager.go +++ b/core/chain_manager.go @@ -23,7 +23,6 @@ import ( "github.com/ethereum/go-ethereum/pow" "github.com/ethereum/go-ethereum/rlp" "github.com/hashicorp/golang-lru" - "github.com/rcrowley/go-metrics" "github.com/syndtr/goleveldb/leveldb" )