github.com/minio/minio@v0.0.0-20240328213742-3f72439b8a27/internal/logger/logger.go (about)

     1  // Copyright (c) 2015-2021 MinIO, Inc.
     2  //
     3  // This file is part of MinIO Object Storage stack
     4  //
     5  // This program is free software: you can redistribute it and/or modify
     6  // it under the terms of the GNU Affero General Public License as published by
     7  // the Free Software Foundation, either version 3 of the License, or
     8  // (at your option) any later version.
     9  //
    10  // This program is distributed in the hope that it will be useful
    11  // but WITHOUT ANY WARRANTY; without even the implied warranty of
    12  // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
    13  // GNU Affero General Public License for more details.
    14  //
    15  // You should have received a copy of the GNU Affero General Public License
    16  // along with this program.  If not, see <http://www.gnu.org/licenses/>.
    17  
    18  package logger
    19  
    20  import (
    21  	"context"
    22  	"encoding/hex"
    23  	"errors"
    24  	"fmt"
    25  	"go/build"
    26  	"path/filepath"
    27  	"reflect"
    28  	"runtime"
    29  	"sort"
    30  	"strings"
    31  	"time"
    32  
    33  	"github.com/minio/highwayhash"
    34  	"github.com/minio/madmin-go/v3"
    35  	xhttp "github.com/minio/minio/internal/http"
    36  	"github.com/minio/pkg/v2/logger/message/log"
    37  )
    38  
    39  // HighwayHash key for logging in anonymous mode
    40  var magicHighwayHash256Key = []byte("\x4b\xe7\x34\xfa\x8e\x23\x8a\xcd\x26\x3e\x83\xe6\xbb\x96\x85\x52\x04\x0f\x93\x5d\xa3\x9f\x44\x14\x97\xe0\x9d\x13\x22\xde\x36\xa0")
    41  
    42  // Enumerated level types
    43  const (
    44  	// Log types errors
    45  	FatalKind   = madmin.LogKindFatal
    46  	WarningKind = madmin.LogKindWarning
    47  	ErrorKind   = madmin.LogKindError
    48  	EventKind   = madmin.LogKindEvent
    49  	InfoKind    = madmin.LogKindInfo
    50  )
    51  
    52  // DisableErrorLog avoids printing error/event/info kind of logs
    53  var DisableErrorLog = false
    54  
    55  var trimStrings []string
    56  
    57  // TimeFormat - logging time format.
    58  const TimeFormat string = "15:04:05 MST 01/02/2006"
    59  
    60  var matchingFuncNames = [...]string{
    61  	"http.HandlerFunc.ServeHTTP",
    62  	"cmd.serverMain",
    63  	// add more here ..
    64  }
    65  
    66  // quietFlag: Hide startup messages if enabled
    67  // jsonFlag: Display in JSON format, if enabled
    68  var (
    69  	quietFlag, jsonFlag, anonFlag bool
    70  	// Custom function to format error
    71  	errorFmtFunc func(string, error, bool) string
    72  )
    73  
    74  // EnableQuiet - turns quiet option on.
    75  func EnableQuiet() {
    76  	quietFlag = true
    77  }
    78  
    79  // EnableJSON - outputs logs in json format.
    80  func EnableJSON() {
    81  	jsonFlag = true
    82  	quietFlag = true
    83  }
    84  
    85  // EnableAnonymous - turns anonymous flag
    86  // to avoid printing sensitive information.
    87  func EnableAnonymous() {
    88  	anonFlag = true
    89  }
    90  
    91  // IsJSON - returns true if jsonFlag is true
    92  func IsJSON() bool {
    93  	return jsonFlag
    94  }
    95  
    96  // IsQuiet - returns true if quietFlag is true
    97  func IsQuiet() bool {
    98  	return quietFlag
    99  }
   100  
   101  // RegisterError registers the specified rendering function. This latter
   102  // will be called for a pretty rendering of fatal errors.
   103  func RegisterError(f func(string, error, bool) string) {
   104  	errorFmtFunc = f
   105  }
   106  
   107  // uniq swaps away duplicate elements in data, returning the size of the
   108  // unique set. data is expected to be pre-sorted, and the resulting set in
   109  // the range [0:size] will remain in sorted order. Uniq, following a
   110  // sort.Sort call, can be used to prepare arbitrary inputs for use as sets.
   111  func uniq(data sort.Interface) (size int) {
   112  	p, l := 0, data.Len()
   113  	if l <= 1 {
   114  		return l
   115  	}
   116  	for i := 1; i < l; i++ {
   117  		if !data.Less(p, i) {
   118  			continue
   119  		}
   120  		p++
   121  		if p < i {
   122  			data.Swap(p, i)
   123  		}
   124  	}
   125  	return p + 1
   126  }
   127  
   128  // Remove any duplicates and return unique entries.
   129  func uniqueEntries(paths []string) []string {
   130  	sort.Strings(paths)
   131  	n := uniq(sort.StringSlice(paths))
   132  	return paths[:n]
   133  }
   134  
   135  // Init sets the trimStrings to possible GOPATHs
   136  // and GOROOT directories. Also append github.com/minio/minio
   137  // This is done to clean up the filename, when stack trace is
   138  // displayed when an error happens.
   139  func Init(goPath string, goRoot string) {
   140  	var goPathList []string
   141  	var goRootList []string
   142  	var defaultgoPathList []string
   143  	var defaultgoRootList []string
   144  	pathSeparator := ":"
   145  	// Add all possible GOPATH paths into trimStrings
   146  	// Split GOPATH depending on the OS type
   147  	if runtime.GOOS == "windows" {
   148  		pathSeparator = ";"
   149  	}
   150  
   151  	goPathList = strings.Split(goPath, pathSeparator)
   152  	goRootList = strings.Split(goRoot, pathSeparator)
   153  	defaultgoPathList = strings.Split(build.Default.GOPATH, pathSeparator)
   154  	defaultgoRootList = strings.Split(build.Default.GOROOT, pathSeparator)
   155  
   156  	// Add trim string "{GOROOT}/src/" into trimStrings
   157  	trimStrings = []string{filepath.Join(runtime.GOROOT(), "src") + string(filepath.Separator)}
   158  
   159  	// Add all possible path from GOPATH=path1:path2...:pathN
   160  	// as "{path#}/src/" into trimStrings
   161  	for _, goPathString := range goPathList {
   162  		trimStrings = append(trimStrings, filepath.Join(goPathString, "src")+string(filepath.Separator))
   163  	}
   164  
   165  	for _, goRootString := range goRootList {
   166  		trimStrings = append(trimStrings, filepath.Join(goRootString, "src")+string(filepath.Separator))
   167  	}
   168  
   169  	for _, defaultgoPathString := range defaultgoPathList {
   170  		trimStrings = append(trimStrings, filepath.Join(defaultgoPathString, "src")+string(filepath.Separator))
   171  	}
   172  
   173  	for _, defaultgoRootString := range defaultgoRootList {
   174  		trimStrings = append(trimStrings, filepath.Join(defaultgoRootString, "src")+string(filepath.Separator))
   175  	}
   176  
   177  	// Remove duplicate entries.
   178  	trimStrings = uniqueEntries(trimStrings)
   179  
   180  	// Add "github.com/minio/minio" as the last to cover
   181  	// paths like "{GOROOT}/src/github.com/minio/minio"
   182  	// and "{GOPATH}/src/github.com/minio/minio"
   183  	trimStrings = append(trimStrings, filepath.Join("github.com", "minio", "minio")+string(filepath.Separator))
   184  }
   185  
   186  func trimTrace(f string) string {
   187  	for _, trimString := range trimStrings {
   188  		f = strings.TrimPrefix(filepath.ToSlash(f), filepath.ToSlash(trimString))
   189  	}
   190  	return filepath.FromSlash(f)
   191  }
   192  
   193  func getSource(level int) string {
   194  	pc, file, lineNumber, ok := runtime.Caller(level)
   195  	if ok {
   196  		// Clean up the common prefixes
   197  		file = trimTrace(file)
   198  		_, funcName := filepath.Split(runtime.FuncForPC(pc).Name())
   199  		return fmt.Sprintf("%v:%v:%v()", file, lineNumber, funcName)
   200  	}
   201  	return ""
   202  }
   203  
   204  // getTrace method - creates and returns stack trace
   205  func getTrace(traceLevel int) []string {
   206  	var trace []string
   207  	pc, file, lineNumber, ok := runtime.Caller(traceLevel)
   208  
   209  	for ok && file != "" {
   210  		// Clean up the common prefixes
   211  		file = trimTrace(file)
   212  		// Get the function name
   213  		_, funcName := filepath.Split(runtime.FuncForPC(pc).Name())
   214  		// Skip duplicate traces that start with file name, "<autogenerated>"
   215  		// and also skip traces with function name that starts with "runtime."
   216  		if !strings.HasPrefix(file, "<autogenerated>") &&
   217  			!strings.HasPrefix(funcName, "runtime.") {
   218  			// Form and append a line of stack trace into a
   219  			// collection, 'trace', to build full stack trace
   220  			trace = append(trace, fmt.Sprintf("%v:%v:%v()", file, lineNumber, funcName))
   221  
   222  			// Ignore trace logs beyond the following conditions
   223  			for _, name := range matchingFuncNames {
   224  				if funcName == name {
   225  					return trace
   226  				}
   227  			}
   228  		}
   229  		traceLevel++
   230  		// Read stack trace information from PC
   231  		pc, file, lineNumber, ok = runtime.Caller(traceLevel)
   232  	}
   233  	return trace
   234  }
   235  
   236  // HashString - return the highway hash of the passed string
   237  func HashString(input string) string {
   238  	hh, _ := highwayhash.New(magicHighwayHash256Key)
   239  	hh.Write([]byte(input))
   240  	return hex.EncodeToString(hh.Sum(nil))
   241  }
   242  
   243  // LogAlwaysIf prints a detailed error message during
   244  // the execution of the server.
   245  func LogAlwaysIf(ctx context.Context, err error, errKind ...interface{}) {
   246  	if err == nil {
   247  		return
   248  	}
   249  
   250  	logIf(ctx, err, errKind...)
   251  }
   252  
   253  // LogIf prints a detailed error message during
   254  // the execution of the server, if it is not an
   255  // ignored error.
   256  func LogIf(ctx context.Context, err error, errKind ...interface{}) {
   257  	if logIgnoreError(err) {
   258  		return
   259  	}
   260  	logIf(ctx, err, errKind...)
   261  }
   262  
   263  // LogIfNot prints a detailed error message during
   264  // the execution of the server, if it is not an ignored error (either internal or given).
   265  func LogIfNot(ctx context.Context, err error, ignored ...error) {
   266  	if logIgnoreError(err) {
   267  		return
   268  	}
   269  	for _, ignore := range ignored {
   270  		if errors.Is(err, ignore) {
   271  			return
   272  		}
   273  	}
   274  	logIf(ctx, err)
   275  }
   276  
   277  func errToEntry(ctx context.Context, err error, errKind ...interface{}) log.Entry {
   278  	var l string
   279  	if anonFlag {
   280  		l = reflect.TypeOf(err).String()
   281  	} else {
   282  		l = fmt.Sprintf("%v (%T)", err, err)
   283  	}
   284  	return buildLogEntry(ctx, l, getTrace(3), errKind...)
   285  }
   286  
   287  func logToEntry(ctx context.Context, message string, errKind ...interface{}) log.Entry {
   288  	return buildLogEntry(ctx, message, nil, errKind...)
   289  }
   290  
   291  func buildLogEntry(ctx context.Context, message string, trace []string, errKind ...interface{}) log.Entry {
   292  	logKind := madmin.LogKindError
   293  	if len(errKind) > 0 {
   294  		if ek, ok := errKind[0].(madmin.LogKind); ok {
   295  			logKind = ek
   296  		}
   297  	}
   298  
   299  	req := GetReqInfo(ctx)
   300  	if req == nil {
   301  		req = &ReqInfo{
   302  			API:       "SYSTEM",
   303  			RequestID: fmt.Sprintf("%X", time.Now().UTC().UnixNano()),
   304  		}
   305  	}
   306  	req.RLock()
   307  	defer req.RUnlock()
   308  
   309  	API := "SYSTEM"
   310  	if req.API != "" {
   311  		API = req.API
   312  	}
   313  
   314  	// Copy tags. We hold read lock already.
   315  	tags := make(map[string]interface{}, len(req.tags))
   316  	for _, entry := range req.tags {
   317  		tags[entry.Key] = entry.Val
   318  	}
   319  
   320  	// Get the cause for the Error
   321  	deploymentID := req.DeploymentID
   322  	if req.DeploymentID == "" {
   323  		deploymentID = xhttp.GlobalDeploymentID
   324  	}
   325  
   326  	objects := make([]log.ObjectVersion, 0, len(req.Objects))
   327  	for _, ov := range req.Objects {
   328  		objects = append(objects, log.ObjectVersion{
   329  			ObjectName: ov.ObjectName,
   330  			VersionID:  ov.VersionID,
   331  		})
   332  	}
   333  
   334  	entry := log.Entry{
   335  		DeploymentID: deploymentID,
   336  		Level:        logKind,
   337  		RemoteHost:   req.RemoteHost,
   338  		Host:         req.Host,
   339  		RequestID:    req.RequestID,
   340  		UserAgent:    req.UserAgent,
   341  		Time:         time.Now().UTC(),
   342  		API: &log.API{
   343  			Name: API,
   344  			Args: &log.Args{
   345  				Bucket:    req.BucketName,
   346  				Object:    req.ObjectName,
   347  				VersionID: req.VersionID,
   348  				Objects:   objects,
   349  			},
   350  		},
   351  	}
   352  
   353  	if trace != nil {
   354  		entry.Trace = &log.Trace{
   355  			Message:   message,
   356  			Source:    trace,
   357  			Variables: tags,
   358  		}
   359  	} else {
   360  		entry.Message = message
   361  	}
   362  
   363  	if anonFlag {
   364  		entry.API.Args.Bucket = HashString(entry.API.Args.Bucket)
   365  		entry.API.Args.Object = HashString(entry.API.Args.Object)
   366  		entry.RemoteHost = HashString(entry.RemoteHost)
   367  		if entry.Trace != nil {
   368  			entry.Trace.Variables = make(map[string]interface{})
   369  		}
   370  	}
   371  
   372  	return entry
   373  }
   374  
   375  // consoleLogIf prints a detailed error message during
   376  // the execution of the server.
   377  func consoleLogIf(ctx context.Context, err error, errKind ...interface{}) {
   378  	if DisableErrorLog {
   379  		return
   380  	}
   381  	if err == nil {
   382  		return
   383  	}
   384  	if consoleTgt != nil {
   385  		consoleTgt.Send(ctx, errToEntry(ctx, err, errKind...))
   386  	}
   387  }
   388  
   389  // logIf prints a detailed error message during
   390  // the execution of the server.
   391  func logIf(ctx context.Context, err error, errKind ...interface{}) {
   392  	if DisableErrorLog {
   393  		return
   394  	}
   395  	if err == nil {
   396  		return
   397  	}
   398  	entry := errToEntry(ctx, err, errKind...)
   399  	sendLog(ctx, entry)
   400  }
   401  
   402  func sendLog(ctx context.Context, entry log.Entry) {
   403  	systemTgts := SystemTargets()
   404  	if len(systemTgts) == 0 {
   405  		return
   406  	}
   407  
   408  	// Iterate over all logger targets to send the log entry
   409  	for _, t := range systemTgts {
   410  		if err := t.Send(ctx, entry); err != nil {
   411  			if consoleTgt != nil { // Sending to the console never fails
   412  				entry.Trace.Message = fmt.Sprintf("event(%#v) was not sent to Logger target (%#v): %#v", entry, t, err)
   413  				consoleTgt.Send(ctx, entry)
   414  			}
   415  		}
   416  	}
   417  }
   418  
   419  // Event sends a event log to  log targets
   420  func Event(ctx context.Context, msg string, args ...interface{}) {
   421  	if DisableErrorLog {
   422  		return
   423  	}
   424  	entry := logToEntry(ctx, fmt.Sprintf(msg, args...), EventKind)
   425  	sendLog(ctx, entry)
   426  }
   427  
   428  // ErrCritical is the value panic'd whenever CriticalIf is called.
   429  var ErrCritical struct{}
   430  
   431  // CriticalIf logs the provided error on the console. It fails the
   432  // current go-routine by causing a `panic(ErrCritical)`.
   433  func CriticalIf(ctx context.Context, err error, errKind ...interface{}) {
   434  	if err != nil {
   435  		LogIf(ctx, err, errKind...)
   436  		panic(ErrCritical)
   437  	}
   438  }
   439  
   440  // FatalIf is similar to Fatal() but it ignores passed nil error
   441  func FatalIf(err error, msg string, data ...interface{}) {
   442  	if err == nil {
   443  		return
   444  	}
   445  	fatal(err, msg, data...)
   446  }