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