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

cmd,core,eth,logger: prettify logging #419

Closed
wants to merge 20 commits into from
Closed

Conversation

whilei
Copy link
Contributor

@whilei whilei commented Nov 27, 2017

problem

Normal logging is kind of "noisy," as @splix complains in #410. With that in mind, making logs "pretty" also removes important debugging information.

solution

Makes pretty logs when a single flag --pretty is used. The reason I used opt-in prettiness in 199652e is because I believe geth should use defaults that are most useful for developers. While indeed it's important for beginners and laymen to have access to an approachable interface, I t hink we'd be shooting ourselves in the foot (it's hard enough getting issue contributors to include any logs) and moving away from a "technology first" principle by establishing a default prioritizing the 💄 before the 🔧 .

With that said, there's very little I love more than a good interface. There's still a long way to go IMO with formatting the STATUS logs, adding possible other STATUS logs besides SYNC, and improving the design of the non-textual visual interface (eg. domino effect); but this is a start.

screen shot 2017-11-27 at 13 07 39

note here that I'm overriding --log-status interval manually; the default for --pretty is sync=15 [seconds]

solve specs

  • only verbosity=error lines are shown
  • geth still logs normal configuration stuff on startup
  • file traces will be excluded unless debug.verbosity(5) is used to set verbosity on the fly (like if user is experiencing some weirdness or just wants a closer look for whatever reason) OR if debug.verbosityTraceFloor(1) is used to set the minimum global verbosity threshold determining if file traces should be included
  • status logs will be dispatched every 15 seconds, including a new block progress display I call the domino effect 🃏

All of these defaults can be overridden manually with their respective flags.

Further, in case of severity=error or severity=fatal, the calling file trace will always be shown.

As explained in geth help:

  --pretty							Use pretty defaults for logging (verbosity=1,vmodule='cmd/geth/*=3',verbosity-trace-floor=5,log-status='sync=15')

how it works

As-is, there are two "dimensions" of logging: verbosity and severity.

  • Verbosity means "how much to say." It scales the granularity and detail of reporting.
  • Severity means "how to say it." It scales the importance, relative to verbosity.
  • TODO: explain this more

The domino effect uses the number of dominos to represent the number of blocks imported since last log, and the domino dot-number to represent number of transactions per block (eg 🁣 = 0 txs, 🂓 = 12+ txs). Representing blocks imported and txs are currently simply 1:1 with actual blocks/txs, but eventually should be scaled dynamically (with a log function... get it?) based on maximums and the limits of reasonable display units, eg. show no more than 20 dominoes, and if tx count increases a lot lately, use domino 3-dots to represent 9 txs or whatever

changes

  • Implement flag --verbosity-trace-floor and JSON-API:debug.verbosityTraceFloor to set the minimum global verbosity level at which to include file name traces in log line headers, eg.
I1127 13:10:19.130503  imported 1 block(s) (0 queued 0 ignored) including 89 txs in 118.756888ms. #4912033 [024edb99 / 024edb99]

vs.

I1127 13:09:59.359355 core/blockchain.go:1514] imported 1 block(s) (0 queued 0 ignored) including 2 txs in 8.742389ms. #4912032 [66839ff4 / 66839ff4]
  • Enable glog.formatHeader to use verbosity and severity thresholds for including file traces in the headers
  • Implement flag --pretty to toggle pretty default log settings, all of which can be overridden manually with their own flags.
  • Implement missing glog.Verbosity#Warn[|ln|f] and glog.Verbosity#Error[|ln|f] methods for using severity with verbosity in logging.
  • Establish default of >= severity.error for including file traces. Important for debugging and reporting bugs.

  • update tests

@whilei whilei requested review from splix and tzdybal November 27, 2017 14:22
@whilei
Copy link
Contributor Author

whilei commented Nov 28, 2017

The reason I used opt-in prettiness in 199652e is because I believe geth should use defaults that are most useful for developers.

This is an arguable point. I might be dead wrong. In which case we could just use --:neckbeard: instead.

@whilei
Copy link
Contributor Author

whilei commented Dec 3, 2017

Closing. Have taken lessons learned here and expanded on them in forthcoming PR from (a very messy) https://github.com/whilei/go-ethereum/tree/feat/log-display-separation

@whilei whilei closed this Dec 3, 2017
@whilei whilei deleted the feat/prettify-logging branch February 19, 2018 13:32
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.

1 participant