Skip to content

Commit

Permalink
WIP: problem: should implement interval-based status logging
Browse files Browse the repository at this point in the history 
solution: use a go func connected to the node's Ethereum to grab and calculate relevant logs

rel ethereumproject#127

---

TODO: fix or remove:
- downloading-from peers, eg 'this var/x/x peers'
- shows mode 'FullSync' before downloader initializes, even if it will be 'FastSync'
  • Loading branch information
@whilei
whilei committed Jul 27, 2017
1 parent 7abe6ca commit 2bc9de4
Show file tree
Hide file tree
Showing 5 changed files with 220 additions and 13 deletions.
3 changes: 2 additions & 1 deletion cmd/geth/cmd.go
View file
Expand Up @@ -40,6 +40,8 @@ const (
importBatchSize = 2500
)

var sigc = make(chan os.Signal, 1)

// Fatalf formats a message to standard error and exits the program.
// The message is also printed to standard output if standard error
// is redirected to a different file.
Expand All @@ -66,7 +68,6 @@ func StartNode(stack *node.Node) {
Fatalf("Error starting protocol stack: %v", err)
}
go func() {
sigc := make(chan os.Signal, 1)
signal.Notify(sigc, os.Interrupt, syscall.SIGTERM)
defer signal.Stop(sigc)
sig := <-sigc
Expand Down
4 changes: 2 additions & 2 deletions cmd/geth/flag.go
View file
Expand Up @@ -431,7 +431,7 @@ func makeNodeName(version string, ctx *cli.Context) string {

// MakeSystemNode sets up a local node, configures the services to launch and
// assembles the P2P protocol stack.
func MakeSystemNode(version string, ctx *cli.Context) (*node.Node, *eth.Ethereum) {
func MakeSystemNode(version string, ctx *cli.Context) (*node.Node) {

var ethInstance *eth.Ethereum
// global settings
Expand Down Expand Up @@ -498,7 +498,7 @@ func MakeSystemNode(version string, ctx *cli.Context) (*node.Node, *eth.Ethereum
glog.V(logger.Info).Infoln(fmt.Sprintf("Geth started with --%s flag, which is unused by Geth Classic and can be omitted", Unused1.Name))
}

return stack, ethInstance
return stack
}

// shouldAttemptDirMigration decides based on flags if
Expand Down
6 changes: 6 additions & 0 deletions cmd/geth/flags.go
View file
Expand Up @@ -153,6 +153,12 @@ var (
Usage: "Directory in which to write log files, redirecting terminal out (stderr)",
Value: DirectoryString{filepath.Join(common.DefaultDataDir(), "logs")},
}
LogPaceFlag = cli.StringFlag{
Name: "log-pace",
// TODO: Incompatible is overstated. But there are nuances of their integration that must be considered and negotiated further.
Usage: `Toggle paced logging instead of event-based logging. Values must be of the form N(m|s), where N is a positive integer, and (m|s) is the literal 'm' or 's' designating _m_inute or _s_econd. This option is INCOMPATIBLE with the verbosity and vmodule flags.`,
Value: "1m",
}
BacktraceAtFlag = cli.GenericFlag{
Name: "backtrace",
Usage: "Request a stack trace at a specific logging statement (e.g. \"block.go:271\")",
Expand Down
219 changes: 210 additions & 9 deletions cmd/geth/main.go
View file
Expand Up @@ -40,9 +40,8 @@ import (
"github.com/ethereumproject/go-ethereum/metrics"
"github.com/ethereumproject/go-ethereum/node"
"time"
"github.com/ethereumproject/go-ethereum/p2p"
"net/rpc"
"bytes"
"github.com/ethereumproject/go-ethereum/eth/downloader"
"math/big"
)

// Version is the application revision identifier. It can be set with the linker
Expand Down Expand Up @@ -164,6 +163,7 @@ The output of this command is supposed to be machine-readable.
VerbosityFlag,
VModuleFlag,
LogDirFlag,
LogPaceFlag,
BacktraceAtFlag,
MetricsFlag,
FakePoWFlag,
Expand Down Expand Up @@ -266,11 +266,25 @@ func main() {
// It creates a default node based on the command line arguments and runs it in
// blocking mode, waiting for it to be shut down.
func geth(ctx *cli.Context) error {
node, e := MakeSystemNode(Version, ctx)
dateth := startNode(ctx, node)

eapi := eth.NewPublicEthereumAPI(dateth)
eapi.
// Force RPC enabling if --log-pace is set.
if ctx.GlobalIsSet(LogPaceFlag.Name) && !ctx.GlobalBool(aliasableName(RPCEnabledFlag.Name, ctx)) {
ctx.Set(aliasableName(RPCEnabledFlag.Name, ctx), "true")
}

n := MakeSystemNode(Version, ctx)
ethe := startNode(ctx, n)

if ctx.GlobalIsSet(LogPaceFlag.Name) {
go startPacedLogging(ctx, n, ethe)
}


//blockchain := nodeEth.BlockChain()
//
//client.Send()



//by := []byte{}
//b := bytes.NewBuffer(by)
Expand Down Expand Up @@ -304,12 +318,199 @@ func geth(ctx *cli.Context) error {
// }
// }
//}()
node.Wait()

n.Wait()

return nil
}

func startPacedLogging(ctx *cli.Context, n *node.Node, e *eth.Ethereum) {

intervalI := 60

if v := ctx.GlobalString(aliasableName(LogPaceFlag.Name, ctx)); v != "" {
u := string(v[len(v)-1]) // m, s
if !(u == "m" || u == "s") {
glog.V(logger.Error).Infof("unknown unit suffix: %s; use 'm' (minutes) or 's' (seconds)", u)
return
}
vv := string(v[:(len(v) - 1)])
i, e := strconv.Atoi(vv)
if e != nil {
glog.V(logger.Error).Infof("could not parse %v argument: %v, :%v", aliasableName(LogPaceFlag.Name, ctx), v, e)
return
}
if u == "m" {
i = i * 60
}
intervalI = i
}
glog.V(logger.Error).Infof("Log-pace [STATUS] interval set: %d seconds", intervalI)

// Need:
//2017-02-03 16:49:00 Sync #3124227 of #3124363 c76c…34e7 77/ 242/ 7 blk/tx/mgas sec 1/ 4/25 peers
//2017-02-03 16:50:00 Sync #3124247 of #3124363 75e4…8eff 51/ 51/ 5 blk/tx/mgas sec 1/ 4/25 peers
//2017-02-03 16:51:00 Sync #3124567 of #3124363 9af3…34ae 117/ 129/11 blk/tx/mgas sec 2/ 5/25 peers
//2017-02-03 16:52:00 Sync #3124787 of #3124363 1e3a…8351 9/ 6/ 1 blk/tx/mgas sec 1/ 7/25 peers
//2017-02-03 16:52:05 Import #3124788 84e1…1ff4 15/ 7 tx/mgas 3/10/25 peers
//2017-02-03 16:52:25 Import #3124789 9e45…a241 5/ 1 tx/mgas 5/12/25 peers
//2017-02-03 16:52:45 Import #3124790 d819…f71c 0/ 0 tx/mgas 11/18/25 peers
//
// - Sync type (Fast/Sync/Import)
// | downloader....
// - #3124787 of #3124363 - block X of total height Y
// - c76c…34e7 block hash
// - 77/ 242/ 7 blk/tx/mgas sec performance for past minute, avg blocks/transactions/mgas processed per second. 3 character for block, 4 for transactions, 2 for mgas
// -- blocks processed per second
// -- txs processed per second
// -- mgas processed per second
// - 1/ 4/25 peers download from 1 peer, connected to 4, of max 25. 2 characters for each part

// TODO: check and possibly modify existing verbsosity so pace is not interrupted... or?

//client, err := n.Attach()
//if err != nil {
// glog.Fatalln(err)
//}
tickerInterval := time.Second * time.Duration(int32(intervalI))
ticker := time.NewTicker(tickerInterval)

var lastLoggedBlockNumber uint64

for {
select {
case <-ticker.C:
peers := e.Downloader().GetPeers()
lenpeers := peers.Len()
//_, lennodedataidlepeers := peers.NodeDataIdlePeers()
_, lenblockidlepeers := peers.BlockIdlePeers()
_, lenbodyidlepeers := peers.BodyIdlePeers()
_, lenheaderidlepeers := peers.HeaderIdlePeers()
_, lenreceiptidlepeers := peers.ReceiptIdlePeers()
peers.AllPeers()

// An ugly, rough way to estimate actively connected/downloading-from peers
activepeers := 0
if lenblockidlepeers < lenpeers {
activepeers += lenblockidlepeers
}
if lenbodyidlepeers < lenpeers {
activepeers += lenbodyidlepeers
}
if lenheaderidlepeers < lenpeers {
activepeers += lenheaderidlepeers
}
if lenreceiptidlepeers < lenpeers {
activepeers += lenreceiptidlepeers
}

maxpeers := ctx.GlobalInt(aliasableName(MaxPeersFlag.Name, ctx))


//origin, current, height, pulled, known := e.Downloader().Progress()
_, current, height, _, _ := e.Downloader().Progress()
mode := e.Downloader().GetMode()

fmode := ""
ofheight := fmt.Sprintf(" of #%7d", height)
heightratio := float64(current) / float64(height)
heightratio = heightratio * 100
percentheight := fmt.Sprintf("(%4.2f", heightratio)
percentheight += "%)"
switch mode {
case downloader.FullSync:
fmode = "FullSync"
case downloader.FastSync:
fmode = "FastSync"
}
if current == height && !(current == 0 && height == 0) {
fmode = "Import"
ofheight = strings.Repeat(" ", 12)
percentheight = strings.Repeat(" ", 8)
}
if height == 0 {
ofheight = strings.Repeat(" ", 12)
percentheight = strings.Repeat(" ", 8)
}

//t := time.Now()
//y, m, d := t.Date()
//hour := t.Hour()
//minute := t.Minute()
//second := t.Second()

blockchain := e.BlockChain()
//td, currentblock, genesisblock := blockchain.Status()
_, currentblock, _:= blockchain.Status()

numBlocksDiff := current - lastLoggedBlockNumber
numTxsDiff := 0
mGas := new(big.Int)

var numBlocksDiffPerSecond uint64
var numTxsDiffPerSecond int
var mGasPerSecond = new(big.Int)

if numBlocksDiff > 0 && numBlocksDiff != current {
for i := lastLoggedBlockNumber; i <= current; i++ {
b := blockchain.GetBlockByNumber(i)
if b != nil {
numTxsDiff += b.Transactions().Len()
mGas = new(big.Int).Add(mGas, b.GasUsed())
}
}
}

// Convert to per-second stats
// FIXME(?): Some degree of rounding will happen.
// For example, if interval is 10s and we get 6 blocks imported in that span,
// stats will show '0' blocks/second. Looks a little strange; but on the other hand,
// precision costs visual space, and mostly just looks weird on when starting up sync or
// syncing slowly.
numBlocksDiffPerSecond = numBlocksDiff / uint64(intervalI)
// Don't show initial current / per second val
if lastLoggedBlockNumber == 0 {
numBlocksDiffPerSecond = 0
}
numTxsDiffPerSecond = numTxsDiff / intervalI
mGasPerSecond = new(big.Int).Div(mGas, big.NewInt(int64(intervalI)))
mGasPerSecond = new(big.Int).Div(mGasPerSecond, big.NewInt(1000000))
mGasPerSecondI := mGasPerSecond.Int64()

// Update last logged current block number
lastLoggedBlockNumber = current

// TODO: possibly convert mGas to better unit

cbhex := currentblock.Hex()
cbhexstart := cbhex[2:5] // trim off '0x' prefix
cbhexend := cbhex[(len(cbhex) - 3):]

//datetime := fmt.Sprintf("%4d-%2d-%2d %2d:%2d:%2d", y, m, d, hour, minute, second)
blockprogress := fmt.Sprintf("#%7d%s", current, ofheight)
cbhexdisplay := fmt.Sprintf("%s…%s", cbhexstart, cbhexend)
peersdisplay := fmt.Sprintf("%2d/%2d/%2d peers", activepeers, lenpeers, maxpeers)
blocksprocesseddisplay := fmt.Sprintf("%3d/%4d/%2d blks/txs/mgas sec", numBlocksDiffPerSecond, numTxsDiffPerSecond, mGasPerSecondI)

glog.V(logger.Error).Infof("STATUS %s %s %s %s %s %s", fmode, blockprogress, percentheight, cbhexdisplay, blocksprocesseddisplay, peersdisplay)
//glog.V(logger.Error).Infof("STATUS %s %s %s %s", fmode, blockprogress, cbhexdisplay, peersdisplay)
case <-sigc:
ticker.Stop()
return
}
}

//miner := e.Miner()
//mining := miner.Mining()
//hashrate := miner.HashRate()

//n.Attach()

//sub := e.EventMux().Subscribe()
//e := sub.Chan()

}

func status(ctx *cli.Context) error {

shouldUseExisting := false
Expand Down
1 change: 0 additions & 1 deletion eth/handler.go
View file
Expand Up @@ -38,7 +38,6 @@ import (
"github.com/ethereumproject/go-ethereum/p2p/discover"
"github.com/ethereumproject/go-ethereum/pow"
"github.com/ethereumproject/go-ethereum/rlp"
"github.com/ethereumproject/go-ethereum/metrics"
)

const (
Expand Down

0 comments on commit 2bc9de4

Please sign in to comment.