github.com/turingchain2020/turingchain@v1.1.21/common/log/log15/doc.go (about)

     1  // Copyright Turing Corp. 2018 All Rights Reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  /*
     6  Package log15 provides an opinionated, simple toolkit for best-practice logging that is
     7  both human and machine readable. It is modeled after the standard library's io and net/http
     8  packages.
     9  
    10  This package enforces you to only log key/value pairs. Keys must be strings. Values may be
    11  any type that you like. The default output format is logfmt, but you may also choose to use
    12  JSON instead if that suits you. Here's how you log:
    13  
    14      log.Info("page accessed", "path", r.URL.Path, "user_id", user.id)
    15  
    16  This will output a line that looks like:
    17  
    18       lvl=info t=2014-05-02T16:07:23-0700 msg="page accessed" path=/org/71/profile user_id=9
    19  
    20  Getting Started
    21  
    22  To get started, you'll want to import the library:
    23  
    24      import log "github.com/turingchain2020/turingchain/common/log/log15"
    25  
    26  
    27  Now you're ready to start logging:
    28  
    29      func main() {
    30          log.Info("Program starting", "args", os.Args())
    31      }
    32  
    33  
    34  Convention
    35  
    36  Because recording a human-meaningful message is common and good practice, the first argument to every
    37  logging method is the value to the *implicit* key 'msg'.
    38  
    39  Additionally, the level you choose for a message will be automatically added with the key 'lvl', and so
    40  will the current timestamp with key 't'.
    41  
    42  You may supply any additional context as a set of key/value pairs to the logging function. log15 allows
    43  you to favor terseness, ordering, and speed over safety. This is a reasonable tradeoff for
    44  logging functions. You don't need to explicitly state keys/values, log15 understands that they alternate
    45  in the variadic argument list:
    46  
    47      log.Warn("size out of bounds", "low", lowBound, "high", highBound, "val", val)
    48  
    49  If you really do favor your type-safety, you may choose to pass a log.Ctx instead:
    50  
    51      log.Warn("size out of bounds", log.Ctx{"low": lowBound, "high": highBound, "val": val})
    52  
    53  
    54  Context loggers
    55  
    56  Frequently, you want to add context to a logger so that you can track actions associated with it. An http
    57  request is a good example. You can easily create new loggers that have context that is automatically included
    58  with each log line:
    59  
    60      requestlogger := log.New("path", r.URL.Path)
    61  
    62      // later
    63      requestlogger.Debug("db txn commit", "duration", txnTimer.Finish())
    64  
    65  This will output a log line that includes the path context that is attached to the logger:
    66  
    67      lvl=dbug t=2014-05-02T16:07:23-0700 path=/repo/12/add_hook msg="db txn commit" duration=0.12
    68  
    69  
    70  Handlers
    71  
    72  The Handler interface defines where log lines are printed to and how they are formated. Handler is a
    73  single interface that is inspired by net/http's handler interface:
    74  
    75      type Handler interface {
    76          Log(r *Record) error
    77      }
    78  
    79  
    80  Handlers can filter records, format them, or dispatch to multiple other Handlers.
    81  This package implements a number of Handlers for common logging patterns that are
    82  easily composed to create flexible, custom logging structures.
    83  
    84  Here's an example handler that prints logfmt output to Stdout:
    85  
    86      handler := log.StreamHandler(os.Stdout, log.LogfmtFormat())
    87  
    88  Here's an example handler that defers to two other handlers. One handler only prints records
    89  from the rpc package in logfmt to standard out. The other prints records at Error level
    90  or above in JSON formatted output to the file /var/log/service.json
    91  
    92      handler := log.MultiHandler(
    93          log.LvlFilterHandler(log.LvlError, log.Must.FileHandler("/var/log/service.json", log.JSONFormat())),
    94          log.MatchFilterHandler("pkg", "app/rpc" log.StdoutHandler())
    95      )
    96  
    97  Logging File Names and Line Numbers
    98  
    99  This package implements three Handlers that add debugging information to the
   100  context, CallerFileHandler, CallerFuncHandler and CallerStackHandler. Here's
   101  an example that adds the source file and line number of each logging call to
   102  the context.
   103  
   104      h := log.CallerFileHandler(log.StdoutHandler)
   105      log.Root().SetHandler(h)
   106      ...
   107      log.Error("open file", "err", err)
   108  
   109  This will output a line that looks like:
   110  
   111      lvl=eror t=2014-05-02T16:07:23-0700 msg="open file" err="file not found" caller=data.go:42
   112  
   113  Here's an example that logs the call stack rather than just the call site.
   114  
   115      h := log.CallerStackHandler("%+v", log.StdoutHandler)
   116      log.Root().SetHandler(h)
   117      ...
   118      log.Error("open file", "err", err)
   119  
   120  This will output a line that looks like:
   121  
   122      lvl=eror t=2014-05-02T16:07:23-0700 msg="open file" err="file not found" stack="[pkg/data.go:42 pkg/cmd/main.go]"
   123  
   124  The "%+v" format instructs the handler to include the path of the source file
   125  relative to the compile time GOPATH. The github.com/go-stack/stack package
   126  documents the full list of formatting verbs and modifiers available.
   127  
   128  Custom Handlers
   129  
   130  The Handler interface is so simple that it's also trivial to write your own. Let's create an
   131  example handler which tries to write to one handler, but if that fails it falls back to
   132  writing to another handler and includes the error that it encountered when trying to write
   133  to the primary. This might be useful when trying to log over a network socket, but if that
   134  fails you want to log those records to a file on disk.
   135  
   136      type BackupHandler struct {
   137          Primary Handler
   138          Secondary Handler
   139      }
   140  
   141      func (h *BackupHandler) Log (r *Record) error {
   142          err := h.Primary.Log(r)
   143          if err != nil {
   144              r.Ctx = append(ctx, "primary_err", err)
   145              return h.Secondary.Log(r)
   146          }
   147          return nil
   148      }
   149  
   150  This pattern is so useful that a generic version that handles an arbitrary number of Handlers
   151  is included as part of this library called FailoverHandler.
   152  
   153  Logging Expensive Operations
   154  
   155  Sometimes, you want to log values that are extremely expensive to compute, but you don't want to pay
   156  the price of computing them if you haven't turned up your logging level to a high level of detail.
   157  
   158  This package provides a simple type to annotate a logging operation that you want to be evaluated
   159  lazily, just when it is about to be logged, so that it would not be evaluated if an upstream Handler
   160  filters it out. Just wrap any function which takes no arguments with the log.Lazy type. For example:
   161  
   162      func factorRSAKey() (factors []int) {
   163          // return the factors of a very large number
   164      }
   165  
   166      log.Debug("factors", log.Lazy{factorRSAKey})
   167  
   168  If this message is not logged for any reason (like logging at the Error level), then
   169  factorRSAKey is never evaluated.
   170  
   171  Dynamic context values
   172  
   173  The same log.Lazy mechanism can be used to attach context to a logger which you want to be
   174  evaluated when the message is logged, but not when the logger is created. For example, let's imagine
   175  a game where you have Player objects:
   176  
   177      type Player struct {
   178          name string
   179          alive bool
   180          log.Logger
   181      }
   182  
   183  You always want to log a player's name and whether they're alive or dead, so when you create the player
   184  object, you might do:
   185  
   186      p := &Player{name: name, alive: true}
   187      p.Logger = log.New("name", p.name, "alive", p.alive)
   188  
   189  Only now, even after a player has died, the logger will still report they are alive because the logging
   190  context is evaluated when the logger was created. By using the Lazy wrapper, we can defer the evaluation
   191  of whether the player is alive or not to each log message, so that the log records will reflect the player's
   192  current state no matter when the log message is written:
   193  
   194      p := &Player{name: name, alive: true}
   195      isAlive := func() bool { return p.alive }
   196      player.Logger = log.New("name", p.name, "alive", log.Lazy{isAlive})
   197  
   198  Terminal Format
   199  
   200  If log15 detects that stdout is a terminal, it will configure the default
   201  handler for it (which is log.StdoutHandler) to use TerminalFormat. This format
   202  logs records nicely for your terminal, including color-coded output based
   203  on log level.
   204  
   205  Error Handling
   206  
   207  Becasuse log15 allows you to step around the type system, there are a few ways you can specify
   208  invalid arguments to the logging functions. You could, for example, wrap something that is not
   209  a zero-argument function with log.Lazy or pass a context key that is not a string. Since logging libraries
   210  are typically the mechanism by which errors are reported, it would be onerous for the logging functions
   211  to return errors. Instead, log15 handles errors by making these guarantees to you:
   212  
   213  - Any log record containing an error will still be printed with the error explained to you as part of the log record.
   214  
   215  - Any log record containing an error will include the context key LOG15_ERROR, enabling you to easily
   216  (and if you like, automatically) detect if any of your logging calls are passing bad values.
   217  
   218  Understanding this, you might wonder why the Handler interface can return an error value in its Log method. Handlers
   219  are encouraged to return errors only if they fail to write their log records out to an external source like if the
   220  syslog daemon is not responding. This allows the construction of useful handlers which cope with those failures
   221  like the FailoverHandler.
   222  
   223  Library Use
   224  
   225  log15 is intended to be useful for library authors as a way to provide configurable logging to
   226  users of their library. Best practice for use in a library is to always disable all output for your logger
   227  by default and to provide a public Logger instance that consumers of your library can configure. Like so:
   228  
   229      package yourlib
   230  
   231      import "github.com/turingchain2020/turingchain/common/log/log15"
   232  
   233      var Log = log.New()
   234  
   235      func init() {
   236          Log.SetHandler(log.DiscardHandler())
   237      }
   238  
   239  Users of your library may then enable it if they like:
   240  
   241      import "github.com/turingchain2020/turingchain/common/log/log15"
   242      import "example.com/yourlib"
   243  
   244      func main() {
   245          handler := // custom handler setup
   246          yourlib.Log.SetHandler(handler)
   247      }
   248  
   249  Best practices attaching logger context
   250  
   251  The ability to attach context to a logger is a powerful one. Where should you do it and why?
   252  I favor embedding a Logger directly into any persistent object in my application and adding
   253  unique, tracing context keys to it. For instance, imagine I am writing a web browser:
   254  
   255      type Tab struct {
   256          url string
   257          render *RenderingContext
   258          // ...
   259  
   260          Logger
   261      }
   262  
   263      func NewTab(url string) *Tab {
   264          return &Tab {
   265              // ...
   266              url: url,
   267  
   268              Logger: log.New("url", url),
   269          }
   270      }
   271  
   272  When a new tab is created, I assign a logger to it with the url of
   273  the tab as context so it can easily be traced through the logs.
   274  Now, whenever we perform any operation with the tab, we'll log with its
   275  embedded logger and it will include the tab title automatically:
   276  
   277      tab.Debug("moved position", "idx", tab.idx)
   278  
   279  There's only one problem. What if the tab url changes? We could
   280  use log.Lazy to make sure the current url is always written, but that
   281  would mean that we couldn't trace a tab's full lifetime through our
   282  logs after the user navigate to a new URL.
   283  
   284  Instead, think about what values to attach to your loggers the
   285  same way you think about what to use as a key in a SQL database schema.
   286  If it's possible to use a natural key that is unique for the lifetime of the
   287  object, do so. But otherwise, log15's ext package has a handy RandId
   288  function to let you generate what you might call "surrogate keys"
   289  They're just random hex identifiers to use for tracing. Back to our
   290  Tab example, we would prefer to set up our Logger like so:
   291  
   292          import logext "github.com/turingchain2020/turingchain/common/log/log15/ext"
   293  
   294          t := &Tab {
   295              // ...
   296              url: url,
   297          }
   298  
   299          t.Logger = log.New("id", logext.RandId(8), "url", log.Lazy{t.getUrl})
   300          return t
   301  
   302  Now we'll have a unique traceable identifier even across loading new urls, but
   303  we'll still be able to see the tab's current url in the log messages.
   304  
   305  Must
   306  
   307  For all Handler functions which can return an error, there is a version of that
   308  function which will return no error but panics on failure. They are all available
   309  on the Must object. For example:
   310  
   311      log.Must.FileHandler("/path", log.JSONFormat)
   312      log.Must.NetHandler("tcp", ":1234", log.JSONFormat)
   313  
   314  Inspiration and Credit
   315  
   316  All of the following excellent projects inspired the design of this library:
   317  
   318  code.google.com/p/log4go
   319  
   320  github.com/op/go-logging
   321  
   322  github.com/technoweenie/grohl
   323  
   324  github.com/Sirupsen/logrus
   325  
   326  github.com/kr/logfmt
   327  
   328  github.com/spacemonkeygo/spacelog
   329  
   330  golang's stdlib, notably io and net/http
   331  
   332  The Name
   333  
   334  https://xkcd.com/927/
   335  
   336  */
   337  package log15