github.com/cellofellow/gopkg@v0.0.0-20140722061823-eec0544a62ad/glog/glog.go (about) 1 // Go support for leveled logs, analogous to https://code.google.com/p/google-glog/ 2 // 3 // Copyright 2013 Google Inc. All Rights Reserved. 4 // 5 // Licensed under the Apache License, Version 2.0 (the "License"); 6 // you may not use this file except in compliance with the License. 7 // You may obtain a copy of the License at 8 // 9 // http://www.apache.org/licenses/LICENSE-2.0 10 // 11 // Unless required by applicable law or agreed to in writing, software 12 // distributed under the License is distributed on an "AS IS" BASIS, 13 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 14 // See the License for the specific language governing permissions and 15 // limitations under the License. 16 17 // Package glog implements logging analogous to the Google-internal C++ INFO/ERROR/V setup. 18 // It provides functions Info, Warning, Error, Fatal, plus formatting variants such as 19 // Infof. It also provides V-style logging controlled by the -v and -vmodule=file=2 flags. 20 // 21 // Basic examples: 22 // 23 // glog.Info("Prepare to repel boarders") 24 // 25 // glog.Fatalf("Initialization failed: %s", err) 26 // 27 // See the documentation for the V function for an explanation of these examples: 28 // 29 // if glog.V(2) { 30 // glog.Info("Starting transaction...") 31 // } 32 // 33 // glog.V(2).Infoln("Processed", nItems, "elements") 34 // 35 // Log output is buffered and written periodically using Flush. Programs 36 // should call Flush before exiting to guarantee all log output is written. 37 // 38 // By default, all log statements write to files in a temporary directory. 39 // This package provides several flags that modify this behavior. 40 // As a result, flag.Parse must be called before any logging is done. 41 // 42 // -logtostderr=false 43 // Logs are written to standard error instead of to files. 44 // -alsologtostderr=false 45 // Logs are written to standard error as well as to files. 46 // -stderrthreshold=ERROR 47 // Log events at or above this severity are logged to standard 48 // error as well as to files. 49 // -log_dir="" 50 // Log files will be written to this directory instead of the 51 // default temporary directory. 52 // 53 // Other flags provide aids to debugging. 54 // 55 // -log_backtrace_at="" 56 // When set to a file and line number holding a logging statement, 57 // such as 58 // -log_backtrace_at=gopherflakes.go:234 59 // a stack trace will be written to the Info log whenever execution 60 // hits that statement. (Unlike with -vmodule, the ".go" must be 61 // present.) 62 // -v=0 63 // Enable V-leveled logging at the specified level. 64 // -vmodule="" 65 // The syntax of the argument is a comma-separated list of pattern=N, 66 // where pattern is a literal file name (minus the ".go" suffix) or 67 // "glob" pattern and N is a V level. For instance, 68 // -vmodule=gopher*=3 69 // sets the V level to 3 in all Go files whose names begin "gopher". 70 // 71 package glog 72 73 import ( 74 "bufio" 75 "bytes" 76 "errors" 77 "flag" 78 "fmt" 79 "io" 80 "os" 81 "path/filepath" 82 "runtime" 83 "strconv" 84 "strings" 85 "sync" 86 "sync/atomic" 87 "time" 88 ) 89 90 // severity identifies the sort of log: info, warning etc. It also implements 91 // the flag.Value interface. The -stderrthreshold flag is of type severity and 92 // should be modified only through the flag.Value interface. The values match 93 // the corresponding constants in C++. 94 type severity int32 // sync/atomic int32 95 96 const ( 97 infoLog severity = iota 98 warningLog 99 errorLog 100 fatalLog 101 numSeverity = 4 102 ) 103 104 const severityChar = "IWEF" 105 106 var severityName = []string{ 107 infoLog: "INFO", 108 warningLog: "WARNING", 109 errorLog: "ERROR", 110 fatalLog: "FATAL", 111 } 112 113 // get returns the value of the severity. 114 func (s *severity) get() severity { 115 return severity(atomic.LoadInt32((*int32)(s))) 116 } 117 118 // set sets the value of the severity. 119 func (s *severity) set(val severity) { 120 atomic.StoreInt32((*int32)(s), int32(val)) 121 } 122 123 // String is part of the flag.Value interface. 124 func (s *severity) String() string { 125 return strconv.FormatInt(int64(*s), 10) 126 } 127 128 // Get is part of the flag.Value interface. 129 func (s *severity) Get() interface{} { 130 return *s 131 } 132 133 // Set is part of the flag.Value interface. 134 func (s *severity) Set(value string) error { 135 var threshold severity 136 // Is it a known name? 137 if v, ok := severityByName(value); ok { 138 threshold = v 139 } else { 140 v, err := strconv.Atoi(value) 141 if err != nil { 142 return err 143 } 144 threshold = severity(v) 145 } 146 logging.stderrThreshold.set(threshold) 147 return nil 148 } 149 150 func severityByName(s string) (severity, bool) { 151 s = strings.ToUpper(s) 152 for i, name := range severityName { 153 if name == s { 154 return severity(i), true 155 } 156 } 157 return 0, false 158 } 159 160 // OutputStats tracks the number of output lines and bytes written. 161 type OutputStats struct { 162 lines int64 163 bytes int64 164 } 165 166 // Lines returns the number of lines written. 167 func (s *OutputStats) Lines() int64 { 168 return atomic.LoadInt64(&s.lines) 169 } 170 171 // Bytes returns the number of bytes written. 172 func (s *OutputStats) Bytes() int64 { 173 return atomic.LoadInt64(&s.bytes) 174 } 175 176 // Stats tracks the number of lines of output and number of bytes 177 // per severity level. Values must be read with atomic.LoadInt64. 178 var Stats struct { 179 Info, Warning, Error OutputStats 180 } 181 182 var severityStats = [numSeverity]*OutputStats{ 183 infoLog: &Stats.Info, 184 warningLog: &Stats.Warning, 185 errorLog: &Stats.Error, 186 } 187 188 // Level is exported because it appears in the arguments to V and is 189 // the type of the v flag, which can be set programmatically. 190 // It's a distinct type because we want to discriminate it from logType. 191 // Variables of type level are only changed under logging.mu. 192 // The -v flag is read only with atomic ops, so the state of the logging 193 // module is consistent. 194 195 // Level is treated as a sync/atomic int32. 196 197 // Level specifies a level of verbosity for V logs. *Level implements 198 // flag.Value; the -v flag is of type Level and should be modified 199 // only through the flag.Value interface. 200 type Level int32 201 202 // get returns the value of the Level. 203 func (l *Level) get() Level { 204 return Level(atomic.LoadInt32((*int32)(l))) 205 } 206 207 // set sets the value of the Level. 208 func (l *Level) set(val Level) { 209 atomic.StoreInt32((*int32)(l), int32(val)) 210 } 211 212 // String is part of the flag.Value interface. 213 func (l *Level) String() string { 214 return strconv.FormatInt(int64(*l), 10) 215 } 216 217 // Get is part of the flag.Value interface. 218 func (l *Level) Get() interface{} { 219 return *l 220 } 221 222 // Set is part of the flag.Value interface. 223 func (l *Level) Set(value string) error { 224 v, err := strconv.Atoi(value) 225 if err != nil { 226 return err 227 } 228 logging.mu.Lock() 229 defer logging.mu.Unlock() 230 logging.setVState(Level(v), logging.vmodule.filter, false) 231 return nil 232 } 233 234 // moduleSpec represents the setting of the -vmodule flag. 235 type moduleSpec struct { 236 filter []modulePat 237 } 238 239 // modulePat contains a filter for the -vmodule flag. 240 // It holds a verbosity level and a file pattern to match. 241 type modulePat struct { 242 pattern string 243 literal bool // The pattern is a literal string 244 level Level 245 } 246 247 // match reports whether the file matches the pattern. It uses a string 248 // comparison if the pattern contains no metacharacters. 249 func (m *modulePat) match(file string) bool { 250 if m.literal { 251 return file == m.pattern 252 } 253 match, _ := filepath.Match(m.pattern, file) 254 return match 255 } 256 257 func (m *moduleSpec) String() string { 258 // Lock because the type is not atomic. TODO: clean this up. 259 logging.mu.Lock() 260 defer logging.mu.Unlock() 261 var b bytes.Buffer 262 for i, f := range m.filter { 263 if i > 0 { 264 b.WriteRune(',') 265 } 266 fmt.Fprintf(&b, "%s=%d", f.pattern, f.level) 267 } 268 return b.String() 269 } 270 271 // Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the 272 // struct is not exported. 273 func (m *moduleSpec) Get() interface{} { 274 return nil 275 } 276 277 var errVmoduleSyntax = errors.New("syntax error: expect comma-separated list of filename=N") 278 279 // Syntax: -vmodule=recordio=2,file=1,gfs*=3 280 func (m *moduleSpec) Set(value string) error { 281 var filter []modulePat 282 for _, pat := range strings.Split(value, ",") { 283 if len(pat) == 0 { 284 // Empty strings such as from a trailing comma can be ignored. 285 continue 286 } 287 patLev := strings.Split(pat, "=") 288 if len(patLev) != 2 || len(patLev[0]) == 0 || len(patLev[1]) == 0 { 289 return errVmoduleSyntax 290 } 291 pattern := patLev[0] 292 v, err := strconv.Atoi(patLev[1]) 293 if err != nil { 294 return errors.New("syntax error: expect comma-separated list of filename=N") 295 } 296 if v < 0 { 297 return errors.New("negative value for vmodule level") 298 } 299 if v == 0 { 300 continue // Ignore. It's harmless but no point in paying the overhead. 301 } 302 // TODO: check syntax of filter? 303 filter = append(filter, modulePat{pattern, isLiteral(pattern), Level(v)}) 304 } 305 logging.mu.Lock() 306 defer logging.mu.Unlock() 307 logging.setVState(logging.verbosity, filter, true) 308 return nil 309 } 310 311 // isLiteral reports whether the pattern is a literal string, that is, has no metacharacters 312 // that require filepath.Match to be called to match the pattern. 313 func isLiteral(pattern string) bool { 314 return !strings.ContainsAny(pattern, `*?[]\`) 315 } 316 317 // traceLocation represents the setting of the -log_backtrace_at flag. 318 type traceLocation struct { 319 file string 320 line int 321 } 322 323 // isSet reports whether the trace location has been specified. 324 // logging.mu is held. 325 func (t *traceLocation) isSet() bool { 326 return t.line > 0 327 } 328 329 // match reports whether the specified file and line matches the trace location. 330 // The argument file name is the full path, not the basename specified in the flag. 331 // logging.mu is held. 332 func (t *traceLocation) match(file string, line int) bool { 333 if t.line != line { 334 return false 335 } 336 if i := strings.LastIndex(file, "/"); i >= 0 { 337 file = file[i+1:] 338 } 339 return t.file == file 340 } 341 342 func (t *traceLocation) String() string { 343 // Lock because the type is not atomic. TODO: clean this up. 344 logging.mu.Lock() 345 defer logging.mu.Unlock() 346 return fmt.Sprintf("%s:%d", t.file, t.line) 347 } 348 349 // Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the 350 // struct is not exported 351 func (t *traceLocation) Get() interface{} { 352 return nil 353 } 354 355 var errTraceSyntax = errors.New("syntax error: expect file.go:234") 356 357 // Syntax: -log_backtrace_at=gopherflakes.go:234 358 // Note that unlike vmodule the file extension is included here. 359 func (t *traceLocation) Set(value string) error { 360 if value == "" { 361 // Unset. 362 t.line = 0 363 t.file = "" 364 } 365 fields := strings.Split(value, ":") 366 if len(fields) != 2 { 367 return errTraceSyntax 368 } 369 file, line := fields[0], fields[1] 370 if !strings.Contains(file, ".") { 371 return errTraceSyntax 372 } 373 v, err := strconv.Atoi(line) 374 if err != nil { 375 return errTraceSyntax 376 } 377 if v <= 0 { 378 return errors.New("negative or zero value for level") 379 } 380 logging.mu.Lock() 381 defer logging.mu.Unlock() 382 t.line = v 383 t.file = file 384 return nil 385 } 386 387 // flushSyncWriter is the interface satisfied by logging destinations. 388 type flushSyncWriter interface { 389 Flush() error 390 Sync() error 391 io.Writer 392 } 393 394 func init() { 395 flag.BoolVar(&logging.toStderr, "logtostderr", false, "log to standard error instead of files") 396 flag.BoolVar(&logging.alsoToStderr, "alsologtostderr", false, "log to standard error as well as files") 397 flag.Var(&logging.verbosity, "v", "log level for V logs") 398 flag.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr") 399 flag.Var(&logging.vmodule, "vmodule", "comma-separated list of pattern=N settings for file-filtered logging") 400 flag.Var(&logging.traceLocation, "log_backtrace_at", "when logging hits line file:N, emit a stack trace") 401 402 // Default stderrThreshold is ERROR. 403 logging.stderrThreshold = errorLog 404 405 logging.setVState(0, nil, false) 406 go logging.flushDaemon() 407 } 408 409 // Flush flushes all pending log I/O. 410 func Flush() { 411 logging.lockAndFlushAll() 412 } 413 414 // loggingT collects all the global state of the logging setup. 415 type loggingT struct { 416 // Boolean flags. Not handled atomically because the flag.Value interface 417 // does not let us avoid the =true, and that shorthand is necessary for 418 // compatibility. TODO: does this matter enough to fix? Seems unlikely. 419 toStderr bool // The -logtostderr flag. 420 alsoToStderr bool // The -alsologtostderr flag. 421 422 // Level flag. Handled atomically. 423 stderrThreshold severity // The -stderrthreshold flag. 424 425 // freeList is a list of byte buffers, maintained under freeListMu. 426 freeList *buffer 427 // freeListMu maintains the free list. It is separate from the main mutex 428 // so buffers can be grabbed and printed to without holding the main lock, 429 // for better parallelization. 430 freeListMu sync.Mutex 431 432 // mu protects the remaining elements of this structure and is 433 // used to synchronize logging. 434 mu sync.Mutex 435 // file holds writer for each of the log types. 436 file [numSeverity]flushSyncWriter 437 // pcs is used in V to avoid an allocation when computing the caller's PC. 438 pcs [1]uintptr 439 // vmap is a cache of the V Level for each V() call site, identified by PC. 440 // It is wiped whenever the vmodule flag changes state. 441 vmap map[uintptr]Level 442 // filterLength stores the length of the vmodule filter chain. If greater 443 // than zero, it means vmodule is enabled. It may be read safely 444 // using sync.LoadInt32, but is only modified under mu. 445 filterLength int32 446 // traceLocation is the state of the -log_backtrace_at flag. 447 traceLocation traceLocation 448 // These flags are modified only under lock, although verbosity may be fetched 449 // safely using atomic.LoadInt32. 450 vmodule moduleSpec // The state of the -vmodule flag. 451 verbosity Level // V logging level, the value of the -v flag/ 452 } 453 454 // buffer holds a byte Buffer for reuse. The zero value is ready for use. 455 type buffer struct { 456 bytes.Buffer 457 tmp [64]byte // temporary byte array for creating headers. 458 next *buffer 459 } 460 461 var logging loggingT 462 463 // setVState sets a consistent state for V logging. 464 // l.mu is held. 465 func (l *loggingT) setVState(verbosity Level, filter []modulePat, setFilter bool) { 466 // Turn verbosity off so V will not fire while we are in transition. 467 logging.verbosity.set(0) 468 // Ditto for filter length. 469 logging.filterLength = 0 470 471 // Set the new filters and wipe the pc->Level map if the filter has changed. 472 if setFilter { 473 logging.vmodule.filter = filter 474 logging.vmap = make(map[uintptr]Level) 475 } 476 477 // Things are consistent now, so enable filtering and verbosity. 478 // They are enabled in order opposite to that in V. 479 atomic.StoreInt32(&logging.filterLength, int32(len(filter))) 480 logging.verbosity.set(verbosity) 481 } 482 483 // getBuffer returns a new, ready-to-use buffer. 484 func (l *loggingT) getBuffer() *buffer { 485 l.freeListMu.Lock() 486 b := l.freeList 487 if b != nil { 488 l.freeList = b.next 489 } 490 l.freeListMu.Unlock() 491 if b == nil { 492 b = new(buffer) 493 } else { 494 b.next = nil 495 b.Reset() 496 } 497 return b 498 } 499 500 // putBuffer returns a buffer to the free list. 501 func (l *loggingT) putBuffer(b *buffer) { 502 if b.Len() >= 256 { 503 // Let big buffers die a natural death. 504 return 505 } 506 l.freeListMu.Lock() 507 b.next = l.freeList 508 l.freeList = b 509 l.freeListMu.Unlock() 510 } 511 512 var timeNow = time.Now // Stubbed out for testing. 513 514 /* 515 header formats a log header as defined by the C++ implementation. 516 It returns a buffer containing the formatted header. 517 518 Log lines have this form: 519 Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg... 520 where the fields are defined as follows: 521 L A single character, representing the log level (eg 'I' for INFO) 522 mm The month (zero padded; ie May is '05') 523 dd The day (zero padded) 524 hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds 525 threadid The space-padded thread ID as returned by GetTID() 526 file The file name 527 line The line number 528 msg The user-supplied message 529 */ 530 func (l *loggingT) header(s severity) *buffer { 531 // Lmmdd hh:mm:ss.uuuuuu threadid file:line] 532 now := timeNow() 533 _, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call. 534 if !ok { 535 file = "???" 536 line = 1 537 } else { 538 slash := strings.LastIndex(file, "/") 539 if slash >= 0 { 540 file = file[slash+1:] 541 } 542 } 543 if line < 0 { 544 line = 0 // not a real line number, but acceptable to someDigits 545 } 546 if s > fatalLog { 547 s = infoLog // for safety. 548 } 549 buf := l.getBuffer() 550 551 // Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand. 552 // It's worth about 3X. Fprintf is hard. 553 _, month, day := now.Date() 554 hour, minute, second := now.Clock() 555 buf.tmp[0] = severityChar[s] 556 buf.twoDigits(1, int(month)) 557 buf.twoDigits(3, day) 558 buf.tmp[5] = ' ' 559 buf.twoDigits(6, hour) 560 buf.tmp[8] = ':' 561 buf.twoDigits(9, minute) 562 buf.tmp[11] = ':' 563 buf.twoDigits(12, second) 564 buf.tmp[14] = '.' 565 buf.nDigits(6, 15, now.Nanosecond()/1000) 566 buf.tmp[21] = ' ' 567 buf.nDigits(5, 22, pid) // TODO: should be TID 568 buf.tmp[27] = ' ' 569 buf.Write(buf.tmp[:28]) 570 buf.WriteString(file) 571 buf.tmp[0] = ':' 572 n := buf.someDigits(1, line) 573 buf.tmp[n+1] = ']' 574 buf.tmp[n+2] = ' ' 575 buf.Write(buf.tmp[:n+3]) 576 return buf 577 } 578 579 // Some custom tiny helper functions to print the log header efficiently. 580 581 const digits = "0123456789" 582 583 // twoDigits formats a zero-prefixed two-digit integer at buf.tmp[i]. 584 func (buf *buffer) twoDigits(i, d int) { 585 buf.tmp[i+1] = digits[d%10] 586 d /= 10 587 buf.tmp[i] = digits[d%10] 588 } 589 590 // nDigits formats a zero-prefixed n-digit integer at buf.tmp[i]. 591 func (buf *buffer) nDigits(n, i, d int) { 592 for j := n - 1; j >= 0; j-- { 593 buf.tmp[i+j] = digits[d%10] 594 d /= 10 595 } 596 } 597 598 // someDigits formats a zero-prefixed variable-width integer at buf.tmp[i]. 599 func (buf *buffer) someDigits(i, d int) int { 600 // Print into the top, then copy down. We know there's space for at least 601 // a 10-digit number. 602 j := len(buf.tmp) 603 for { 604 j-- 605 buf.tmp[j] = digits[d%10] 606 d /= 10 607 if d == 0 { 608 break 609 } 610 } 611 return copy(buf.tmp[i:], buf.tmp[j:]) 612 } 613 614 func (l *loggingT) println(s severity, args ...interface{}) { 615 buf := l.header(s) 616 fmt.Fprintln(buf, args...) 617 l.output(s, buf) 618 } 619 620 func (l *loggingT) print(s severity, args ...interface{}) { 621 buf := l.header(s) 622 fmt.Fprint(buf, args...) 623 if buf.Bytes()[buf.Len()-1] != '\n' { 624 buf.WriteByte('\n') 625 } 626 l.output(s, buf) 627 } 628 629 func (l *loggingT) printf(s severity, format string, args ...interface{}) { 630 buf := l.header(s) 631 fmt.Fprintf(buf, format, args...) 632 if buf.Bytes()[buf.Len()-1] != '\n' { 633 buf.WriteByte('\n') 634 } 635 l.output(s, buf) 636 } 637 638 // output writes the data to the log files and releases the buffer. 639 func (l *loggingT) output(s severity, buf *buffer) { 640 l.mu.Lock() 641 if l.traceLocation.isSet() { 642 _, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call (same as header). 643 if ok && l.traceLocation.match(file, line) { 644 buf.Write(stacks(false)) 645 } 646 } 647 data := buf.Bytes() 648 if l.toStderr { 649 os.Stderr.Write(data) 650 } else { 651 if l.alsoToStderr || s >= l.stderrThreshold.get() { 652 os.Stderr.Write(data) 653 } 654 if l.file[s] == nil { 655 if err := l.createFiles(s); err != nil { 656 os.Stderr.Write(data) // Make sure the message appears somewhere. 657 l.exit(err) 658 } 659 } 660 switch s { 661 case fatalLog: 662 l.file[fatalLog].Write(data) 663 fallthrough 664 case errorLog: 665 l.file[errorLog].Write(data) 666 fallthrough 667 case warningLog: 668 l.file[warningLog].Write(data) 669 fallthrough 670 case infoLog: 671 l.file[infoLog].Write(data) 672 } 673 } 674 if s == fatalLog { 675 // Make sure we see the trace for the current goroutine on standard error. 676 if !l.toStderr { 677 os.Stderr.Write(stacks(false)) 678 } 679 // Write the stack trace for all goroutines to the files. 680 trace := stacks(true) 681 logExitFunc = func(error) {} // If we get a write error, we'll still exit below. 682 for log := fatalLog; log >= infoLog; log-- { 683 if f := l.file[log]; f != nil { // Can be nil if -logtostderr is set. 684 f.Write(trace) 685 } 686 } 687 l.mu.Unlock() 688 timeoutFlush(10 * time.Second) 689 os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway. 690 } 691 l.putBuffer(buf) 692 l.mu.Unlock() 693 if stats := severityStats[s]; stats != nil { 694 atomic.AddInt64(&stats.lines, 1) 695 atomic.AddInt64(&stats.bytes, int64(len(data))) 696 } 697 } 698 699 // timeoutFlush calls Flush and returns when it completes or after timeout 700 // elapses, whichever happens first. This is needed because the hooks invoked 701 // by Flush may deadlock when glog.Fatal is called from a hook that holds 702 // a lock. 703 func timeoutFlush(timeout time.Duration) { 704 done := make(chan bool, 1) 705 go func() { 706 Flush() // calls logging.lockAndFlushAll() 707 done <- true 708 }() 709 select { 710 case <-done: 711 case <-time.After(timeout): 712 fmt.Fprintln(os.Stderr, "glog: Flush took longer than", timeout) 713 } 714 } 715 716 // stacks is a wrapper for runtime.Stack that attempts to recover the data for all goroutines. 717 func stacks(all bool) []byte { 718 // We don't know how big the traces are, so grow a few times if they don't fit. Start large, though. 719 n := 10000 720 if all { 721 n = 100000 722 } 723 var trace []byte 724 for i := 0; i < 5; i++ { 725 trace = make([]byte, n) 726 nbytes := runtime.Stack(trace, all) 727 if nbytes < len(trace) { 728 return trace[:nbytes] 729 } 730 n *= 2 731 } 732 return trace 733 } 734 735 // logExitFunc provides a simple mechanism to override the default behavior 736 // of exiting on error. Used in testing and to guarantee we reach a required exit 737 // for fatal logs. Instead, exit could be a function rather than a method but that 738 // would make its use clumsier. 739 var logExitFunc func(error) 740 741 // exit is called if there is trouble creating or writing log files. 742 // It flushes the logs and exits the program; there's no point in hanging around. 743 // l.mu is held. 744 func (l *loggingT) exit(err error) { 745 fmt.Fprintf(os.Stderr, "log: exiting because of error: %s\n", err) 746 // If logExitFunc is set, we do that instead of exiting. 747 if logExitFunc != nil { 748 logExitFunc(err) 749 return 750 } 751 l.flushAll() 752 os.Exit(2) 753 } 754 755 // syncBuffer joins a bufio.Writer to its underlying file, providing access to the 756 // file's Sync method and providing a wrapper for the Write method that provides log 757 // file rotation. There are conflicting methods, so the file cannot be embedded. 758 // l.mu is held for all its methods. 759 type syncBuffer struct { 760 logger *loggingT 761 *bufio.Writer 762 file *os.File 763 sev severity 764 nbytes uint64 // The number of bytes written to this file 765 } 766 767 func (sb *syncBuffer) Sync() error { 768 return sb.file.Sync() 769 } 770 771 func (sb *syncBuffer) Write(p []byte) (n int, err error) { 772 if sb.nbytes+uint64(len(p)) >= MaxSize { 773 if err := sb.rotateFile(time.Now()); err != nil { 774 sb.logger.exit(err) 775 } 776 } 777 n, err = sb.Writer.Write(p) 778 sb.nbytes += uint64(n) 779 if err != nil { 780 sb.logger.exit(err) 781 } 782 return 783 } 784 785 // rotateFile closes the syncBuffer's file and starts a new one. 786 func (sb *syncBuffer) rotateFile(now time.Time) error { 787 if sb.file != nil { 788 sb.Flush() 789 sb.file.Close() 790 } 791 var err error 792 sb.file, _, err = create(severityName[sb.sev], now) 793 sb.nbytes = 0 794 if err != nil { 795 return err 796 } 797 798 sb.Writer = bufio.NewWriterSize(sb.file, bufferSize) 799 800 // Write header. 801 var buf bytes.Buffer 802 fmt.Fprintf(&buf, "Log file created at: %s\n", now.Format("2006/01/02 15:04:05")) 803 fmt.Fprintf(&buf, "Running on machine: %s\n", host) 804 fmt.Fprintf(&buf, "Binary: Built with %s %s for %s/%s\n", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH) 805 fmt.Fprintf(&buf, "Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg\n") 806 n, err := sb.file.Write(buf.Bytes()) 807 sb.nbytes += uint64(n) 808 return err 809 } 810 811 // bufferSize sizes the buffer associated with each log file. It's large 812 // so that log records can accumulate without the logging thread blocking 813 // on disk I/O. The flushDaemon will block instead. 814 const bufferSize = 256 * 1024 815 816 // createFiles creates all the log files for severity from sev down to infoLog. 817 // l.mu is held. 818 func (l *loggingT) createFiles(sev severity) error { 819 now := time.Now() 820 // Files are created in decreasing severity order, so as soon as we find one 821 // has already been created, we can stop. 822 for s := sev; s >= infoLog && l.file[s] == nil; s-- { 823 sb := &syncBuffer{ 824 logger: l, 825 sev: s, 826 } 827 if err := sb.rotateFile(now); err != nil { 828 return err 829 } 830 l.file[s] = sb 831 } 832 return nil 833 } 834 835 const flushInterval = 30 * time.Second 836 837 // flushDaemon periodically flushes the log file buffers. 838 func (l *loggingT) flushDaemon() { 839 for _ = range time.NewTicker(flushInterval).C { 840 l.lockAndFlushAll() 841 } 842 } 843 844 // lockAndFlushAll is like flushAll but locks l.mu first. 845 func (l *loggingT) lockAndFlushAll() { 846 l.mu.Lock() 847 l.flushAll() 848 l.mu.Unlock() 849 } 850 851 // flushAll flushes all the logs and attempts to "sync" their data to disk. 852 // l.mu is held. 853 func (l *loggingT) flushAll() { 854 // Flush from fatal down, in case there's trouble flushing. 855 for s := fatalLog; s >= infoLog; s-- { 856 file := l.file[s] 857 if file != nil { 858 file.Flush() // ignore error 859 file.Sync() // ignore error 860 } 861 } 862 } 863 864 // setV computes and remembers the V level for a given PC 865 // when vmodule is enabled. 866 // File pattern matching takes the basename of the file, stripped 867 // of its .go suffix, and uses filepath.Match, which is a little more 868 // general than the *? matching used in C++. 869 // l.mu is held. 870 func (l *loggingT) setV(pc uintptr) Level { 871 fn := runtime.FuncForPC(pc) 872 file, _ := fn.FileLine(pc) 873 // The file is something like /a/b/c/d.go. We want just the d. 874 if strings.HasSuffix(file, ".go") { 875 file = file[:len(file)-3] 876 } 877 if slash := strings.LastIndex(file, "/"); slash >= 0 { 878 file = file[slash+1:] 879 } 880 for _, filter := range l.vmodule.filter { 881 if filter.match(file) { 882 l.vmap[pc] = filter.level 883 return filter.level 884 } 885 } 886 l.vmap[pc] = 0 887 return 0 888 } 889 890 // Verbose is a boolean type that implements Infof (like Printf) etc. 891 // See the documentation of V for more information. 892 type Verbose bool 893 894 // V reports whether verbosity at the call site is at least the requested level. 895 // The returned value is a boolean of type Verbose, which implements Info, Infoln 896 // and Infof. These methods will write to the Info log if called. 897 // Thus, one may write either 898 // if glog.V(2) { glog.Info("log this") } 899 // or 900 // glog.V(2).Info("log this") 901 // The second form is shorter but the first is cheaper if logging is off because it does 902 // not evaluate its arguments. 903 // 904 // Whether an individual call to V generates a log record depends on the setting of 905 // the -v and --vmodule flags; both are off by default. If the level in the call to 906 // V is at least the value of -v, or of -vmodule for the source file containing the 907 // call, the V call will log. 908 func V(level Level) Verbose { 909 // This function tries hard to be cheap unless there's work to do. 910 // The fast path is two atomic loads and compares. 911 912 // Here is a cheap but safe test to see if V logging is enabled globally. 913 if logging.verbosity.get() >= level { 914 return Verbose(true) 915 } 916 917 // It's off globally but it vmodule may still be set. 918 // Here is another cheap but safe test to see if vmodule is enabled. 919 if atomic.LoadInt32(&logging.filterLength) > 0 { 920 // Now we need a proper lock to use the logging structure. The pcs field 921 // is shared so we must lock before accessing it. This is fairly expensive, 922 // but if V logging is enabled we're slow anyway. 923 logging.mu.Lock() 924 defer logging.mu.Unlock() 925 if runtime.Callers(2, logging.pcs[:]) == 0 { 926 return Verbose(false) 927 } 928 v, ok := logging.vmap[logging.pcs[0]] 929 if !ok { 930 v = logging.setV(logging.pcs[0]) 931 } 932 return Verbose(v >= level) 933 } 934 return Verbose(false) 935 } 936 937 // Info is equivalent to the global Info function, guarded by the value of v. 938 // See the documentation of V for usage. 939 func (v Verbose) Info(args ...interface{}) { 940 if v { 941 logging.print(infoLog, args...) 942 } 943 } 944 945 // Infoln is equivalent to the global Infoln function, guarded by the value of v. 946 // See the documentation of V for usage. 947 func (v Verbose) Infoln(args ...interface{}) { 948 if v { 949 logging.println(infoLog, args...) 950 } 951 } 952 953 // Infof is equivalent to the global Infof function, guarded by the value of v. 954 // See the documentation of V for usage. 955 func (v Verbose) Infof(format string, args ...interface{}) { 956 if v { 957 logging.printf(infoLog, format, args...) 958 } 959 } 960 961 // Info logs to the INFO log. 962 // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. 963 func Info(args ...interface{}) { 964 logging.print(infoLog, args...) 965 } 966 967 // Infoln logs to the INFO log. 968 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing. 969 func Infoln(args ...interface{}) { 970 logging.println(infoLog, args...) 971 } 972 973 // Infof logs to the INFO log. 974 // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. 975 func Infof(format string, args ...interface{}) { 976 logging.printf(infoLog, format, args...) 977 } 978 979 // Warning logs to the WARNING and INFO logs. 980 // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. 981 func Warning(args ...interface{}) { 982 logging.print(warningLog, args...) 983 } 984 985 // Warningln logs to the WARNING and INFO logs. 986 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing. 987 func Warningln(args ...interface{}) { 988 logging.println(warningLog, args...) 989 } 990 991 // Warningf logs to the WARNING and INFO logs. 992 // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. 993 func Warningf(format string, args ...interface{}) { 994 logging.printf(warningLog, format, args...) 995 } 996 997 // Error logs to the ERROR, WARNING, and INFO logs. 998 // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. 999 func Error(args ...interface{}) { 1000 logging.print(errorLog, args...) 1001 } 1002 1003 // Errorln logs to the ERROR, WARNING, and INFO logs. 1004 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing. 1005 func Errorln(args ...interface{}) { 1006 logging.println(errorLog, args...) 1007 } 1008 1009 // Errorf logs to the ERROR, WARNING, and INFO logs. 1010 // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. 1011 func Errorf(format string, args ...interface{}) { 1012 logging.printf(errorLog, format, args...) 1013 } 1014 1015 // Fatal logs to the FATAL, ERROR, WARNING, and INFO logs, 1016 // including a stack trace of all running goroutines, then calls os.Exit(255). 1017 // Arguments are handled in the manner of fmt.Print; a newline is appended if missing. 1018 func Fatal(args ...interface{}) { 1019 logging.print(fatalLog, args...) 1020 } 1021 1022 // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs, 1023 // including a stack trace of all running goroutines, then calls os.Exit(255). 1024 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing. 1025 func Fatalln(args ...interface{}) { 1026 logging.println(fatalLog, args...) 1027 } 1028 1029 // Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs, 1030 // including a stack trace of all running goroutines, then calls os.Exit(255). 1031 // Arguments are handled in the manner of fmt.Printf; a newline is appended if missing. 1032 func Fatalf(format string, args ...interface{}) { 1033 logging.printf(fatalLog, format, args...) 1034 }