mirror of
https://github.com/seaweedfs/seaweedfs.git
synced 2024-11-26 03:59:12 +08:00
1182 lines
36 KiB
Go
1182 lines
36 KiB
Go
// Go support for leveled logs, analogous to https://code.google.com/p/google-glog/
|
|
//
|
|
// Copyright 2013 Google Inc. All Rights Reserved.
|
|
//
|
|
// Licensed under the Apache License, Version 2.0 (the "License");
|
|
// you may not use this file except in compliance with the License.
|
|
// You may obtain a copy of the License at
|
|
//
|
|
// http://www.apache.org/licenses/LICENSE-2.0
|
|
//
|
|
// Unless required by applicable law or agreed to in writing, software
|
|
// distributed under the License is distributed on an "AS IS" BASIS,
|
|
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
// See the License for the specific language governing permissions and
|
|
// limitations under the License.
|
|
|
|
// Package glog implements logging analogous to the Google-internal C++ INFO/ERROR/V setup.
|
|
// It provides functions Info, Warning, Error, Fatal, plus formatting variants such as
|
|
// Infof. It also provides V-style logging controlled by the -v and -vmodule=file=2 flags.
|
|
//
|
|
// Basic examples:
|
|
//
|
|
// glog.Info("Prepare to repel boarders")
|
|
//
|
|
// glog.Fatalf("Initialization failed: %s", err)
|
|
//
|
|
// See the documentation for the V function for an explanation of these examples:
|
|
//
|
|
// if glog.V(2) {
|
|
// glog.Info("Starting transaction...")
|
|
// }
|
|
//
|
|
// glog.V(2).Infoln("Processed", nItems, "elements")
|
|
//
|
|
// Log output is buffered and written periodically using Flush. Programs
|
|
// should call Flush before exiting to guarantee all log output is written.
|
|
//
|
|
// By default, all log statements write to files in a temporary directory.
|
|
// This package provides several flags that modify this behavior.
|
|
// As a result, flag.Parse must be called before any logging is done.
|
|
//
|
|
// -logtostderr=false
|
|
// Logs are written to standard error instead of to files.
|
|
// -alsologtostderr=false
|
|
// Logs are written to standard error as well as to files.
|
|
// -stderrthreshold=ERROR
|
|
// Log events at or above this severity are logged to standard
|
|
// error as well as to files.
|
|
// -logdir=""
|
|
// Log files will be written to this directory instead of the
|
|
// default temporary directory.
|
|
//
|
|
// Other flags provide aids to debugging.
|
|
//
|
|
// -log_backtrace_at=""
|
|
// When set to a file and line number holding a logging statement,
|
|
// such as
|
|
// -log_backtrace_at=gopherflakes.go:234
|
|
// a stack trace will be written to the Info log whenever execution
|
|
// hits that statement. (Unlike with -vmodule, the ".go" must be
|
|
// present.)
|
|
// -v=0
|
|
// Enable V-leveled logging at the specified level.
|
|
// -vmodule=""
|
|
// The syntax of the argument is a comma-separated list of pattern=N,
|
|
// where pattern is a literal file name (minus the ".go" suffix) or
|
|
// "glob" pattern and N is a V level. For instance,
|
|
// -vmodule=gopher*=3
|
|
// sets the V level to 3 in all Go files whose names begin "gopher".
|
|
//
|
|
package glog
|
|
|
|
import (
|
|
"bufio"
|
|
"bytes"
|
|
"errors"
|
|
"fmt"
|
|
flag "github.com/chrislusf/seaweedfs/weed/util/fla9"
|
|
"io"
|
|
stdLog "log"
|
|
"os"
|
|
"path/filepath"
|
|
"runtime"
|
|
"strconv"
|
|
"strings"
|
|
"sync"
|
|
"sync/atomic"
|
|
"time"
|
|
)
|
|
|
|
// severity identifies the sort of log: info, warning etc. It also implements
|
|
// the flag.Value interface. The -stderrthreshold flag is of type severity and
|
|
// should be modified only through the flag.Value interface. The values match
|
|
// the corresponding constants in C++.
|
|
type severity int32 // sync/atomic int32
|
|
|
|
// These constants identify the log levels in order of increasing severity.
|
|
// A message written to a high-severity log file is also written to each
|
|
// lower-severity log file.
|
|
const (
|
|
infoLog severity = iota
|
|
warningLog
|
|
errorLog
|
|
fatalLog
|
|
numSeverity = 4
|
|
)
|
|
|
|
const severityChar = "IWEF"
|
|
|
|
var severityName = []string{
|
|
infoLog: "INFO",
|
|
warningLog: "WARNING",
|
|
errorLog: "ERROR",
|
|
fatalLog: "FATAL",
|
|
}
|
|
|
|
// get returns the value of the severity.
|
|
func (s *severity) get() severity {
|
|
return severity(atomic.LoadInt32((*int32)(s)))
|
|
}
|
|
|
|
// set sets the value of the severity.
|
|
func (s *severity) set(val severity) {
|
|
atomic.StoreInt32((*int32)(s), int32(val))
|
|
}
|
|
|
|
// String is part of the flag.Value interface.
|
|
func (s *severity) String() string {
|
|
return strconv.FormatInt(int64(*s), 10)
|
|
}
|
|
|
|
// Get is part of the flag.Value interface.
|
|
func (s *severity) Get() interface{} {
|
|
return *s
|
|
}
|
|
|
|
// Set is part of the flag.Value interface.
|
|
func (s *severity) Set(value string) error {
|
|
var threshold severity
|
|
// Is it a known name?
|
|
if v, ok := severityByName(value); ok {
|
|
threshold = v
|
|
} else {
|
|
v, err := strconv.Atoi(value)
|
|
if err != nil {
|
|
return err
|
|
}
|
|
threshold = severity(v)
|
|
}
|
|
logging.stderrThreshold.set(threshold)
|
|
return nil
|
|
}
|
|
|
|
func severityByName(s string) (severity, bool) {
|
|
s = strings.ToUpper(s)
|
|
for i, name := range severityName {
|
|
if name == s {
|
|
return severity(i), true
|
|
}
|
|
}
|
|
return 0, false
|
|
}
|
|
|
|
// OutputStats tracks the number of output lines and bytes written.
|
|
type OutputStats struct {
|
|
lines int64
|
|
bytes int64
|
|
}
|
|
|
|
// Lines returns the number of lines written.
|
|
func (s *OutputStats) Lines() int64 {
|
|
return atomic.LoadInt64(&s.lines)
|
|
}
|
|
|
|
// Bytes returns the number of bytes written.
|
|
func (s *OutputStats) Bytes() int64 {
|
|
return atomic.LoadInt64(&s.bytes)
|
|
}
|
|
|
|
// Stats tracks the number of lines of output and number of bytes
|
|
// per severity level. Values must be read with atomic.LoadInt64.
|
|
var Stats struct {
|
|
Info, Warning, Error OutputStats
|
|
}
|
|
|
|
var severityStats = [numSeverity]*OutputStats{
|
|
infoLog: &Stats.Info,
|
|
warningLog: &Stats.Warning,
|
|
errorLog: &Stats.Error,
|
|
}
|
|
|
|
// Level is exported because it appears in the arguments to V and is
|
|
// the type of the v flag, which can be set programmatically.
|
|
// It's a distinct type because we want to discriminate it from logType.
|
|
// Variables of type level are only changed under logging.mu.
|
|
// The -v flag is read only with atomic ops, so the state of the logging
|
|
// module is consistent.
|
|
|
|
// Level is treated as a sync/atomic int32.
|
|
|
|
// Level specifies a level of verbosity for V logs. *Level implements
|
|
// flag.Value; the -v flag is of type Level and should be modified
|
|
// only through the flag.Value interface.
|
|
type Level int32
|
|
|
|
// get returns the value of the Level.
|
|
func (l *Level) get() Level {
|
|
return Level(atomic.LoadInt32((*int32)(l)))
|
|
}
|
|
|
|
// set sets the value of the Level.
|
|
func (l *Level) set(val Level) {
|
|
atomic.StoreInt32((*int32)(l), int32(val))
|
|
}
|
|
|
|
// String is part of the flag.Value interface.
|
|
func (l *Level) String() string {
|
|
return strconv.FormatInt(int64(*l), 10)
|
|
}
|
|
|
|
// Get is part of the flag.Value interface.
|
|
func (l *Level) Get() interface{} {
|
|
return *l
|
|
}
|
|
|
|
// Set is part of the flag.Value interface.
|
|
func (l *Level) Set(value string) error {
|
|
v, err := strconv.Atoi(value)
|
|
if err != nil {
|
|
return err
|
|
}
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
logging.setVState(Level(v), logging.vmodule.filter, false)
|
|
return nil
|
|
}
|
|
|
|
// moduleSpec represents the setting of the -vmodule flag.
|
|
type moduleSpec struct {
|
|
filter []modulePat
|
|
}
|
|
|
|
// modulePat contains a filter for the -vmodule flag.
|
|
// It holds a verbosity level and a file pattern to match.
|
|
type modulePat struct {
|
|
pattern string
|
|
literal bool // The pattern is a literal string
|
|
level Level
|
|
}
|
|
|
|
// match reports whether the file matches the pattern. It uses a string
|
|
// comparison if the pattern contains no metacharacters.
|
|
func (m *modulePat) match(file string) bool {
|
|
if m.literal {
|
|
return file == m.pattern
|
|
}
|
|
match, _ := filepath.Match(m.pattern, file)
|
|
return match
|
|
}
|
|
|
|
func (m *moduleSpec) String() string {
|
|
// Lock because the type is not atomic. TODO: clean this up.
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
var b bytes.Buffer
|
|
for i, f := range m.filter {
|
|
if i > 0 {
|
|
b.WriteRune(',')
|
|
}
|
|
fmt.Fprintf(&b, "%s=%d", f.pattern, f.level)
|
|
}
|
|
return b.String()
|
|
}
|
|
|
|
// Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the
|
|
// struct is not exported.
|
|
func (m *moduleSpec) Get() interface{} {
|
|
return nil
|
|
}
|
|
|
|
var errVmoduleSyntax = errors.New("syntax error: expect comma-separated list of filename=N")
|
|
|
|
// Syntax: -vmodule=recordio=2,file=1,gfs*=3
|
|
func (m *moduleSpec) Set(value string) error {
|
|
var filter []modulePat
|
|
for _, pat := range strings.Split(value, ",") {
|
|
if len(pat) == 0 {
|
|
// Empty strings such as from a trailing comma can be ignored.
|
|
continue
|
|
}
|
|
patLev := strings.Split(pat, "=")
|
|
if len(patLev) != 2 || len(patLev[0]) == 0 || len(patLev[1]) == 0 {
|
|
return errVmoduleSyntax
|
|
}
|
|
pattern := patLev[0]
|
|
v, err := strconv.Atoi(patLev[1])
|
|
if err != nil {
|
|
return errors.New("syntax error: expect comma-separated list of filename=N")
|
|
}
|
|
if v < 0 {
|
|
return errors.New("negative value for vmodule level")
|
|
}
|
|
if v == 0 {
|
|
continue // Ignore. It's harmless but no point in paying the overhead.
|
|
}
|
|
// TODO: check syntax of filter?
|
|
filter = append(filter, modulePat{pattern, isLiteral(pattern), Level(v)})
|
|
}
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
logging.setVState(logging.verbosity, filter, true)
|
|
return nil
|
|
}
|
|
|
|
// isLiteral reports whether the pattern is a literal string, that is, has no metacharacters
|
|
// that require filepath.Match to be called to match the pattern.
|
|
func isLiteral(pattern string) bool {
|
|
return !strings.ContainsAny(pattern, `\*?[]`)
|
|
}
|
|
|
|
// traceLocation represents the setting of the -log_backtrace_at flag.
|
|
type traceLocation struct {
|
|
file string
|
|
line int
|
|
}
|
|
|
|
// isSet reports whether the trace location has been specified.
|
|
// logging.mu is held.
|
|
func (t *traceLocation) isSet() bool {
|
|
return t.line > 0
|
|
}
|
|
|
|
// match reports whether the specified file and line matches the trace location.
|
|
// The argument file name is the full path, not the basename specified in the flag.
|
|
// logging.mu is held.
|
|
func (t *traceLocation) match(file string, line int) bool {
|
|
if t.line != line {
|
|
return false
|
|
}
|
|
if i := strings.LastIndex(file, "/"); i >= 0 {
|
|
file = file[i+1:]
|
|
}
|
|
return t.file == file
|
|
}
|
|
|
|
func (t *traceLocation) String() string {
|
|
// Lock because the type is not atomic. TODO: clean this up.
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
return fmt.Sprintf("%s:%d", t.file, t.line)
|
|
}
|
|
|
|
// Get is part of the (Go 1.2) flag.Getter interface. It always returns nil for this flag type since the
|
|
// struct is not exported
|
|
func (t *traceLocation) Get() interface{} {
|
|
return nil
|
|
}
|
|
|
|
var errTraceSyntax = errors.New("syntax error: expect file.go:234")
|
|
|
|
// Syntax: -log_backtrace_at=gopherflakes.go:234
|
|
// Note that unlike vmodule the file extension is included here.
|
|
func (t *traceLocation) Set(value string) error {
|
|
if value == "" {
|
|
// Unset.
|
|
t.line = 0
|
|
t.file = ""
|
|
}
|
|
fields := strings.Split(value, ":")
|
|
if len(fields) != 2 {
|
|
return errTraceSyntax
|
|
}
|
|
file, line := fields[0], fields[1]
|
|
if !strings.Contains(file, ".") {
|
|
return errTraceSyntax
|
|
}
|
|
v, err := strconv.Atoi(line)
|
|
if err != nil {
|
|
return errTraceSyntax
|
|
}
|
|
if v <= 0 {
|
|
return errors.New("negative or zero value for level")
|
|
}
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
t.line = v
|
|
t.file = file
|
|
return nil
|
|
}
|
|
|
|
// flushSyncWriter is the interface satisfied by logging destinations.
|
|
type flushSyncWriter interface {
|
|
Flush() error
|
|
Sync() error
|
|
io.Writer
|
|
}
|
|
|
|
func init() {
|
|
flag.BoolVar(&logging.toStderr, "logtostderr", false, "log to standard error instead of files")
|
|
flag.BoolVar(&logging.alsoToStderr, "alsologtostderr", true, "log to standard error as well as files")
|
|
flag.Var(&logging.verbosity, "v", "log levels [0|1|2|3|4], default to 0")
|
|
flag.Var(&logging.stderrThreshold, "stderrthreshold", "logs at or above this threshold go to stderr")
|
|
flag.Var(&logging.vmodule, "vmodule", "comma-separated list of pattern=N settings for file-filtered logging")
|
|
flag.Var(&logging.traceLocation, "log_backtrace_at", "when logging hits line file:N, emit a stack trace")
|
|
|
|
// Default stderrThreshold is ERROR.
|
|
logging.stderrThreshold = errorLog
|
|
|
|
logging.setVState(0, nil, false)
|
|
go logging.flushDaemon()
|
|
}
|
|
|
|
// Flush flushes all pending log I/O.
|
|
func Flush() {
|
|
logging.lockAndFlushAll()
|
|
}
|
|
|
|
// loggingT collects all the global state of the logging setup.
|
|
type loggingT struct {
|
|
// Boolean flags. Not handled atomically because the flag.Value interface
|
|
// does not let us avoid the =true, and that shorthand is necessary for
|
|
// compatibility. TODO: does this matter enough to fix? Seems unlikely.
|
|
toStderr bool // The -logtostderr flag.
|
|
alsoToStderr bool // The -alsologtostderr flag.
|
|
|
|
// Level flag. Handled atomically.
|
|
stderrThreshold severity // The -stderrthreshold flag.
|
|
|
|
// freeList is a list of byte buffers, maintained under freeListMu.
|
|
freeList *buffer
|
|
// freeListMu maintains the free list. It is separate from the main mutex
|
|
// so buffers can be grabbed and printed to without holding the main lock,
|
|
// for better parallelization.
|
|
freeListMu sync.Mutex
|
|
|
|
// mu protects the remaining elements of this structure and is
|
|
// used to synchronize logging.
|
|
mu sync.Mutex
|
|
// file holds writer for each of the log types.
|
|
file [numSeverity]flushSyncWriter
|
|
// pcs is used in V to avoid an allocation when computing the caller's PC.
|
|
pcs [1]uintptr
|
|
// vmap is a cache of the V Level for each V() call site, identified by PC.
|
|
// It is wiped whenever the vmodule flag changes state.
|
|
vmap map[uintptr]Level
|
|
// filterLength stores the length of the vmodule filter chain. If greater
|
|
// than zero, it means vmodule is enabled. It may be read safely
|
|
// using sync.LoadInt32, but is only modified under mu.
|
|
filterLength int32
|
|
// traceLocation is the state of the -log_backtrace_at flag.
|
|
traceLocation traceLocation
|
|
// These flags are modified only under lock, although verbosity may be fetched
|
|
// safely using atomic.LoadInt32.
|
|
vmodule moduleSpec // The state of the -vmodule flag.
|
|
verbosity Level // V logging level, the value of the -v flag/
|
|
|
|
// added by seaweedfs
|
|
exited bool
|
|
}
|
|
|
|
// buffer holds a byte Buffer for reuse. The zero value is ready for use.
|
|
type buffer struct {
|
|
bytes.Buffer
|
|
tmp [64]byte // temporary byte array for creating headers.
|
|
next *buffer
|
|
}
|
|
|
|
var logging loggingT
|
|
|
|
// setVState sets a consistent state for V logging.
|
|
// l.mu is held.
|
|
func (l *loggingT) setVState(verbosity Level, filter []modulePat, setFilter bool) {
|
|
// Turn verbosity off so V will not fire while we are in transition.
|
|
logging.verbosity.set(0)
|
|
// Ditto for filter length.
|
|
atomic.StoreInt32(&logging.filterLength, 0)
|
|
|
|
// Set the new filters and wipe the pc->Level map if the filter has changed.
|
|
if setFilter {
|
|
logging.vmodule.filter = filter
|
|
logging.vmap = make(map[uintptr]Level)
|
|
}
|
|
|
|
// Things are consistent now, so enable filtering and verbosity.
|
|
// They are enabled in order opposite to that in V.
|
|
atomic.StoreInt32(&logging.filterLength, int32(len(filter)))
|
|
logging.verbosity.set(verbosity)
|
|
}
|
|
|
|
// getBuffer returns a new, ready-to-use buffer.
|
|
func (l *loggingT) getBuffer() *buffer {
|
|
l.freeListMu.Lock()
|
|
b := l.freeList
|
|
if b != nil {
|
|
l.freeList = b.next
|
|
}
|
|
l.freeListMu.Unlock()
|
|
if b == nil {
|
|
b = new(buffer)
|
|
} else {
|
|
b.next = nil
|
|
b.Reset()
|
|
}
|
|
return b
|
|
}
|
|
|
|
// putBuffer returns a buffer to the free list.
|
|
func (l *loggingT) putBuffer(b *buffer) {
|
|
if b.Len() >= 256 {
|
|
// Let big buffers die a natural death.
|
|
return
|
|
}
|
|
l.freeListMu.Lock()
|
|
b.next = l.freeList
|
|
l.freeList = b
|
|
l.freeListMu.Unlock()
|
|
}
|
|
|
|
var timeNow = time.Now // Stubbed out for testing.
|
|
|
|
/*
|
|
header formats a log header as defined by the C++ implementation.
|
|
It returns a buffer containing the formatted header and the user's file and line number.
|
|
The depth specifies how many stack frames above lives the source line to be identified in the log message.
|
|
|
|
Log lines have this form:
|
|
Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
|
|
where the fields are defined as follows:
|
|
L A single character, representing the log level (eg 'I' for INFO)
|
|
mm The month (zero padded; ie May is '05')
|
|
dd The day (zero padded)
|
|
hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds
|
|
threadid The space-padded thread ID as returned by GetTID()
|
|
file The file name
|
|
line The line number
|
|
msg The user-supplied message
|
|
*/
|
|
func (l *loggingT) header(s severity, depth int) (*buffer, string, int) {
|
|
_, file, line, ok := runtime.Caller(3 + depth)
|
|
if !ok {
|
|
file = "???"
|
|
line = 1
|
|
} else {
|
|
slash := strings.LastIndex(file, "/")
|
|
if slash >= 0 {
|
|
file = file[slash+1:]
|
|
}
|
|
}
|
|
return l.formatHeader(s, file, line), file, line
|
|
}
|
|
|
|
// formatHeader formats a log header using the provided file name and line number.
|
|
func (l *loggingT) formatHeader(s severity, file string, line int) *buffer {
|
|
now := timeNow()
|
|
if line < 0 {
|
|
line = 0 // not a real line number, but acceptable to someDigits
|
|
}
|
|
if s > fatalLog {
|
|
s = infoLog // for safety.
|
|
}
|
|
buf := l.getBuffer()
|
|
|
|
// Avoid Fprintf, for speed. The format is so simple that we can do it quickly by hand.
|
|
// It's worth about 3X. Fprintf is hard.
|
|
_, month, day := now.Date()
|
|
hour, minute, second := now.Clock()
|
|
// Lmmdd hh:mm:ss.uuuuuu threadid file:line]
|
|
buf.tmp[0] = severityChar[s]
|
|
buf.twoDigits(1, int(month))
|
|
buf.twoDigits(3, day)
|
|
buf.tmp[5] = ' '
|
|
buf.twoDigits(6, hour)
|
|
buf.tmp[8] = ':'
|
|
buf.twoDigits(9, minute)
|
|
buf.tmp[11] = ':'
|
|
buf.twoDigits(12, second)
|
|
buf.tmp[14] = ' '
|
|
buf.nDigits(5, 15, pid, ' ') // TODO: should be TID
|
|
buf.tmp[20] = ' '
|
|
buf.Write(buf.tmp[:21])
|
|
buf.WriteString(file)
|
|
buf.tmp[0] = ':'
|
|
n := buf.someDigits(1, line)
|
|
buf.tmp[n+1] = ']'
|
|
buf.tmp[n+2] = ' '
|
|
buf.Write(buf.tmp[:n+3])
|
|
return buf
|
|
}
|
|
|
|
// Some custom tiny helper functions to print the log header efficiently.
|
|
|
|
const digits = "0123456789"
|
|
|
|
// twoDigits formats a zero-prefixed two-digit integer at buf.tmp[i].
|
|
func (buf *buffer) twoDigits(i, d int) {
|
|
buf.tmp[i+1] = digits[d%10]
|
|
d /= 10
|
|
buf.tmp[i] = digits[d%10]
|
|
}
|
|
|
|
// nDigits formats an n-digit integer at buf.tmp[i],
|
|
// padding with pad on the left.
|
|
// It assumes d >= 0.
|
|
func (buf *buffer) nDigits(n, i, d int, pad byte) {
|
|
j := n - 1
|
|
for ; j >= 0 && d > 0; j-- {
|
|
buf.tmp[i+j] = digits[d%10]
|
|
d /= 10
|
|
}
|
|
for ; j >= 0; j-- {
|
|
buf.tmp[i+j] = pad
|
|
}
|
|
}
|
|
|
|
// someDigits formats a zero-prefixed variable-width integer at buf.tmp[i].
|
|
func (buf *buffer) someDigits(i, d int) int {
|
|
// Print into the top, then copy down. We know there's space for at least
|
|
// a 10-digit number.
|
|
j := len(buf.tmp)
|
|
for {
|
|
j--
|
|
buf.tmp[j] = digits[d%10]
|
|
d /= 10
|
|
if d == 0 {
|
|
break
|
|
}
|
|
}
|
|
return copy(buf.tmp[i:], buf.tmp[j:])
|
|
}
|
|
|
|
func (l *loggingT) println(s severity, args ...interface{}) {
|
|
buf, file, line := l.header(s, 0)
|
|
fmt.Fprintln(buf, args...)
|
|
l.output(s, buf, file, line, false)
|
|
}
|
|
|
|
func (l *loggingT) print(s severity, args ...interface{}) {
|
|
l.printDepth(s, 1, args...)
|
|
}
|
|
|
|
func (l *loggingT) printDepth(s severity, depth int, args ...interface{}) {
|
|
buf, file, line := l.header(s, depth)
|
|
fmt.Fprint(buf, args...)
|
|
if buf.Bytes()[buf.Len()-1] != '\n' {
|
|
buf.WriteByte('\n')
|
|
}
|
|
l.output(s, buf, file, line, false)
|
|
}
|
|
|
|
func (l *loggingT) printf(s severity, format string, args ...interface{}) {
|
|
buf, file, line := l.header(s, 0)
|
|
fmt.Fprintf(buf, format, args...)
|
|
if buf.Bytes()[buf.Len()-1] != '\n' {
|
|
buf.WriteByte('\n')
|
|
}
|
|
l.output(s, buf, file, line, false)
|
|
}
|
|
|
|
// printWithFileLine behaves like print but uses the provided file and line number. If
|
|
// alsoLogToStderr is true, the log message always appears on standard error; it
|
|
// will also appear in the log file unless --logtostderr is set.
|
|
func (l *loggingT) printWithFileLine(s severity, file string, line int, alsoToStderr bool, args ...interface{}) {
|
|
buf := l.formatHeader(s, file, line)
|
|
fmt.Fprint(buf, args...)
|
|
if buf.Bytes()[buf.Len()-1] != '\n' {
|
|
buf.WriteByte('\n')
|
|
}
|
|
l.output(s, buf, file, line, alsoToStderr)
|
|
}
|
|
|
|
// output writes the data to the log files and releases the buffer.
|
|
func (l *loggingT) output(s severity, buf *buffer, file string, line int, alsoToStderr bool) {
|
|
l.mu.Lock()
|
|
if l.traceLocation.isSet() {
|
|
if l.traceLocation.match(file, line) {
|
|
buf.Write(stacks(false))
|
|
}
|
|
}
|
|
data := buf.Bytes()
|
|
if l.toStderr {
|
|
os.Stderr.Write(data)
|
|
} else {
|
|
if alsoToStderr || l.alsoToStderr || s >= l.stderrThreshold.get() {
|
|
os.Stderr.Write(data)
|
|
}
|
|
if l.file[s] == nil {
|
|
if err := l.createFiles(s); err != nil {
|
|
os.Stderr.Write(data) // Make sure the message appears somewhere.
|
|
l.exit(err)
|
|
}
|
|
}
|
|
switch s {
|
|
case fatalLog:
|
|
l.file[fatalLog].Write(data)
|
|
fallthrough
|
|
case errorLog:
|
|
l.file[errorLog].Write(data)
|
|
fallthrough
|
|
case warningLog:
|
|
l.file[warningLog].Write(data)
|
|
fallthrough
|
|
case infoLog:
|
|
l.file[infoLog].Write(data)
|
|
}
|
|
}
|
|
if s == fatalLog {
|
|
// If we got here via Exit rather than Fatal, print no stacks.
|
|
if atomic.LoadUint32(&fatalNoStacks) > 0 {
|
|
l.mu.Unlock()
|
|
timeoutFlush(10 * time.Second)
|
|
os.Exit(1)
|
|
}
|
|
// Dump all goroutine stacks before exiting.
|
|
// First, make sure we see the trace for the current goroutine on standard error.
|
|
// If -logtostderr has been specified, the loop below will do that anyway
|
|
// as the first stack in the full dump.
|
|
if !l.toStderr {
|
|
os.Stderr.Write(stacks(false))
|
|
}
|
|
// Write the stack trace for all goroutines to the files.
|
|
trace := stacks(true)
|
|
logExitFunc = func(error) {} // If we get a write error, we'll still exit below.
|
|
for log := fatalLog; log >= infoLog; log-- {
|
|
if f := l.file[log]; f != nil { // Can be nil if -logtostderr is set.
|
|
f.Write(trace)
|
|
}
|
|
}
|
|
l.mu.Unlock()
|
|
timeoutFlush(10 * time.Second)
|
|
os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
|
|
}
|
|
l.putBuffer(buf)
|
|
l.mu.Unlock()
|
|
if stats := severityStats[s]; stats != nil {
|
|
atomic.AddInt64(&stats.lines, 1)
|
|
atomic.AddInt64(&stats.bytes, int64(len(data)))
|
|
}
|
|
}
|
|
|
|
// timeoutFlush calls Flush and returns when it completes or after timeout
|
|
// elapses, whichever happens first. This is needed because the hooks invoked
|
|
// by Flush may deadlock when glog.Fatal is called from a hook that holds
|
|
// a lock.
|
|
func timeoutFlush(timeout time.Duration) {
|
|
done := make(chan bool, 1)
|
|
go func() {
|
|
Flush() // calls logging.lockAndFlushAll()
|
|
done <- true
|
|
}()
|
|
select {
|
|
case <-done:
|
|
case <-time.After(timeout):
|
|
fmt.Fprintln(os.Stderr, "glog: Flush took longer than", timeout)
|
|
}
|
|
}
|
|
|
|
// stacks is a wrapper for runtime.Stack that attempts to recover the data for all goroutines.
|
|
func stacks(all bool) []byte {
|
|
// We don't know how big the traces are, so grow a few times if they don't fit. Start large, though.
|
|
n := 10000
|
|
if all {
|
|
n = 100000
|
|
}
|
|
var trace []byte
|
|
for i := 0; i < 5; i++ {
|
|
trace = make([]byte, n)
|
|
nbytes := runtime.Stack(trace, all)
|
|
if nbytes < len(trace) {
|
|
return trace[:nbytes]
|
|
}
|
|
n *= 2
|
|
}
|
|
return trace
|
|
}
|
|
|
|
// logExitFunc provides a simple mechanism to override the default behavior
|
|
// of exiting on error. Used in testing and to guarantee we reach a required exit
|
|
// for fatal logs. Instead, exit could be a function rather than a method but that
|
|
// would make its use clumsier.
|
|
var logExitFunc func(error)
|
|
|
|
// exit is called if there is trouble creating or writing log files.
|
|
// It flushes the logs and exits the program; there's no point in hanging around.
|
|
// l.mu is held.
|
|
func (l *loggingT) exit(err error) {
|
|
fmt.Fprintf(os.Stderr, "glog: exiting because of error: %s\n", err)
|
|
// If logExitFunc is set, we do that instead of exiting.
|
|
if logExitFunc != nil {
|
|
logExitFunc(err)
|
|
return
|
|
}
|
|
l.flushAll()
|
|
l.exited = true // os.Exit(2)
|
|
}
|
|
|
|
// syncBuffer joins a bufio.Writer to its underlying file, providing access to the
|
|
// file's Sync method and providing a wrapper for the Write method that provides log
|
|
// file rotation. There are conflicting methods, so the file cannot be embedded.
|
|
// l.mu is held for all its methods.
|
|
type syncBuffer struct {
|
|
logger *loggingT
|
|
*bufio.Writer
|
|
file *os.File
|
|
sev severity
|
|
nbytes uint64 // The number of bytes written to this file
|
|
}
|
|
|
|
func (sb *syncBuffer) Sync() error {
|
|
return sb.file.Sync()
|
|
}
|
|
|
|
func (sb *syncBuffer) Write(p []byte) (n int, err error) {
|
|
if sb.logger.exited {
|
|
return
|
|
}
|
|
if sb.nbytes+uint64(len(p)) >= MaxSize {
|
|
if err := sb.rotateFile(time.Now()); err != nil {
|
|
sb.logger.exit(err)
|
|
}
|
|
}
|
|
n, err = sb.Writer.Write(p)
|
|
sb.nbytes += uint64(n)
|
|
if err != nil {
|
|
sb.logger.exit(err)
|
|
}
|
|
return
|
|
}
|
|
|
|
// rotateFile closes the syncBuffer's file and starts a new one.
|
|
func (sb *syncBuffer) rotateFile(now time.Time) error {
|
|
if sb.file != nil {
|
|
sb.Flush()
|
|
sb.file.Close()
|
|
}
|
|
var err error
|
|
sb.file, _, err = create(severityName[sb.sev], now)
|
|
sb.nbytes = 0
|
|
if err != nil {
|
|
return err
|
|
}
|
|
|
|
sb.Writer = bufio.NewWriterSize(sb.file, bufferSize)
|
|
|
|
// Write header.
|
|
var buf bytes.Buffer
|
|
fmt.Fprintf(&buf, "Log file created at: %s\n", now.Format("2006/01/02 15:04:05"))
|
|
fmt.Fprintf(&buf, "Running on machine: %s\n", host)
|
|
fmt.Fprintf(&buf, "Binary: Built with %s %s for %s/%s\n", runtime.Compiler, runtime.Version(), runtime.GOOS, runtime.GOARCH)
|
|
fmt.Fprintf(&buf, "Log line format: [IWEF]mmdd hh:mm:ss threadid file:line] msg\n")
|
|
n, err := sb.file.Write(buf.Bytes())
|
|
sb.nbytes += uint64(n)
|
|
return err
|
|
}
|
|
|
|
// bufferSize sizes the buffer associated with each log file. It's large
|
|
// so that log records can accumulate without the logging thread blocking
|
|
// on disk I/O. The flushDaemon will block instead.
|
|
const bufferSize = 256 * 1024
|
|
|
|
// createFiles creates all the log files for severity from sev down to infoLog.
|
|
// l.mu is held.
|
|
func (l *loggingT) createFiles(sev severity) error {
|
|
now := time.Now()
|
|
// Files are created in decreasing severity order, so as soon as we find one
|
|
// has already been created, we can stop.
|
|
for s := sev; s >= infoLog && l.file[s] == nil; s-- {
|
|
sb := &syncBuffer{
|
|
logger: l,
|
|
sev: s,
|
|
}
|
|
if err := sb.rotateFile(now); err != nil {
|
|
return err
|
|
}
|
|
l.file[s] = sb
|
|
}
|
|
return nil
|
|
}
|
|
|
|
const flushInterval = 30 * time.Second
|
|
|
|
// flushDaemon periodically flushes the log file buffers.
|
|
func (l *loggingT) flushDaemon() {
|
|
for _ = range time.NewTicker(flushInterval).C {
|
|
l.lockAndFlushAll()
|
|
}
|
|
}
|
|
|
|
// lockAndFlushAll is like flushAll but locks l.mu first.
|
|
func (l *loggingT) lockAndFlushAll() {
|
|
l.mu.Lock()
|
|
l.flushAll()
|
|
l.mu.Unlock()
|
|
}
|
|
|
|
// flushAll flushes all the logs and attempts to "sync" their data to disk.
|
|
// l.mu is held.
|
|
func (l *loggingT) flushAll() {
|
|
// Flush from fatal down, in case there's trouble flushing.
|
|
for s := fatalLog; s >= infoLog; s-- {
|
|
file := l.file[s]
|
|
if file != nil {
|
|
file.Flush() // ignore error
|
|
file.Sync() // ignore error
|
|
}
|
|
}
|
|
}
|
|
|
|
// CopyStandardLogTo arranges for messages written to the Go "log" package's
|
|
// default logs to also appear in the Google logs for the named and lower
|
|
// severities. Subsequent changes to the standard log's default output location
|
|
// or format may break this behavior.
|
|
//
|
|
// Valid names are "INFO", "WARNING", "ERROR", and "FATAL". If the name is not
|
|
// recognized, CopyStandardLogTo panics.
|
|
func CopyStandardLogTo(name string) {
|
|
sev, ok := severityByName(name)
|
|
if !ok {
|
|
panic(fmt.Sprintf("log.CopyStandardLogTo(%q): unrecognized severity name", name))
|
|
}
|
|
// Set a log format that captures the user's file and line:
|
|
// d.go:23: message
|
|
stdLog.SetFlags(stdLog.Lshortfile)
|
|
stdLog.SetOutput(logBridge(sev))
|
|
}
|
|
|
|
// logBridge provides the Write method that enables CopyStandardLogTo to connect
|
|
// Go's standard logs to the logs provided by this package.
|
|
type logBridge severity
|
|
|
|
// Write parses the standard logging line and passes its components to the
|
|
// logger for severity(lb).
|
|
func (lb logBridge) Write(b []byte) (n int, err error) {
|
|
var (
|
|
file = "???"
|
|
line = 1
|
|
text string
|
|
)
|
|
// Split "d.go:23: message" into "d.go", "23", and "message".
|
|
if parts := bytes.SplitN(b, []byte{':'}, 3); len(parts) != 3 || len(parts[0]) < 1 || len(parts[2]) < 1 {
|
|
text = fmt.Sprintf("bad log format: %s", b)
|
|
} else {
|
|
file = string(parts[0])
|
|
text = string(parts[2][1:]) // skip leading space
|
|
line, err = strconv.Atoi(string(parts[1]))
|
|
if err != nil {
|
|
text = fmt.Sprintf("bad line number: %s", b)
|
|
line = 1
|
|
}
|
|
}
|
|
// printWithFileLine with alsoToStderr=true, so standard log messages
|
|
// always appear on standard error.
|
|
logging.printWithFileLine(severity(lb), file, line, true, text)
|
|
return len(b), nil
|
|
}
|
|
|
|
// setV computes and remembers the V level for a given PC
|
|
// when vmodule is enabled.
|
|
// File pattern matching takes the basename of the file, stripped
|
|
// of its .go suffix, and uses filepath.Match, which is a little more
|
|
// general than the *? matching used in C++.
|
|
// l.mu is held.
|
|
func (l *loggingT) setV(pc uintptr) Level {
|
|
fn := runtime.FuncForPC(pc)
|
|
file, _ := fn.FileLine(pc)
|
|
// The file is something like /a/b/c/d.go. We want just the d.
|
|
if strings.HasSuffix(file, ".go") {
|
|
file = file[:len(file)-3]
|
|
}
|
|
if slash := strings.LastIndex(file, "/"); slash >= 0 {
|
|
file = file[slash+1:]
|
|
}
|
|
for _, filter := range l.vmodule.filter {
|
|
if filter.match(file) {
|
|
l.vmap[pc] = filter.level
|
|
return filter.level
|
|
}
|
|
}
|
|
l.vmap[pc] = 0
|
|
return 0
|
|
}
|
|
|
|
// Verbose is a boolean type that implements Infof (like Printf) etc.
|
|
// See the documentation of V for more information.
|
|
type Verbose bool
|
|
|
|
// V reports whether verbosity at the call site is at least the requested level.
|
|
// The returned value is a boolean of type Verbose, which implements Info, Infoln
|
|
// and Infof. These methods will write to the Info log if called.
|
|
// Thus, one may write either
|
|
// if glog.V(2) { glog.Info("log this") }
|
|
// or
|
|
// glog.V(2).Info("log this")
|
|
// The second form is shorter but the first is cheaper if logging is off because it does
|
|
// not evaluate its arguments.
|
|
//
|
|
// Whether an individual call to V generates a log record depends on the setting of
|
|
// the -v and --vmodule flags; both are off by default. If the level in the call to
|
|
// V is at least the value of -v, or of -vmodule for the source file containing the
|
|
// call, the V call will log.
|
|
func V(level Level) Verbose {
|
|
// This function tries hard to be cheap unless there's work to do.
|
|
// The fast path is two atomic loads and compares.
|
|
|
|
// Here is a cheap but safe test to see if V logging is enabled globally.
|
|
if logging.verbosity.get() >= level {
|
|
return Verbose(true)
|
|
}
|
|
|
|
// It's off globally but it vmodule may still be set.
|
|
// Here is another cheap but safe test to see if vmodule is enabled.
|
|
if atomic.LoadInt32(&logging.filterLength) > 0 {
|
|
// Now we need a proper lock to use the logging structure. The pcs field
|
|
// is shared so we must lock before accessing it. This is fairly expensive,
|
|
// but if V logging is enabled we're slow anyway.
|
|
logging.mu.Lock()
|
|
defer logging.mu.Unlock()
|
|
if runtime.Callers(2, logging.pcs[:]) == 0 {
|
|
return Verbose(false)
|
|
}
|
|
v, ok := logging.vmap[logging.pcs[0]]
|
|
if !ok {
|
|
v = logging.setV(logging.pcs[0])
|
|
}
|
|
return Verbose(v >= level)
|
|
}
|
|
return Verbose(false)
|
|
}
|
|
|
|
// Info is equivalent to the global Info function, guarded by the value of v.
|
|
// See the documentation of V for usage.
|
|
func (v Verbose) Info(args ...interface{}) {
|
|
if v {
|
|
logging.print(infoLog, args...)
|
|
}
|
|
}
|
|
|
|
// Infoln is equivalent to the global Infoln function, guarded by the value of v.
|
|
// See the documentation of V for usage.
|
|
func (v Verbose) Infoln(args ...interface{}) {
|
|
if v {
|
|
logging.println(infoLog, args...)
|
|
}
|
|
}
|
|
|
|
// Infof is equivalent to the global Infof function, guarded by the value of v.
|
|
// See the documentation of V for usage.
|
|
func (v Verbose) Infof(format string, args ...interface{}) {
|
|
if v {
|
|
logging.printf(infoLog, format, args...)
|
|
}
|
|
}
|
|
|
|
// Info logs to the INFO log.
|
|
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
|
|
func Info(args ...interface{}) {
|
|
logging.print(infoLog, args...)
|
|
}
|
|
|
|
// InfoDepth acts as Info but uses depth to determine which call frame to log.
|
|
// InfoDepth(0, "msg") is the same as Info("msg").
|
|
func InfoDepth(depth int, args ...interface{}) {
|
|
logging.printDepth(infoLog, depth, args...)
|
|
}
|
|
|
|
// Infoln logs to the INFO log.
|
|
// Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
|
|
func Infoln(args ...interface{}) {
|
|
logging.println(infoLog, args...)
|
|
}
|
|
|
|
// Infof logs to the INFO log.
|
|
// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
|
|
func Infof(format string, args ...interface{}) {
|
|
logging.printf(infoLog, format, args...)
|
|
}
|
|
|
|
// Warning logs to the WARNING and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
|
|
func Warning(args ...interface{}) {
|
|
logging.print(warningLog, args...)
|
|
}
|
|
|
|
// WarningDepth acts as Warning but uses depth to determine which call frame to log.
|
|
// WarningDepth(0, "msg") is the same as Warning("msg").
|
|
func WarningDepth(depth int, args ...interface{}) {
|
|
logging.printDepth(warningLog, depth, args...)
|
|
}
|
|
|
|
// Warningln logs to the WARNING and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
|
|
func Warningln(args ...interface{}) {
|
|
logging.println(warningLog, args...)
|
|
}
|
|
|
|
// Warningf logs to the WARNING and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
|
|
func Warningf(format string, args ...interface{}) {
|
|
logging.printf(warningLog, format, args...)
|
|
}
|
|
|
|
// Error logs to the ERROR, WARNING, and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
|
|
func Error(args ...interface{}) {
|
|
logging.print(errorLog, args...)
|
|
}
|
|
|
|
// ErrorDepth acts as Error but uses depth to determine which call frame to log.
|
|
// ErrorDepth(0, "msg") is the same as Error("msg").
|
|
func ErrorDepth(depth int, args ...interface{}) {
|
|
logging.printDepth(errorLog, depth, args...)
|
|
}
|
|
|
|
// Errorln logs to the ERROR, WARNING, and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
|
|
func Errorln(args ...interface{}) {
|
|
logging.println(errorLog, args...)
|
|
}
|
|
|
|
// Errorf logs to the ERROR, WARNING, and INFO logs.
|
|
// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
|
|
func Errorf(format string, args ...interface{}) {
|
|
logging.printf(errorLog, format, args...)
|
|
}
|
|
|
|
// Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,
|
|
// including a stack trace of all running goroutines, then calls os.Exit(255).
|
|
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
|
|
func Fatal(args ...interface{}) {
|
|
logging.print(fatalLog, args...)
|
|
}
|
|
|
|
// FatalDepth acts as Fatal but uses depth to determine which call frame to log.
|
|
// FatalDepth(0, "msg") is the same as Fatal("msg").
|
|
func FatalDepth(depth int, args ...interface{}) {
|
|
logging.printDepth(fatalLog, depth, args...)
|
|
}
|
|
|
|
// Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs,
|
|
// including a stack trace of all running goroutines, then calls os.Exit(255).
|
|
// Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
|
|
func Fatalln(args ...interface{}) {
|
|
logging.println(fatalLog, args...)
|
|
}
|
|
|
|
// Fatalf logs to the FATAL, ERROR, WARNING, and INFO logs,
|
|
// including a stack trace of all running goroutines, then calls os.Exit(255).
|
|
// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
|
|
func Fatalf(format string, args ...interface{}) {
|
|
logging.printf(fatalLog, format, args...)
|
|
}
|
|
|
|
// fatalNoStacks is non-zero if we are to exit without dumping goroutine stacks.
|
|
// It allows Exit and relatives to use the Fatal logs.
|
|
var fatalNoStacks uint32
|
|
|
|
// Exit logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
|
|
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
|
|
func Exit(args ...interface{}) {
|
|
atomic.StoreUint32(&fatalNoStacks, 1)
|
|
logging.print(fatalLog, args...)
|
|
}
|
|
|
|
// ExitDepth acts as Exit but uses depth to determine which call frame to log.
|
|
// ExitDepth(0, "msg") is the same as Exit("msg").
|
|
func ExitDepth(depth int, args ...interface{}) {
|
|
atomic.StoreUint32(&fatalNoStacks, 1)
|
|
logging.printDepth(fatalLog, depth, args...)
|
|
}
|
|
|
|
// Exitln logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
|
|
func Exitln(args ...interface{}) {
|
|
atomic.StoreUint32(&fatalNoStacks, 1)
|
|
logging.println(fatalLog, args...)
|
|
}
|
|
|
|
// Exitf logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
|
|
// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
|
|
func Exitf(format string, args ...interface{}) {
|
|
atomic.StoreUint32(&fatalNoStacks, 1)
|
|
logging.printf(fatalLog, format, args...)
|
|
}
|