github.com/safing/portbase@v0.19.5/log/trace.go (about)

     1  package log
     2  
     3  import (
     4  	"context"
     5  	"fmt"
     6  	"runtime"
     7  	"strings"
     8  	"sync"
     9  	"sync/atomic"
    10  	"time"
    11  )
    12  
    13  // ContextTracerKey is the key used for the context key/value storage.
    14  type ContextTracerKey struct{}
    15  
    16  // ContextTracer is attached to a context in order bind logs to a context.
    17  type ContextTracer struct {
    18  	sync.Mutex
    19  	logs []*logLine
    20  }
    21  
    22  var key = ContextTracerKey{}
    23  
    24  // AddTracer adds a ContextTracer to the returned Context. Will return a nil ContextTracer if logging level is not set to trace. Will return a nil ContextTracer if one already exists. Will return a nil ContextTracer in case of an error. Will return a nil context if nil.
    25  func AddTracer(ctx context.Context) (context.Context, *ContextTracer) {
    26  	if ctx != nil && fastcheck(TraceLevel) {
    27  		// check pkg levels
    28  		if pkgLevelsActive.IsSet() {
    29  			// get file
    30  			_, file, _, ok := runtime.Caller(1)
    31  			if !ok {
    32  				// cannot get file, ignore
    33  				return ctx, nil
    34  			}
    35  
    36  			pathSegments := strings.Split(file, "/")
    37  			if len(pathSegments) < 2 {
    38  				// file too short for package levels
    39  				return ctx, nil
    40  			}
    41  			pkgLevelsLock.Lock()
    42  			severity, ok := pkgLevels[pathSegments[len(pathSegments)-2]]
    43  			pkgLevelsLock.Unlock()
    44  			if ok {
    45  				// check against package level
    46  				if TraceLevel < severity {
    47  					return ctx, nil
    48  				}
    49  			} else {
    50  				// no package level set, check against global level
    51  				if uint32(TraceLevel) < atomic.LoadUint32(logLevel) {
    52  					return ctx, nil
    53  				}
    54  			}
    55  		} else if uint32(TraceLevel) < atomic.LoadUint32(logLevel) {
    56  			// no package levels set, check against global level
    57  			return ctx, nil
    58  		}
    59  
    60  		// check for existing tracer
    61  		_, ok := ctx.Value(key).(*ContextTracer)
    62  		if !ok {
    63  			// add and return new tracer
    64  			tracer := &ContextTracer{}
    65  			return context.WithValue(ctx, key, tracer), tracer
    66  		}
    67  	}
    68  	return ctx, nil
    69  }
    70  
    71  // Tracer returns the ContextTracer previously added to the given Context.
    72  func Tracer(ctx context.Context) *ContextTracer {
    73  	if ctx != nil {
    74  		tracer, ok := ctx.Value(key).(*ContextTracer)
    75  		if ok {
    76  			return tracer
    77  		}
    78  	}
    79  	return nil
    80  }
    81  
    82  // Submit collected logs on the context for further processing/outputting. Does nothing if called on a nil ContextTracer.
    83  func (tracer *ContextTracer) Submit() {
    84  	if tracer == nil {
    85  		return
    86  	}
    87  
    88  	if !started.IsSet() {
    89  		// a bit resource intense, but keeps logs before logging started.
    90  		// TODO: create option to disable logging
    91  		go func() {
    92  			<-startedSignal
    93  			tracer.Submit()
    94  		}()
    95  		return
    96  	}
    97  
    98  	if len(tracer.logs) == 0 {
    99  		return
   100  	}
   101  
   102  	// extract last line as main line
   103  	mainLine := tracer.logs[len(tracer.logs)-1]
   104  	tracer.logs = tracer.logs[:len(tracer.logs)-1]
   105  
   106  	// create log object
   107  	log := &logLine{
   108  		msg:       mainLine.msg,
   109  		tracer:    tracer,
   110  		level:     mainLine.level,
   111  		timestamp: mainLine.timestamp,
   112  		file:      mainLine.file,
   113  		line:      mainLine.line,
   114  	}
   115  
   116  	// send log to processing
   117  	select {
   118  	case logBuffer <- log:
   119  	default:
   120  	forceEmptyingLoop:
   121  		// force empty buffer until we can send to it
   122  		for {
   123  			select {
   124  			case forceEmptyingOfBuffer <- struct{}{}:
   125  			case logBuffer <- log:
   126  				break forceEmptyingLoop
   127  			}
   128  		}
   129  	}
   130  
   131  	// wake up writer if necessary
   132  	if logsWaitingFlag.SetToIf(false, true) {
   133  		logsWaiting <- struct{}{}
   134  	}
   135  }
   136  
   137  func (tracer *ContextTracer) log(level Severity, msg string) {
   138  	// get file and line
   139  	_, file, line, ok := runtime.Caller(2)
   140  	if !ok {
   141  		file = ""
   142  		line = 0
   143  	} else {
   144  		if len(file) > 3 {
   145  			file = file[:len(file)-3]
   146  		} else {
   147  			file = ""
   148  		}
   149  	}
   150  
   151  	tracer.Lock()
   152  	defer tracer.Unlock()
   153  	tracer.logs = append(tracer.logs, &logLine{
   154  		timestamp: time.Now(),
   155  		level:     level,
   156  		msg:       msg,
   157  		file:      file,
   158  		line:      line,
   159  	})
   160  }
   161  
   162  // Trace is used to log tiny steps. Log traces to context if you can!
   163  func (tracer *ContextTracer) Trace(msg string) {
   164  	switch {
   165  	case tracer != nil:
   166  		tracer.log(TraceLevel, msg)
   167  	case fastcheck(TraceLevel):
   168  		log(TraceLevel, msg, nil)
   169  	}
   170  }
   171  
   172  // Tracef is used to log tiny steps. Log traces to context if you can!
   173  func (tracer *ContextTracer) Tracef(format string, things ...interface{}) {
   174  	switch {
   175  	case tracer != nil:
   176  		tracer.log(TraceLevel, fmt.Sprintf(format, things...))
   177  	case fastcheck(TraceLevel):
   178  		log(TraceLevel, fmt.Sprintf(format, things...), nil)
   179  	}
   180  }
   181  
   182  // Debug is used to log minor errors or unexpected events. These occurrences are usually not worth mentioning in itself, but they might hint at a bigger problem.
   183  func (tracer *ContextTracer) Debug(msg string) {
   184  	switch {
   185  	case tracer != nil:
   186  		tracer.log(DebugLevel, msg)
   187  	case fastcheck(DebugLevel):
   188  		log(DebugLevel, msg, nil)
   189  	}
   190  }
   191  
   192  // Debugf is used to log minor errors or unexpected events. These occurrences are usually not worth mentioning in itself, but they might hint at a bigger problem.
   193  func (tracer *ContextTracer) Debugf(format string, things ...interface{}) {
   194  	switch {
   195  	case tracer != nil:
   196  		tracer.log(DebugLevel, fmt.Sprintf(format, things...))
   197  	case fastcheck(DebugLevel):
   198  		log(DebugLevel, fmt.Sprintf(format, things...), nil)
   199  	}
   200  }
   201  
   202  // Info is used to log mildly significant events. Should be used to inform about somewhat bigger or user affecting events that happen.
   203  func (tracer *ContextTracer) Info(msg string) {
   204  	switch {
   205  	case tracer != nil:
   206  		tracer.log(InfoLevel, msg)
   207  	case fastcheck(InfoLevel):
   208  		log(InfoLevel, msg, nil)
   209  	}
   210  }
   211  
   212  // Infof is used to log mildly significant events. Should be used to inform about somewhat bigger or user affecting events that happen.
   213  func (tracer *ContextTracer) Infof(format string, things ...interface{}) {
   214  	switch {
   215  	case tracer != nil:
   216  		tracer.log(InfoLevel, fmt.Sprintf(format, things...))
   217  	case fastcheck(InfoLevel):
   218  		log(InfoLevel, fmt.Sprintf(format, things...), nil)
   219  	}
   220  }
   221  
   222  // Warning is used to log (potentially) bad events, but nothing broke (even a little) and there is no need to panic yet.
   223  func (tracer *ContextTracer) Warning(msg string) {
   224  	switch {
   225  	case tracer != nil:
   226  		tracer.log(WarningLevel, msg)
   227  	case fastcheck(WarningLevel):
   228  		log(WarningLevel, msg, nil)
   229  	}
   230  }
   231  
   232  // Warningf is used to log (potentially) bad events, but nothing broke (even a little) and there is no need to panic yet.
   233  func (tracer *ContextTracer) Warningf(format string, things ...interface{}) {
   234  	switch {
   235  	case tracer != nil:
   236  		tracer.log(WarningLevel, fmt.Sprintf(format, things...))
   237  	case fastcheck(WarningLevel):
   238  		log(WarningLevel, fmt.Sprintf(format, things...), nil)
   239  	}
   240  }
   241  
   242  // Error is used to log errors that break or impair functionality. The task/process may have to be aborted and tried again later. The system is still operational. Maybe User/Admin should be informed.
   243  func (tracer *ContextTracer) Error(msg string) {
   244  	switch {
   245  	case tracer != nil:
   246  		tracer.log(ErrorLevel, msg)
   247  	case fastcheck(ErrorLevel):
   248  		log(ErrorLevel, msg, nil)
   249  	}
   250  }
   251  
   252  // Errorf is used to log errors that break or impair functionality. The task/process may have to be aborted and tried again later. The system is still operational.
   253  func (tracer *ContextTracer) Errorf(format string, things ...interface{}) {
   254  	switch {
   255  	case tracer != nil:
   256  		tracer.log(ErrorLevel, fmt.Sprintf(format, things...))
   257  	case fastcheck(ErrorLevel):
   258  		log(ErrorLevel, fmt.Sprintf(format, things...), nil)
   259  	}
   260  }
   261  
   262  // Critical is used to log events that completely break the system. Operation connot continue. User/Admin must be informed.
   263  func (tracer *ContextTracer) Critical(msg string) {
   264  	switch {
   265  	case tracer != nil:
   266  		tracer.log(CriticalLevel, msg)
   267  	case fastcheck(CriticalLevel):
   268  		log(CriticalLevel, msg, nil)
   269  	}
   270  }
   271  
   272  // Criticalf is used to log events that completely break the system. Operation connot continue. User/Admin must be informed.
   273  func (tracer *ContextTracer) Criticalf(format string, things ...interface{}) {
   274  	switch {
   275  	case tracer != nil:
   276  		tracer.log(CriticalLevel, fmt.Sprintf(format, things...))
   277  	case fastcheck(CriticalLevel):
   278  		log(CriticalLevel, fmt.Sprintf(format, things...), nil)
   279  	}
   280  }