Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log polish #27

Merged
merged 4 commits into from
Aug 26, 2018
Merged

Log polish #27

merged 4 commits into from
Aug 26, 2018

Conversation

arnetheduck
Copy link
Member

  • use textlines by default
  • fixed-width level, time and message makes for nice columns
  • colorize keys according to log level
  • remove brackets around stuff (already conveyed by columns)
  • quote values with spaces in them (like logfmt, allows parsing k/v
    easily
INFO 2018-08-24 11:33:06 long info                                  thread=0 str="some multiline\nstring\nmore lines"
WARN 2018-08-24 11:33:06 long warning                               thread=0 str="some multiline\nstring\nmore lines"
INFO 2018-08-24 11:33:06 long info
  thread: 0
  str: some multiline
       string
       more lines
       
WARN 2018-08-24 11:33:06 long warning
  thread: 0
  str: some multiline
       string
       more lines
       

during discussion, several advantages were noted:
* easy to grep
* easy to integrate with text processing other tools (log collectors
etc)
* better use of screen space
* fixed-width level, time and message makes for nice columns
* colorize keys according to log level
* remove brackets around stuff (already conveyed by columns)
* quote values with spaces in them (like logfmt, allows parsing k/v
easily
@zah
Copy link
Contributor

zah commented Aug 25, 2018

A nitpick. Both 5-letter and 3-letter log levels seem nicer to me than 4-letters:

TRACE
DEBUG
INFO 
NOTIC
WARN 
ERROR
FATAL

TRC
DBG
INF
NOT
WRN
ERR
FTL

TRAC
DEBU
NOTI
WARN
ERRO
FATA

of NONE: (fgWhite, false)

template appendLogLevelMarker(r: var auto, lvl: LogLevel, align: bool) =
let (color, bright) = levelToStyle(lvl)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can still have when r.colors != NoColors: here.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

can, but repeats color check from fgColor etc - not better to keep all in one place?

# no good way to tell how much padding is going to be needed so we
# choose an arbitrary number and use that - should be fine even for
# 80-char terminals
let padding = static(repeat(' ', if pad: 42 - min(42, name.len) else: 0))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this should be const

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

likewise, compile error


template appendLogLevelMarker(r: var auto, lvl: LogLevel, align: bool) =
let (color, bright) = levelToStyle(lvl)
let lvlString =
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be const.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

no luck:

/home/arnetheduck/status/nim-chronicles/chronicles/log_output.nim(309, 9) Error: internal error: transformConstSection


fgColor(r, propColor, false)
let (color, bright) = levelToStyle(r.level)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can add when r.colors != NoColors: above this line.

# default is textlines - single-line format is good for interop with
# text processing tools like grep and logstash, good use of screen
# real estate
else: parseSinksSpec "textlines"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since the team decided on this change, that's OK, but I'll voice few more arguments for the former textblocks choice:

  • The argument that log systems are already optimized to deal with one record per-line is not that strong IMO, because most systems already had to deal with stack traces appearing in the logs and I think a lot of specialized software has adopted the rule that indented blocks are considered part of the log line before them.

  • The gripability argument is not that strong either, because most people don't know about the -A and -B options of grep, which solves the problem to a reasonable extent. I have quite a lot of experience in grepping the indented human-readable output of https://github.com/trentm/node-bunyan (one of the most popular and established json loggers).

  • The dense log produced by textlines doesn't come without downsides too:

    • Long lines will be wrapped making them harder to read. This creates a psychological effect where the developer is incentivized to log less information in order to keep the log readable.
    • Visually scanning a log line to find a particular property value will be objectively slower.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

documented these arguments as well.

I think a lot of specialized software has adopted the rule that indented blocks are considered part of the log line before them
this is an interesting point - examples of such systems? potentially, these might come from the python world where indents are the norm. I checked logstash - it has a special plugin that can deal with this by specifying a regex to match: https://www.elastic.co/guide/en/logstash/current/multiline.html - however, this is not part of the "default" config and requires extra setup

gripability argument
two things of note:

  • -A xx -B xx - there's no way to choose good numbers here because log lines have different numbers of params and you don't know which one you're grepping for - also, like you say, these arguments are less well known, so the out-of-the-box experience is worse
  • it's also easier to regex-match a single line - you can do INF.*message here.*ip=XXX to get a quick and filter.. the same holds true for IDE/editor searches etc

@arnetheduck
Copy link
Member Author

updated to:

INF 2018-08-25 12:42:54 long info                                  thread=0 str="some multiline\nstring\nmore lines"
WRN 2018-08-25 12:42:54 long warning                               thread=0 str="some multiline\nstring\nmore lines"
INF 2018-08-25 12:42:54 long info
  thread: 0
  str: some multiline
       string
       more lines
       
WRN 2018-08-25 12:42:54 long warning
  thread: 0
  str: some multiline
       string
       more lines
       

@zah zah merged commit bb3da67 into master Aug 26, 2018
@arnetheduck arnetheduck deleted the log-polish branch December 22, 2018 02:51
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants