1// Copyright (c) 2017 The btcsuite developers 2// Use of this source code is governed by an ISC 3// license that can be found in the LICENSE file. 4// 5// Copyright (c) 2009 The Go Authors. All rights reserved. 6// 7// Redistribution and use in source and binary forms, with or without 8// modification, are permitted provided that the following conditions are 9// met: 10// 11// * Redistributions of source code must retain the above copyright 12// notice, this list of conditions and the following disclaimer. 13// * Redistributions in binary form must reproduce the above 14// copyright notice, this list of conditions and the following disclaimer 15// in the documentation and/or other materials provided with the 16// distribution. 17// * Neither the name of Google Inc. nor the names of its 18// contributors may be used to endorse or promote products derived from 19// this software without specific prior written permission. 20// 21// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS 22// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 23// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR 24// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT 25// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, 26// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT 27// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, 28// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY 29// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT 30// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE 31// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. 32 33package btclog 34 35import ( 36 "bytes" 37 "fmt" 38 "io" 39 "io/ioutil" 40 "os" 41 "runtime" 42 "strings" 43 "sync" 44 "sync/atomic" 45 "time" 46) 47 48// defaultFlags specifies changes to the default logger behavior. It is set 49// during package init and configured using the LOGFLAGS environment variable. 50// New logger backends can override these default flags using WithFlags. 51var defaultFlags uint32 52 53// Flags to modify Backend's behavior. 54const ( 55 // Llongfile modifies the logger output to include full path and line number 56 // of the logging callsite, e.g. /a/b/c/main.go:123. 57 Llongfile uint32 = 1 << iota 58 59 // Lshortfile modifies the logger output to include filename and line number 60 // of the logging callsite, e.g. main.go:123. Overrides Llongfile. 61 Lshortfile 62) 63 64// Read logger flags from the LOGFLAGS environment variable. Multiple flags can 65// be set at once, separated by commas. 66func init() { 67 for _, f := range strings.Split(os.Getenv("LOGFLAGS"), ",") { 68 switch f { 69 case "longfile": 70 defaultFlags |= Llongfile 71 case "shortfile": 72 defaultFlags |= Lshortfile 73 } 74 } 75} 76 77// Level is the level at which a logger is configured. All messages sent 78// to a level which is below the current level are filtered. 79type Level uint32 80 81// Level constants. 82const ( 83 LevelTrace Level = iota 84 LevelDebug 85 LevelInfo 86 LevelWarn 87 LevelError 88 LevelCritical 89 LevelOff 90) 91 92// levelStrs defines the human-readable names for each logging level. 93var levelStrs = [...]string{"TRC", "DBG", "INF", "WRN", "ERR", "CRT", "OFF"} 94 95// LevelFromString returns a level based on the input string s. If the input 96// can't be interpreted as a valid log level, the info level and false is 97// returned. 98func LevelFromString(s string) (l Level, ok bool) { 99 switch strings.ToLower(s) { 100 case "trace", "trc": 101 return LevelTrace, true 102 case "debug", "dbg": 103 return LevelDebug, true 104 case "info", "inf": 105 return LevelInfo, true 106 case "warn", "wrn": 107 return LevelWarn, true 108 case "error", "err": 109 return LevelError, true 110 case "critical", "crt": 111 return LevelCritical, true 112 case "off": 113 return LevelOff, true 114 default: 115 return LevelInfo, false 116 } 117} 118 119// String returns the tag of the logger used in log messages, or "OFF" if 120// the level will not produce any log output. 121func (l Level) String() string { 122 if l >= LevelOff { 123 return "OFF" 124 } 125 return levelStrs[l] 126} 127 128// NewBackend creates a logger backend from a Writer. 129func NewBackend(w io.Writer, opts ...BackendOption) *Backend { 130 b := &Backend{w: w, flag: defaultFlags} 131 for _, o := range opts { 132 o(b) 133 } 134 return b 135} 136 137// Backend is a logging backend. Subsystems created from the backend write to 138// the backend's Writer. Backend provides atomic writes to the Writer from all 139// subsystems. 140type Backend struct { 141 w io.Writer 142 mu sync.Mutex // ensures atomic writes 143 flag uint32 144} 145 146// BackendOption is a function used to modify the behavior of a Backend. 147type BackendOption func(b *Backend) 148 149// WithFlags configures a Backend to use the specified flags rather than using 150// the package's defaults as determined through the LOGFLAGS environment 151// variable. 152func WithFlags(flags uint32) BackendOption { 153 return func(b *Backend) { 154 b.flag = flags 155 } 156} 157 158// bufferPool defines a concurrent safe free list of byte slices used to provide 159// temporary buffers for formatting log messages prior to outputting them. 160var bufferPool = sync.Pool{ 161 New: func() interface{} { 162 b := make([]byte, 0, 120) 163 return &b // pointer to slice to avoid boxing alloc 164 }, 165} 166 167// buffer returns a byte slice from the free list. A new buffer is allocated if 168// there are not any available on the free list. The returned byte slice should 169// be returned to the fee list by using the recycleBuffer function when the 170// caller is done with it. 171func buffer() *[]byte { 172 return bufferPool.Get().(*[]byte) 173} 174 175// recycleBuffer puts the provided byte slice, which should have been obtain via 176// the buffer function, back on the free list. 177func recycleBuffer(b *[]byte) { 178 *b = (*b)[:0] 179 bufferPool.Put(b) 180} 181 182// From stdlib log package. 183// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid 184// zero-padding. 185func itoa(buf *[]byte, i int, wid int) { 186 // Assemble decimal in reverse order. 187 var b [20]byte 188 bp := len(b) - 1 189 for i >= 10 || wid > 1 { 190 wid-- 191 q := i / 10 192 b[bp] = byte('0' + i - q*10) 193 bp-- 194 i = q 195 } 196 // i < 10 197 b[bp] = byte('0' + i) 198 *buf = append(*buf, b[bp:]...) 199} 200 201// Appends a header in the default format 'YYYY-MM-DD hh:mm:ss.sss [LVL] TAG: '. 202// If either of the Lshortfile or Llongfile flags are specified, the file named 203// and line number are included after the tag and before the final colon. 204func formatHeader(buf *[]byte, t time.Time, lvl, tag string, file string, line int) { 205 year, month, day := t.Date() 206 hour, min, sec := t.Clock() 207 ms := t.Nanosecond() / 1e6 208 209 itoa(buf, year, 4) 210 *buf = append(*buf, '-') 211 itoa(buf, int(month), 2) 212 *buf = append(*buf, '-') 213 itoa(buf, day, 2) 214 *buf = append(*buf, ' ') 215 itoa(buf, hour, 2) 216 *buf = append(*buf, ':') 217 itoa(buf, min, 2) 218 *buf = append(*buf, ':') 219 itoa(buf, sec, 2) 220 *buf = append(*buf, '.') 221 itoa(buf, ms, 3) 222 *buf = append(*buf, " ["...) 223 *buf = append(*buf, lvl...) 224 *buf = append(*buf, "] "...) 225 *buf = append(*buf, tag...) 226 if file != "" { 227 *buf = append(*buf, ' ') 228 *buf = append(*buf, file...) 229 *buf = append(*buf, ':') 230 itoa(buf, line, -1) 231 } 232 *buf = append(*buf, ": "...) 233} 234 235// calldepth is the call depth of the callsite function relative to the 236// caller of the subsystem logger. It is used to recover the filename and line 237// number of the logging call if either the short or long file flags are 238// specified. 239const calldepth = 3 240 241// callsite returns the file name and line number of the callsite to the 242// subsystem logger. 243func callsite(flag uint32) (string, int) { 244 _, file, line, ok := runtime.Caller(calldepth) 245 if !ok { 246 return "???", 0 247 } 248 if flag&Lshortfile != 0 { 249 short := file 250 for i := len(file) - 1; i > 0; i-- { 251 if os.IsPathSeparator(file[i]) { 252 short = file[i+1:] 253 break 254 } 255 } 256 file = short 257 } 258 return file, line 259} 260 261// print outputs a log message to the writer associated with the backend after 262// creating a prefix for the given level and tag according to the formatHeader 263// function and formatting the provided arguments using the default formatting 264// rules. 265func (b *Backend) print(lvl, tag string, args ...interface{}) { 266 t := time.Now() // get as early as possible 267 268 bytebuf := buffer() 269 270 var file string 271 var line int 272 if b.flag&(Lshortfile|Llongfile) != 0 { 273 file, line = callsite(b.flag) 274 } 275 276 formatHeader(bytebuf, t, lvl, tag, file, line) 277 buf := bytes.NewBuffer(*bytebuf) 278 fmt.Fprintln(buf, args...) 279 *bytebuf = buf.Bytes() 280 281 b.mu.Lock() 282 b.w.Write(*bytebuf) 283 b.mu.Unlock() 284 285 recycleBuffer(bytebuf) 286} 287 288// printf outputs a log message to the writer associated with the backend after 289// creating a prefix for the given level and tag according to the formatHeader 290// function and formatting the provided arguments according to the given format 291// specifier. 292func (b *Backend) printf(lvl, tag string, format string, args ...interface{}) { 293 t := time.Now() // get as early as possible 294 295 bytebuf := buffer() 296 297 var file string 298 var line int 299 if b.flag&(Lshortfile|Llongfile) != 0 { 300 file, line = callsite(b.flag) 301 } 302 303 formatHeader(bytebuf, t, lvl, tag, file, line) 304 buf := bytes.NewBuffer(*bytebuf) 305 fmt.Fprintf(buf, format, args...) 306 *bytebuf = append(buf.Bytes(), '\n') 307 308 b.mu.Lock() 309 b.w.Write(*bytebuf) 310 b.mu.Unlock() 311 312 recycleBuffer(bytebuf) 313} 314 315// Logger returns a new logger for a particular subsystem that writes to the 316// Backend b. A tag describes the subsystem and is included in all log 317// messages. The logger uses the info verbosity level by default. 318func (b *Backend) Logger(subsystemTag string) Logger { 319 return &slog{LevelInfo, subsystemTag, b} 320} 321 322// slog is a subsystem logger for a Backend. Implements the Logger interface. 323type slog struct { 324 lvl Level // atomic 325 tag string 326 b *Backend 327} 328 329// Trace formats message using the default formats for its operands, prepends 330// the prefix as necessary, and writes to log with LevelTrace. 331// 332// This is part of the Logger interface implementation. 333func (l *slog) Trace(args ...interface{}) { 334 lvl := l.Level() 335 if lvl <= LevelTrace { 336 l.b.print("TRC", l.tag, args...) 337 } 338} 339 340// Tracef formats message according to format specifier, prepends the prefix as 341// necessary, and writes to log with LevelTrace. 342// 343// This is part of the Logger interface implementation. 344func (l *slog) Tracef(format string, args ...interface{}) { 345 lvl := l.Level() 346 if lvl <= LevelTrace { 347 l.b.printf("TRC", l.tag, format, args...) 348 } 349} 350 351// Debug formats message using the default formats for its operands, prepends 352// the prefix as necessary, and writes to log with LevelDebug. 353// 354// This is part of the Logger interface implementation. 355func (l *slog) Debug(args ...interface{}) { 356 lvl := l.Level() 357 if lvl <= LevelDebug { 358 l.b.print("DBG", l.tag, args...) 359 } 360} 361 362// Debugf formats message according to format specifier, prepends the prefix as 363// necessary, and writes to log with LevelDebug. 364// 365// This is part of the Logger interface implementation. 366func (l *slog) Debugf(format string, args ...interface{}) { 367 lvl := l.Level() 368 if lvl <= LevelDebug { 369 l.b.printf("DBG", l.tag, format, args...) 370 } 371} 372 373// Info formats message using the default formats for its operands, prepends 374// the prefix as necessary, and writes to log with LevelInfo. 375// 376// This is part of the Logger interface implementation. 377func (l *slog) Info(args ...interface{}) { 378 lvl := l.Level() 379 if lvl <= LevelInfo { 380 l.b.print("INF", l.tag, args...) 381 } 382} 383 384// Infof formats message according to format specifier, prepends the prefix as 385// necessary, and writes to log with LevelInfo. 386// 387// This is part of the Logger interface implementation. 388func (l *slog) Infof(format string, args ...interface{}) { 389 lvl := l.Level() 390 if lvl <= LevelInfo { 391 l.b.printf("INF", l.tag, format, args...) 392 } 393} 394 395// Warn formats message using the default formats for its operands, prepends 396// the prefix as necessary, and writes to log with LevelWarn. 397// 398// This is part of the Logger interface implementation. 399func (l *slog) Warn(args ...interface{}) { 400 lvl := l.Level() 401 if lvl <= LevelWarn { 402 l.b.print("WRN", l.tag, args...) 403 } 404} 405 406// Warnf formats message according to format specifier, prepends the prefix as 407// necessary, and writes to log with LevelWarn. 408// 409// This is part of the Logger interface implementation. 410func (l *slog) Warnf(format string, args ...interface{}) { 411 lvl := l.Level() 412 if lvl <= LevelWarn { 413 l.b.printf("WRN", l.tag, format, args...) 414 } 415} 416 417// Error formats message using the default formats for its operands, prepends 418// the prefix as necessary, and writes to log with LevelError. 419// 420// This is part of the Logger interface implementation. 421func (l *slog) Error(args ...interface{}) { 422 lvl := l.Level() 423 if lvl <= LevelError { 424 l.b.print("ERR", l.tag, args...) 425 } 426} 427 428// Errorf formats message according to format specifier, prepends the prefix as 429// necessary, and writes to log with LevelError. 430// 431// This is part of the Logger interface implementation. 432func (l *slog) Errorf(format string, args ...interface{}) { 433 lvl := l.Level() 434 if lvl <= LevelError { 435 l.b.printf("ERR", l.tag, format, args...) 436 } 437} 438 439// Critical formats message using the default formats for its operands, prepends 440// the prefix as necessary, and writes to log with LevelCritical. 441// 442// This is part of the Logger interface implementation. 443func (l *slog) Critical(args ...interface{}) { 444 lvl := l.Level() 445 if lvl <= LevelCritical { 446 l.b.print("CRT", l.tag, args...) 447 } 448} 449 450// Criticalf formats message according to format specifier, prepends the prefix 451// as necessary, and writes to log with LevelCritical. 452// 453// This is part of the Logger interface implementation. 454func (l *slog) Criticalf(format string, args ...interface{}) { 455 lvl := l.Level() 456 if lvl <= LevelCritical { 457 l.b.printf("CRT", l.tag, format, args...) 458 } 459} 460 461// Level returns the current logging level 462// 463// This is part of the Logger interface implementation. 464func (l *slog) Level() Level { 465 return Level(atomic.LoadUint32((*uint32)(&l.lvl))) 466} 467 468// SetLevel changes the logging level to the passed level. 469// 470// This is part of the Logger interface implementation. 471func (l *slog) SetLevel(level Level) { 472 atomic.StoreUint32((*uint32)(&l.lvl), uint32(level)) 473} 474 475// Disabled is a Logger that will never output anything. 476var Disabled Logger 477 478func init() { 479 Disabled = &slog{lvl: LevelOff, b: NewBackend(ioutil.Discard)} 480} 481