blob: 07a1e5fa7249c4e72c01a27f7b623e6369632dc9 [file] [log] [blame]
kesavand2cde6582020-06-22 04:56:23 -04001package logrus
2
3import (
4 "bytes"
5 "context"
6 "fmt"
7 "os"
8 "reflect"
9 "runtime"
10 "strings"
11 "sync"
12 "time"
13)
14
15var (
kesavand2cde6582020-06-22 04:56:23 -040016
17 // qualified package name, cached at first use
18 logrusPackage string
19
20 // Positions in the call stack when tracing to report the calling method
21 minimumCallerDepth int
22
23 // Used for caller information initialisation
24 callerInitOnce sync.Once
25)
26
27const (
28 maximumCallerDepth int = 25
29 knownLogrusFrames int = 4
30)
31
32func init() {
kesavand2cde6582020-06-22 04:56:23 -040033 // start at the bottom of the stack before the package-name cache is primed
34 minimumCallerDepth = 1
35}
36
37// Defines the key when adding errors using WithError.
38var ErrorKey = "error"
39
40// An entry is the final or intermediate Logrus logging entry. It contains all
41// the fields passed with WithField{,s}. It's finally logged when Trace, Debug,
42// Info, Warn, Error, Fatal or Panic is called on it. These objects can be
43// reused and passed around as much as you wish to avoid field duplication.
44type Entry struct {
45 Logger *Logger
46
47 // Contains all the fields set by the user.
48 Data Fields
49
50 // Time at which the log entry was created
51 Time time.Time
52
53 // Level the log entry was logged at: Trace, Debug, Info, Warn, Error, Fatal or Panic
54 // This field will be set on entry firing and the value will be equal to the one in Logger struct field.
55 Level Level
56
57 // Calling method, with package name
58 Caller *runtime.Frame
59
60 // Message passed to Trace, Debug, Info, Warn, Error, Fatal or Panic
61 Message string
62
63 // When formatter is called in entry.log(), a Buffer may be set to entry
64 Buffer *bytes.Buffer
65
66 // Contains the context set by the user. Useful for hook processing etc.
67 Context context.Context
68
69 // err may contain a field formatting error
70 err string
71}
72
73func NewEntry(logger *Logger) *Entry {
74 return &Entry{
75 Logger: logger,
76 // Default is three fields, plus one optional. Give a little extra room.
77 Data: make(Fields, 6),
78 }
79}
80
kesavandc71914f2022-03-25 11:19:03 +053081func (entry *Entry) Dup() *Entry {
82 data := make(Fields, len(entry.Data))
83 for k, v := range entry.Data {
84 data[k] = v
85 }
86 return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time, Context: entry.Context, err: entry.err}
87}
88
89// Returns the bytes representation of this entry from the formatter.
90func (entry *Entry) Bytes() ([]byte, error) {
91 return entry.Logger.Formatter.Format(entry)
92}
93
kesavand2cde6582020-06-22 04:56:23 -040094// Returns the string representation from the reader and ultimately the
95// formatter.
96func (entry *Entry) String() (string, error) {
kesavandc71914f2022-03-25 11:19:03 +053097 serialized, err := entry.Bytes()
kesavand2cde6582020-06-22 04:56:23 -040098 if err != nil {
99 return "", err
100 }
101 str := string(serialized)
102 return str, nil
103}
104
105// Add an error as single field (using the key defined in ErrorKey) to the Entry.
106func (entry *Entry) WithError(err error) *Entry {
107 return entry.WithField(ErrorKey, err)
108}
109
110// Add a context to the Entry.
111func (entry *Entry) WithContext(ctx context.Context) *Entry {
kesavandc71914f2022-03-25 11:19:03 +0530112 dataCopy := make(Fields, len(entry.Data))
113 for k, v := range entry.Data {
114 dataCopy[k] = v
115 }
116 return &Entry{Logger: entry.Logger, Data: dataCopy, Time: entry.Time, err: entry.err, Context: ctx}
kesavand2cde6582020-06-22 04:56:23 -0400117}
118
119// Add a single field to the Entry.
120func (entry *Entry) WithField(key string, value interface{}) *Entry {
121 return entry.WithFields(Fields{key: value})
122}
123
124// Add a map of fields to the Entry.
125func (entry *Entry) WithFields(fields Fields) *Entry {
126 data := make(Fields, len(entry.Data)+len(fields))
127 for k, v := range entry.Data {
128 data[k] = v
129 }
130 fieldErr := entry.err
131 for k, v := range fields {
132 isErrField := false
133 if t := reflect.TypeOf(v); t != nil {
kesavandc71914f2022-03-25 11:19:03 +0530134 switch {
135 case t.Kind() == reflect.Func, t.Kind() == reflect.Ptr && t.Elem().Kind() == reflect.Func:
kesavand2cde6582020-06-22 04:56:23 -0400136 isErrField = true
kesavand2cde6582020-06-22 04:56:23 -0400137 }
138 }
139 if isErrField {
140 tmp := fmt.Sprintf("can not add field %q", k)
141 if fieldErr != "" {
142 fieldErr = entry.err + ", " + tmp
143 } else {
144 fieldErr = tmp
145 }
146 } else {
147 data[k] = v
148 }
149 }
150 return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time, err: fieldErr, Context: entry.Context}
151}
152
153// Overrides the time of the Entry.
154func (entry *Entry) WithTime(t time.Time) *Entry {
kesavandc71914f2022-03-25 11:19:03 +0530155 dataCopy := make(Fields, len(entry.Data))
156 for k, v := range entry.Data {
157 dataCopy[k] = v
158 }
159 return &Entry{Logger: entry.Logger, Data: dataCopy, Time: t, err: entry.err, Context: entry.Context}
kesavand2cde6582020-06-22 04:56:23 -0400160}
161
162// getPackageName reduces a fully qualified function name to the package name
163// There really ought to be to be a better way...
164func getPackageName(f string) string {
165 for {
166 lastPeriod := strings.LastIndex(f, ".")
167 lastSlash := strings.LastIndex(f, "/")
168 if lastPeriod > lastSlash {
169 f = f[:lastPeriod]
170 } else {
171 break
172 }
173 }
174
175 return f
176}
177
178// getCaller retrieves the name of the first non-logrus calling function
179func getCaller() *runtime.Frame {
kesavand2cde6582020-06-22 04:56:23 -0400180 // cache this package's fully-qualified name
181 callerInitOnce.Do(func() {
kesavandc71914f2022-03-25 11:19:03 +0530182 pcs := make([]uintptr, maximumCallerDepth)
kesavand2cde6582020-06-22 04:56:23 -0400183 _ = runtime.Callers(0, pcs)
kesavand2cde6582020-06-22 04:56:23 -0400184
kesavandc71914f2022-03-25 11:19:03 +0530185 // dynamic get the package name and the minimum caller depth
186 for i := 0; i < maximumCallerDepth; i++ {
187 funcName := runtime.FuncForPC(pcs[i]).Name()
188 if strings.Contains(funcName, "getCaller") {
189 logrusPackage = getPackageName(funcName)
190 break
191 }
192 }
193
kesavand2cde6582020-06-22 04:56:23 -0400194 minimumCallerDepth = knownLogrusFrames
195 })
196
197 // Restrict the lookback frames to avoid runaway lookups
198 pcs := make([]uintptr, maximumCallerDepth)
199 depth := runtime.Callers(minimumCallerDepth, pcs)
200 frames := runtime.CallersFrames(pcs[:depth])
201
202 for f, again := frames.Next(); again; f, again = frames.Next() {
203 pkg := getPackageName(f.Function)
204
205 // If the caller isn't part of this package, we're done
206 if pkg != logrusPackage {
kesavandc71914f2022-03-25 11:19:03 +0530207 return &f //nolint:scopelint
kesavand2cde6582020-06-22 04:56:23 -0400208 }
209 }
210
211 // if we got here, we failed to find the caller's context
212 return nil
213}
214
215func (entry Entry) HasCaller() (has bool) {
216 return entry.Logger != nil &&
217 entry.Logger.ReportCaller &&
218 entry.Caller != nil
219}
220
kesavandc71914f2022-03-25 11:19:03 +0530221func (entry *Entry) log(level Level, msg string) {
kesavand2cde6582020-06-22 04:56:23 -0400222 var buffer *bytes.Buffer
223
kesavandc71914f2022-03-25 11:19:03 +0530224 newEntry := entry.Dup()
225
226 if newEntry.Time.IsZero() {
227 newEntry.Time = time.Now()
kesavand2cde6582020-06-22 04:56:23 -0400228 }
229
kesavandc71914f2022-03-25 11:19:03 +0530230 newEntry.Level = level
231 newEntry.Message = msg
232
233 newEntry.Logger.mu.Lock()
234 reportCaller := newEntry.Logger.ReportCaller
235 newEntry.Logger.mu.Unlock()
236
237 if reportCaller {
238 newEntry.Caller = getCaller()
kesavand2cde6582020-06-22 04:56:23 -0400239 }
240
kesavandc71914f2022-03-25 11:19:03 +0530241 newEntry.fireHooks()
kesavand2cde6582020-06-22 04:56:23 -0400242
kesavandc71914f2022-03-25 11:19:03 +0530243 buffer = getBuffer()
244 defer func() {
245 newEntry.Buffer = nil
246 putBuffer(buffer)
247 }()
kesavand2cde6582020-06-22 04:56:23 -0400248 buffer.Reset()
kesavandc71914f2022-03-25 11:19:03 +0530249 newEntry.Buffer = buffer
kesavand2cde6582020-06-22 04:56:23 -0400250
kesavandc71914f2022-03-25 11:19:03 +0530251 newEntry.write()
kesavand2cde6582020-06-22 04:56:23 -0400252
kesavandc71914f2022-03-25 11:19:03 +0530253 newEntry.Buffer = nil
kesavand2cde6582020-06-22 04:56:23 -0400254
255 // To avoid Entry#log() returning a value that only would make sense for
256 // panic() to use in Entry#Panic(), we avoid the allocation by checking
257 // directly here.
258 if level <= PanicLevel {
kesavandc71914f2022-03-25 11:19:03 +0530259 panic(newEntry)
kesavand2cde6582020-06-22 04:56:23 -0400260 }
261}
262
263func (entry *Entry) fireHooks() {
kesavandc71914f2022-03-25 11:19:03 +0530264 var tmpHooks LevelHooks
kesavand2cde6582020-06-22 04:56:23 -0400265 entry.Logger.mu.Lock()
kesavandc71914f2022-03-25 11:19:03 +0530266 tmpHooks = make(LevelHooks, len(entry.Logger.Hooks))
267 for k, v := range entry.Logger.Hooks {
268 tmpHooks[k] = v
269 }
270 entry.Logger.mu.Unlock()
271
272 err := tmpHooks.Fire(entry.Level, entry)
kesavand2cde6582020-06-22 04:56:23 -0400273 if err != nil {
274 fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
275 }
276}
277
278func (entry *Entry) write() {
kesavand2cde6582020-06-22 04:56:23 -0400279 serialized, err := entry.Logger.Formatter.Format(entry)
280 if err != nil {
281 fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
kesavandc71914f2022-03-25 11:19:03 +0530282 return
283 }
284 entry.Logger.mu.Lock()
285 defer entry.Logger.mu.Unlock()
286 if _, err := entry.Logger.Out.Write(serialized); err != nil {
287 fmt.Fprintf(os.Stderr, "Failed to write to log, %v\n", err)
kesavand2cde6582020-06-22 04:56:23 -0400288 }
289}
290
291func (entry *Entry) Log(level Level, args ...interface{}) {
292 if entry.Logger.IsLevelEnabled(level) {
293 entry.log(level, fmt.Sprint(args...))
294 }
295}
296
297func (entry *Entry) Trace(args ...interface{}) {
298 entry.Log(TraceLevel, args...)
299}
300
301func (entry *Entry) Debug(args ...interface{}) {
302 entry.Log(DebugLevel, args...)
303}
304
305func (entry *Entry) Print(args ...interface{}) {
306 entry.Info(args...)
307}
308
309func (entry *Entry) Info(args ...interface{}) {
310 entry.Log(InfoLevel, args...)
311}
312
313func (entry *Entry) Warn(args ...interface{}) {
314 entry.Log(WarnLevel, args...)
315}
316
317func (entry *Entry) Warning(args ...interface{}) {
318 entry.Warn(args...)
319}
320
321func (entry *Entry) Error(args ...interface{}) {
322 entry.Log(ErrorLevel, args...)
323}
324
325func (entry *Entry) Fatal(args ...interface{}) {
326 entry.Log(FatalLevel, args...)
327 entry.Logger.Exit(1)
328}
329
330func (entry *Entry) Panic(args ...interface{}) {
331 entry.Log(PanicLevel, args...)
kesavand2cde6582020-06-22 04:56:23 -0400332}
333
334// Entry Printf family functions
335
336func (entry *Entry) Logf(level Level, format string, args ...interface{}) {
337 if entry.Logger.IsLevelEnabled(level) {
338 entry.Log(level, fmt.Sprintf(format, args...))
339 }
340}
341
342func (entry *Entry) Tracef(format string, args ...interface{}) {
343 entry.Logf(TraceLevel, format, args...)
344}
345
346func (entry *Entry) Debugf(format string, args ...interface{}) {
347 entry.Logf(DebugLevel, format, args...)
348}
349
350func (entry *Entry) Infof(format string, args ...interface{}) {
351 entry.Logf(InfoLevel, format, args...)
352}
353
354func (entry *Entry) Printf(format string, args ...interface{}) {
355 entry.Infof(format, args...)
356}
357
358func (entry *Entry) Warnf(format string, args ...interface{}) {
359 entry.Logf(WarnLevel, format, args...)
360}
361
362func (entry *Entry) Warningf(format string, args ...interface{}) {
363 entry.Warnf(format, args...)
364}
365
366func (entry *Entry) Errorf(format string, args ...interface{}) {
367 entry.Logf(ErrorLevel, format, args...)
368}
369
370func (entry *Entry) Fatalf(format string, args ...interface{}) {
371 entry.Logf(FatalLevel, format, args...)
372 entry.Logger.Exit(1)
373}
374
375func (entry *Entry) Panicf(format string, args ...interface{}) {
376 entry.Logf(PanicLevel, format, args...)
377}
378
379// Entry Println family functions
380
381func (entry *Entry) Logln(level Level, args ...interface{}) {
382 if entry.Logger.IsLevelEnabled(level) {
383 entry.Log(level, entry.sprintlnn(args...))
384 }
385}
386
387func (entry *Entry) Traceln(args ...interface{}) {
388 entry.Logln(TraceLevel, args...)
389}
390
391func (entry *Entry) Debugln(args ...interface{}) {
392 entry.Logln(DebugLevel, args...)
393}
394
395func (entry *Entry) Infoln(args ...interface{}) {
396 entry.Logln(InfoLevel, args...)
397}
398
399func (entry *Entry) Println(args ...interface{}) {
400 entry.Infoln(args...)
401}
402
403func (entry *Entry) Warnln(args ...interface{}) {
404 entry.Logln(WarnLevel, args...)
405}
406
407func (entry *Entry) Warningln(args ...interface{}) {
408 entry.Warnln(args...)
409}
410
411func (entry *Entry) Errorln(args ...interface{}) {
412 entry.Logln(ErrorLevel, args...)
413}
414
415func (entry *Entry) Fatalln(args ...interface{}) {
416 entry.Logln(FatalLevel, args...)
417 entry.Logger.Exit(1)
418}
419
420func (entry *Entry) Panicln(args ...interface{}) {
421 entry.Logln(PanicLevel, args...)
422}
423
424// Sprintlnn => Sprint no newline. This is to get the behavior of how
425// fmt.Sprintln where spaces are always added between operands, regardless of
426// their type. Instead of vendoring the Sprintln implementation to spare a
427// string allocation, we do the simplest thing.
428func (entry *Entry) sprintlnn(args ...interface{}) string {
429 msg := fmt.Sprintln(args...)
430 return msg[:len(msg)-1]
431}