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