forked from delicb/ligno
-
Notifications
You must be signed in to change notification settings - Fork 0
/
logger.go
696 lines (619 loc) · 21.4 KB
/
logger.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
package ligno
import (
"fmt"
"os"
"runtime"
"strings"
"sync"
"sync/atomic"
"time"
)
// stdLogger is interface that describes logger from standard library.
// It is defined here to trigger build time errors if ligno logger does not
// implement it.
// Not all methods from stdlib logger are set here (like Flags, Prefix and
// Output manipulation) because they are not straight forward do implement
// with ligno, but they might be added later.
type stdLogger interface {
Printf(format string, v ...interface{})
Print(v ...interface{})
Println(v ...interface{})
Fatal(v ...interface{})
Fatalf(format string, v ...interface{})
Fatalln(v ...interface{})
Panic(v ...interface{})
Panicf(format string, v ...interface{})
Panicln(v ...interface{})
}
// assign instance of logger to stdLogger interface to trigger compile time
// error if logger does not implement interface
var _ stdLogger = GetLogger("_")
// Printf formats message according to stdlib rules and logs it in INFO level.
func (l *Logger) Printf(format string, v ...interface{}) {
l.Log(2, INFO, fmt.Sprintf(format, v...))
}
// Print formats message according to stdlib rules and logs it in INFO level.
func (l *Logger) Print(v ...interface{}) {
l.Log(2, INFO, fmt.Sprint(v...))
}
// Println formats message according to stdlib rules and logs it in INFO level.
func (l *Logger) Println(v ...interface{}) {
l.Log(2, INFO, fmt.Sprintln(v...))
}
// Write is implementation of io.Writer interface for logger.
// It writes provided message in INFO level to logger.
func (l *Logger) Write(p []byte) (n int, err error) {
l.Log(2, INFO, string(p))
return len(p), nil
}
// Fatal formats message according to stdlib rules, logs it in CRITICAL level
// and exists application.
func (l *Logger) Fatal(v ...interface{}) {
l.Log(2, CRITICAL, fmt.Sprint(v...))
os.Exit(1)
}
// Fatalf formats message according to stdlib rules, logs it in CRITICAL level
// and exists application.
func (l *Logger) Fatalf(format string, v ...interface{}) {
l.Log(2, CRITICAL, fmt.Sprintf(format, v...))
os.Exit(1)
}
// Fatalln formats message according to stdlib rules, logs it in CRITICAL level
// and exists application.
func (l *Logger) Fatalln(v ...interface{}) {
l.Log(2, CRITICAL, fmt.Sprintln(v...))
os.Exit(1)
}
// Panic formats message according to stdlib rules, logs it in CRITICAL level
// and panics.
func (l *Logger) Panic(v ...interface{}) {
s := fmt.Sprint(v...)
l.Log(2, CRITICAL, s)
panic(s)
}
// Panicf formats message according to stdlib rules, logs it in CRITICAL level
// and panics.
func (l *Logger) Panicf(format string, v ...interface{}) {
s := fmt.Sprintf(format, v...)
l.Log(2, CRITICAL, s)
panic(s)
}
// Panicln formats message according to stdlib rules, logs it in CRITICAL level
// and panics.
func (l *Logger) Panicln(v ...interface{}) {
s := fmt.Sprintln(v...)
l.Log(2, CRITICAL, s)
panic(s)
}
// root logger is parent of all loggers and it always exists.
var rootLogger = createLogger("", LoggerOptions{
Context: nil,
Handler: StreamHandler(os.Stdout, TerminalFormat()),
BufferSize: 2048,
})
// WaitAll blocks until all loggers are finished with message processing.
func WaitAll() {
rootLogger.Wait()
}
// WaitAllTimeout blocks until all messages send to all loggers are processed or max
// specified amount of time.
// Boolean return value indicates if function returned because all messages
// were processed (true) or because timeout has expired (false).
func WaitAllTimeout(t time.Duration) bool {
return rootLogger.WaitTimeout(t)
}
type loggerState uint8
const (
loggerRunning loggerState = iota
loggerStopped
)
// Logger is central data type in ligno which represents logger itself.
// Logger is first level of processing events. It creates them and
// queues for async processing. It holds slice of Handlers that process
// messages and context (set of key-value pairs that will be include
// in every log record).
type Logger struct {
// name is name of this logger.
name string
// Context in which logger is operating. Basically, this is set of
// key-value pairs that will be added to every record logged with this
// logger. They have lowest priority.
context Ctx
contextList []interface{}
// handler is backed for processing records.
handler *replaceableHandler
// handlerChanged is notification mechanism to notify working goroutines
// that they need to switch their handler for further processing.
handlerChanged chan Handler
// relationship holds information about logger parent and children.
relationship struct {
sync.RWMutex
// parent is this logger's parent. Final context of record is created
// by combining all parents contexts and if preventPropagation is false
// all records will be sent to parent to processing as well.
// parent should be immutable once it is set, so it should be safe to
// read it without concurrency protection.
parent *Logger
// children is slice of all loggers that have this logger as parent.
// children []*Logger
children map[string]*Logger
// preventPropagation is flag that indicates if propagation of log
// records to parent should be prevented.
preventPropagation bool
}
// rawMessages is channel for queueing and buffering raw messages from
// application which needs to be merged with context and submitted
// to final processing
rawRecords chan Record
// records is channel for queueing and buffering log records.
records chan Record
// notifyFinished is channel of channels. When someone wants to be notified
// when logger processed all queued records, it sends channel that will be
// closed after last queued record is processed to notifyFinished.
notifyFinished chan chan struct{}
// toProcess is number of messages left to process in this logger.
toProcess int32
// state represents state in which logger is currently
state struct {
sync.RWMutex
val loggerState
}
// level is lowest level that this logger will process
level Level
// Flag that indicates that file and line of place where logging took place
// should be kept.
includeFileAndLine bool
}
// LoggerOptions is container for configuration options for logger instances.
// Empty value is valid for initializing logger.
type LoggerOptions struct {
// Context that logger should have.
Context Ctx
// Handler for processing records.
Handler Handler
// Level is minimal level that logger will process.
Level Level
// BufferSize is size of buffer for records that will be process async.
BufferSize int
// PreventPropagation is flag that indicates if records should be passed
// to parent logger for processing.
PreventPropagation bool
// Flag that indicates that file and line of place where logging took place
// should be kept. Note that this is expensive, so use with care. If this
// information will be shown depends on formatter.
IncludeFileAndLine bool
}
// createLogger creates new instance of logger, initializes all values based
// on provided options and starts worker goroutines.
func createLogger(name string, options LoggerOptions) *Logger {
rh := new(replaceableHandler)
rh.Replace(options.Handler)
var buffSize = 0
if options.BufferSize > 0 {
buffSize = options.BufferSize
} else {
buffSize = 1024
}
l := &Logger{
name: name,
context: options.Context,
contextList: make([]interface{}, 0),
records: make(chan Record, buffSize),
rawRecords: make(chan Record, buffSize),
notifyFinished: make(chan chan struct{}),
handler: rh,
level: options.Level,
includeFileAndLine: options.IncludeFileAndLine,
}
// performance enhanced: no use map[string]interface{}
// context's type should be []interface{}
for k, v := range options.Context {
l.contextList = append(l.contextList, k, fmt.Sprintf("%+v", v))
}
// no need to lock access to state here since we just created logger
// and nobody can use it anywhere else at the moment.
l.state.val = loggerRunning
l.relationship.children = make(map[string]*Logger)
l.relationship.preventPropagation = options.PreventPropagation
go l.handle()
go l.processRecords()
return l
}
// SubLogger creates new logger that has current logger as parent with default
// options and starts it so it is ready for message processing.
func (l *Logger) SubLogger(name string) *Logger {
newLogger := createLogger(name, LoggerOptions{})
l.addChild(newLogger)
return newLogger
}
// SubLoggerOptions creates new logger that has current logger as parent with
// provided options and starts it so it is ready for message processing.
func (l *Logger) SubLoggerOptions(name string, options LoggerOptions) *Logger {
newLogger := createLogger(name, options)
l.addChild(newLogger)
return newLogger
}
// GetLogger returns logger with provided name (creating it if needed).
// Name is dot-separated string with parent logger names and this function
// will create all intermediate loggers with default options.
func GetLogger(name string) *Logger {
current := rootLogger
for _, part := range strings.Split(name, ".") {
current.relationship.RLock()
child, ok := current.relationship.children[part]
current.relationship.RUnlock()
if ok {
current = child
} else {
current = current.SubLogger(part)
}
}
return current
}
// GetLoggerOptions returns logger with provided name (creating it if needed).
// Name is dot-separated string with parent loggers and this function will
// create all intermediate loggers with default options. Provided options will
// be applied only to last logger in chain. If all loggers in chain already
// exist, no new loggers will be creates and provided options will be discarded.
// If options different then default are needed for intermediate loggers,
// create them first with appropriate options.
func GetLoggerOptions(name string, options LoggerOptions) *Logger {
current := rootLogger
parts := strings.Split(name, ".")
for i := 0; i < len(parts); i++ {
part := parts[i]
current.relationship.RLock()
child, ok := current.relationship.children[part]
current.relationship.RUnlock()
if ok {
current = child
} else {
if i == len(parts)-1 {
current = current.SubLoggerOptions(part, options)
} else {
current = current.SubLogger(part)
}
}
}
return current
}
func (l *Logger) addChild(child *Logger) {
l.relationship.Lock()
// l.relationship.children = append(l.relationship.children, child)
l.relationship.children[child.name] = child
l.relationship.Unlock()
child.relationship.Lock()
child.relationship.parent = l
child.relationship.Unlock()
}
func (l *Logger) removeChild(child *Logger) {
l.relationship.Lock()
defer l.relationship.Unlock()
delete(l.relationship.children, child.name)
}
// SetHandler set handler to this logger to be used from now on.
func (l *Logger) SetHandler(handler Handler) {
l.handler.Replace(handler)
}
// Handler returns current handler for this logger
func (l *Logger) Handler() Handler {
return l.handler.Handler()
}
// Level returns minimal level that this logger will process.
func (l *Logger) Level() Level {
return l.level
}
// Name returns name of this logger.
func (l *Logger) Name() string {
return l.name
}
// FullName returns name of this logger prefixed with name of its parent,
// separated by ".". This happens recursively, so return value will contain
// names of all parents.
func (l *Logger) FullName() string {
if l.relationship.parent != nil {
parentFullName := l.relationship.parent.FullName()
if parentFullName != "" {
return l.relationship.parent.FullName() + "." + l.name
}
}
return l.name
}
// handle is log record processor which takes records from chan and invokes all handlers.
func (l *Logger) handle() {
var notifyFinished chan struct{}
for {
select {
case record, ok := <-l.records:
if !ok {
return
}
l.handler.Handle(record)
atomic.AddInt32(&l.toProcess, -1)
// if count dropped to 0, close notification channel
if atomic.LoadInt32(&l.toProcess) == 0 && notifyFinished != nil {
close(notifyFinished)
// reset notification channel
notifyFinished = nil
}
case notifyFinished = <-l.notifyFinished:
// check count right away and notify that processing is done if possible
if atomic.LoadInt32(&l.toProcess) == 0 {
close(notifyFinished)
// reset notification channel
notifyFinished = nil
}
}
}
}
// buildContext builds context from this logger ant all its parents.
// TODO: Maybe keep context stating per logger, so that we do not have to build it all the time
func (l *Logger) buildContext() Ctx {
if l.relationship.parent == nil {
return l.context
}
return l.relationship.parent.context.merge(l.context)
}
// processRecords creates full records from provided user record and this and
// all parents contexts.
func (l *Logger) processRecords() {
for {
select {
case record, ok := <-l.rawRecords:
if !ok {
return
}
l.records <- record
if !l.relationship.preventPropagation && l.relationship.parent != nil {
l.relationship.parent.log(-1, record)
}
}
}
}
// log creates record suitable for processing and sends it to messages chan.
func (l *Logger) log(calldepth int, record Record) {
l.state.RLock()
defer l.state.RUnlock()
if l.state.val == loggerStopped || !l.IsEnabledFor(record.Level) {
return
}
var file string
var line int
var gotCaller bool
if l.includeFileAndLine && calldepth > 0 {
_, file, line, gotCaller = runtime.Caller(calldepth)
if !gotCaller {
file = "???"
line = -1
}
}
record.File = file
record.Line = line
atomic.AddInt32(&l.toProcess, 1)
l.rawRecords <- record
}
// Stop stops listening for new messages sent to this logger.
// Messages already sent will be processed, but all new messages will
// silently be dropped.
// Stopping loggers stops processing goroutines and cleans up resources.
func (l *Logger) stopAndWait(waitFunc func()) {
l.state.Lock()
defer l.state.Unlock()
// mark logger as stopped
l.state.val = loggerStopped
// stop processing of raw records
close(l.rawRecords)
// break relationship
if l.relationship.parent != nil {
l.relationship.parent.removeChild(l)
}
// wait for all records that have already arrived to processed
waitFunc()
// stop processing all records
close(l.records)
// close handler, if it supports closing.
if handlerCloser, ok := l.Handler().(HandlerCloser); ok {
handlerCloser.Close()
}
}
// StopAndWait stops listening for new messages sent to this logger and
// blocks until all previously arrived messages are processed.
// Records already sent will be processed, but all new messages will
// silently be dropped.
func (l *Logger) StopAndWait() {
l.stopAndWait(l.Wait)
}
// StopAndWaitTimeout stops listening for new messages sent to this logger and
// blocks until all previously sent message are processed or max provided duration.
// Records already sent will be processed, but all new messages will
// silently be dropped. Return value indicates if all messages are processed (true)
// or if provided timeout expired (false)
func (l *Logger) StopAndWaitTimeout(t time.Duration) (finished bool) {
finished = false
l.stopAndWait(func() {
finished = l.WaitTimeout(t)
})
return finished
}
// IsRunning returns boolean indicating if this logger is still running.
func (l *Logger) IsRunning() bool {
l.state.RLock()
defer l.state.RUnlock()
return l.state.val == loggerRunning
}
// wait blocks until all messages on messages channel are processed.
// Provided done channel will be closed when messages are processed to notify
// interested parties that they can unblock.
func (l *Logger) wait(done chan struct{}) {
runtime.Gosched()
l.relationship.RLock()
defer l.relationship.RUnlock()
var wg sync.WaitGroup
wg.Add(len(l.relationship.children) + 1)
go func() {
l.notifyFinished <- done
wg.Done()
}()
for _, child := range l.relationship.children {
go func(l *Logger) {
chDone := make(chan struct{})
l.wait(chDone)
<-chDone
wg.Done()
}(child)
}
wg.Wait()
}
// Wait block until all messages sent to logger are processed.
// If timeout is needed, see WaitTimeout.
func (l *Logger) Wait() {
done := make(chan struct{})
l.wait(done)
<-done
}
// WaitTimeout blocks until all messages send to logger are processed or max
// specified amount of time.
// Boolean return value indicates if function returned because all messages
// were processed (true) or because timeout has expired (false).
func (l *Logger) WaitTimeout(t time.Duration) (finished bool) {
done := make(chan struct{})
timeout := time.After(t)
l.wait(done)
select {
case <-done:
return true
case <-timeout:
return false
}
}
// Log creates record and queues it for processing.
// Required parameters are level for record and event that occurred. Any
// additional parameters will be transformed to key-value pairs for record
// in order in which they were provided. There should be even number of them,
// but in case that there is on number of parameters, empty string is
// appended. Example:
// l.Log(INFO, "User logged in", "user_id", user_id, "platform", PLATFORM_NAME)
// will be translated into log record with following keys:
// {LEVEL: INFO", EVENT: "User logged in", "user_id": user_id, "platform": PLATFORM_NAME}
func (l *Logger) Log(calldepth int, level Level, message string, pairs ...interface{}) {
// if level is not sufficient, do not proceed to avoid unneeded allocations
if !l.IsEnabledFor(level) {
return
}
// make sure that number of items in data is even
pairsNo := len(pairs)
if pairsNo%2 != 0 && pairsNo > 0 {
// If there is no even number of items provided - add dummy values and
// indicate that there was a problem.
// However, if last provided unpaired item is instance of error,
// add it with key "err" without reporting problems. This is useful
// for logging stuff in format ligno.Error("Description", err)
last := pairs[pairsNo-1]
if _, ok := last.(error); ok {
pairs = append(pairs[:pairsNo-1], "err", last)
} else {
pairs = append(pairs, []interface{}{nil, "error", "missing key"}...)
}
}
r := Record{
Time: time.Now().UTC(),
Level: level,
Message: message,
Pairs: pairs,
ContextList: l.contextList,
Logger: l,
}
l.log(calldepth+1, r)
}
// LogCtx adds provided message in specified level.
func (l *Logger) LogCtx(calldepth int, level Level, message string, data Ctx) {
// if level is not sufficient, do not proceed to avoid unneeded allocations
if !l.IsEnabledFor(level) {
return
}
r := Record{
Time: time.Now().UTC(),
Level: level,
Message: message,
Logger: l,
}
// performance enhanced: no use map[string]interface{}
// context's type should be []interface{}
for k, v := range data {
r.ContextList = append(r.ContextList, k, fmt.Sprintf("%+v", v))
}
l.log(calldepth+1, r)
}
// Debug creates log record and queues it for processing with DEBUG level.
// Additional parameters have same semantics as in Log method.
func (l *Logger) Debug(message string, pairs ...interface{}) {
l.Log(2, DEBUG, message, pairs...)
}
// DebugCtx logs message in DEBUG level with provided context.
func (l *Logger) DebugCtx(message string, ctx Ctx) {
l.LogCtx(2, DEBUG, message, ctx)
}
// Info creates log record and queues it for processing with INFO level.
// Additional parameters have same semantics as in Log method.
func (l *Logger) Info(message string, pairs ...interface{}) {
l.Log(2, INFO, message, pairs...)
}
// InfoCtx logs message in INFO level with provided context.
func (l *Logger) InfoCtx(message string, ctx Ctx) {
l.LogCtx(2, INFO, message, ctx)
}
// Warning creates log record and queues it for processing with WARNING level.
// Additional parameters have same semantics as in Log method.
func (l *Logger) Warning(message string, pairs ...interface{}) {
l.Log(2, WARNING, message, pairs...)
}
// WarningCtx logs message in WARNING level with provided context.
func (l *Logger) WarningCtx(message string, ctx Ctx) {
l.LogCtx(2, WARNING, message, ctx)
}
// Error creates log record and queues it for processing with ERROR level.
// Additional parameters have same semantics as in Log method.
func (l *Logger) Error(message string, pairs ...interface{}) {
l.Log(2, ERROR, message, pairs...)
}
// ErrorCtx logs message in ERROR level with provided context.
func (l *Logger) ErrorCtx(message string, ctx Ctx) {
l.LogCtx(2, ERROR, message, ctx)
}
// Critical creates log record and queues it for processing with CRITICAL level.
// Additional parameters have same semantics as in Log method.
func (l *Logger) Critical(message string, pairs ...interface{}) {
l.Log(2, CRITICAL, message, pairs...)
}
// CriticalCtx logs message in CRITICAL level with provided context.
func (l *Logger) CriticalCtx(message string, ctx Ctx) {
l.LogCtx(2, CRITICAL, message, ctx)
}
// IsEnabledFor returns true if logger will process records with provided level.
func (l *Logger) IsEnabledFor(level Level) bool {
return l.Level() <= level
}
// IsDebug returns true if logger will process messages in DEBUG level
func (l *Logger) IsDebug() bool {
return l.IsEnabledFor(DEBUG)
}
// IsInfo returns true if logger will process messages in INFO level
func (l *Logger) IsInfo() bool {
return l.IsEnabledFor(INFO)
}
// IsWarning returns true if logger will process messages in WARNING level
func (l *Logger) IsWarning() bool {
return l.IsEnabledFor(WARNING)
}
// IsError returns true if logger will process messages in ERROR level
func (l *Logger) IsError() bool {
return l.IsEnabledFor(ERROR)
}
// IsCritical returns true if logger will process messages in Critical level
func (l *Logger) IsCritical() bool {
return l.IsEnabledFor(CRITICAL)
}
// IsLevel return true if logger will process messages in provided level.
func (l *Logger) IsLevel(level Level) bool {
return l.IsEnabledFor(level)
}