Skip to content
This repository has been archived by the owner on Oct 4, 2019. It is now read-only.

cmd/geth: implement interval-based status logging #324

Merged
merged 21 commits into from Aug 16, 2017

Conversation

whilei
Copy link
Contributor

@whilei whilei commented Jul 27, 2017

Rel #127, #318

Currently looks like this:

I0728 08:49:11.749102 cmd/geth/main.go:402] STATUS SYNC FastSync # 298028 of #4176953 (7.14%) ed3…012  406/ 779/16 blks/txs/mgas sec  9/25 peers
I0728 08:49:13.580677 cmd/geth/main.go:402] STATUS SYNC FastSync # 298028 of #4176953 (7.14%) 60f…2fb    0/   0/ 0 blks/txs/mgas sec  8/25 peers
I0728 08:49:16.420559 cmd/geth/main.go:402] STATUS SYNC FastSync # 300076 of #4176953 (7.18%) 169…dfc 1024/1278/47 blks/txs/mgas sec 11/25 peers
I0728 08:49:18.067878 cmd/geth/main.go:402] STATUS SYNC FastSync # 300076 of #4176953 (7.18%) 274…ee1    0/   0/ 0 blks/txs/mgas sec  9/25 peers
I0728 08:49:20.339668 cmd/geth/main.go:402] STATUS SYNC FastSync # 302142 of #4176953 (7.23%) d11…3ea 1033/1312/29 blks/txs/mgas sec  8/25 peers
I0728 08:49:21.913738 cmd/geth/main.go:402] STATUS SYNC FastSync # 304190 of #4176953 (7.28%) 06e…de0 1024/1052/37 blks/txs/mgas sec  9/25 peers
I0728 08:49:23.814678 cmd/geth/main.go:402] STATUS SYNC FastSync # 304190 of #4176953 (7.28%) 556…c1c    0/   0/ 0 blks/txs/mgas sec 12/25 peers
I0728 08:49:26.228164 cmd/geth/main.go:402] STATUS SYNC FastSync # 307456 of #4176953 (7.36%) 57c…878 1633/2195/55 blks/txs/mgas sec 11/25 peers
I0728 08:49:27.777262 cmd/geth/main.go:402] STATUS SYNC FastSync # 308324 of #4176953 (7.38%) 1b2…aae  434/ 420/16 blks/txs/mgas sec  9/25 peers
I0728 08:49:29.636223 cmd/geth/main.go:402] STATUS SYNC FastSync # 308324 of #4176953 (7.38%) 3eb…8ef    0/   0/ 0 blks/txs/mgas sec  8/25 peers

So far, I've made the optional interval-based logging use Error (level=1) tier of logging priority, which enables a user-specified graduated combination of event-based and interval-based logging (since Error is "highest" priority tier), eg.

# I want STATUS SYNC logs every 10 seconds and event-based ERROR logs (which are very few, hopefully!)
$ geth --verbosity=1 --log-status="sync=10"

# I want STATUS SYNC logs every 10 seconds and to debug something in core/
$ geth --verbosity=1 --log-status="sync=10" --vmodule="core=5"

# I want STATUS SYNC logs every 10 seconds and standard (INFO) event-based logging
$ get --verbosity=3 --log-status="sync=10"

TODO:

  • Are we happy with --log-pace name? Alternative ideas might be --log-status, --vstatus, ...
    • -> Chose --log-status
  • Thinking along the lines of forward compatibility: possibly using --log-status="sync=60,disk=120,net=30,mine=10", where current PR deals only with sync=<interval> functionality, but in the future we might want interval-based status logs for additional information, like disk I/O rates, network latency, and mining progress. This proposed flag argument syntax echoes existing --vmodule="eth=2,core*=5", but uses integer values for interval rates instead of verbosity levels
    • -> Implemented: --log-status="sync=60", with extensibility then for comma-separated input <feature>=<interval>, eg. --log-status="sync=60,mine=15,net=120"

whilei added 17 commits July 27, 2017 17:52
may be worth thinking about more flexible and beautiful
ways to display information... 'monitor', 'attach', etc,
along with termui, graphs...

output can be 'machiney'-- line-by-line,
or human-y -- pictures of buffalo and whatnot.
solution: use a go func connected to the node's Ethereum to grab and calculate relevant logs

rel ethereumproject#127
rel ethereumproject#318

---

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'
solution: comment code and include small explanation
solution: remove exploratory code that is not useless
solution: move to Warn from Error
solution: update it and simplify
solution:
- remove dead code, old notes
- remove units from --log-pace= argument, just use seconds as value (simpler is better)
- if mining, show STATUS MINE with minerthreads and hashrate (TODO: more?)
- gofmt

Rel ethereumproject#127, ethereumproject#318
solution: share chan in main between shutdown and closing status log goroutine
solution: implement and glog SetAlsoToStdErr exported function and use in case of --log-dir
results in missing any logs after shutdown processes in FS logs

solution: defer log Flush after shutdown services

also decrease flushInterval from 30 -> 5 seconds (rate at which log buffer is written to FS)
solution: rename flag and flagvar and status log function

also adds logstatus flag to correct category for usage output
solution: refactor to use '--log-status='sync=60'' syntax, which can eventually support other features besides 'sync',
eg. mine, net, disk
…to cmd.go

solution: cut and paste and update imports
@whilei whilei changed the title [WIP]: cmd/geth: implement interval-based status logging cmd/geth: implement interval-based status logging Jul 30, 2017
@whilei whilei requested review from splix, sorpaas and r8d8 July 30, 2017 21:48
solution: error if neither fastblock nor fullblock match desired head number

fixes ethereumproject#325
solution: don't share os-interrupt channel as a global.
Notify library documentation clearly says Notify events can be called
multiple times and notification will be copied, so there's no harm in
listening for the same event on mutliple channels.

This pattern avoids a global and encourages per-feature handling of
shutdown scenarios.
@whilei whilei merged commit a8a0b79 into ethereumproject:master Aug 16, 2017
@whilei whilei mentioned this pull request Sep 11, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants