blob: cc750f4d3d63b6550fe92ac8da12734f3a6fcfd7 [file] [log] [blame]
sslobodrd046be82019-01-16 10:02:22 -05001// Copyright 2015 The etcd Authors
2//
3// Licensed under the Apache License, Version 2.0 (the "License");
4// you may not use this file except in compliance with the License.
5// You may obtain a copy of the License at
6//
7// http://www.apache.org/licenses/LICENSE-2.0
8//
9// Unless required by applicable law or agreed to in writing, software
10// distributed under the License is distributed on an "AS IS" BASIS,
11// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12// See the License for the specific language governing permissions and
13// limitations under the License.
14
15// Package logutil includes utilities to facilitate logging.
16package logutil
17
18import (
19 "fmt"
20 "sync"
21 "time"
22
23 "github.com/coreos/pkg/capnslog"
24)
25
26var (
27 defaultMergePeriod = time.Second
28 defaultTimeOutputScale = 10 * time.Millisecond
29
30 outputInterval = time.Second
31)
32
33// line represents a log line that can be printed out
34// through capnslog.PackageLogger.
35type line struct {
36 level capnslog.LogLevel
37 str string
38}
39
40func (l line) append(s string) line {
41 return line{
42 level: l.level,
43 str: l.str + " " + s,
44 }
45}
46
47// status represents the merge status of a line.
48type status struct {
49 period time.Duration
50
51 start time.Time // start time of latest merge period
52 count int // number of merged lines from starting
53}
54
55func (s *status) isInMergePeriod(now time.Time) bool {
56 return s.period == 0 || s.start.Add(s.period).After(now)
57}
58
59func (s *status) isEmpty() bool { return s.count == 0 }
60
61func (s *status) summary(now time.Time) string {
62 ts := s.start.Round(defaultTimeOutputScale)
63 took := now.Round(defaultTimeOutputScale).Sub(ts)
64 return fmt.Sprintf("[merged %d repeated lines in %s]", s.count, took)
65}
66
67func (s *status) reset(now time.Time) {
68 s.start = now
69 s.count = 0
70}
71
72// MergeLogger supports merge logging, which merges repeated log lines
73// and prints summary log lines instead.
74//
75// For merge logging, MergeLogger prints out the line when the line appears
76// at the first time. MergeLogger holds the same log line printed within
77// defaultMergePeriod, and prints out summary log line at the end of defaultMergePeriod.
78// It stops merging when the line doesn't appear within the
79// defaultMergePeriod.
80type MergeLogger struct {
81 *capnslog.PackageLogger
82
83 mu sync.Mutex // protect statusm
84 statusm map[line]*status
85}
86
87func NewMergeLogger(logger *capnslog.PackageLogger) *MergeLogger {
88 l := &MergeLogger{
89 PackageLogger: logger,
90 statusm: make(map[line]*status),
91 }
92 go l.outputLoop()
93 return l
94}
95
96func (l *MergeLogger) MergeInfo(entries ...interface{}) {
97 l.merge(line{
98 level: capnslog.INFO,
99 str: fmt.Sprint(entries...),
100 })
101}
102
103func (l *MergeLogger) MergeInfof(format string, args ...interface{}) {
104 l.merge(line{
105 level: capnslog.INFO,
106 str: fmt.Sprintf(format, args...),
107 })
108}
109
110func (l *MergeLogger) MergeNotice(entries ...interface{}) {
111 l.merge(line{
112 level: capnslog.NOTICE,
113 str: fmt.Sprint(entries...),
114 })
115}
116
117func (l *MergeLogger) MergeNoticef(format string, args ...interface{}) {
118 l.merge(line{
119 level: capnslog.NOTICE,
120 str: fmt.Sprintf(format, args...),
121 })
122}
123
124func (l *MergeLogger) MergeWarning(entries ...interface{}) {
125 l.merge(line{
126 level: capnslog.WARNING,
127 str: fmt.Sprint(entries...),
128 })
129}
130
131func (l *MergeLogger) MergeWarningf(format string, args ...interface{}) {
132 l.merge(line{
133 level: capnslog.WARNING,
134 str: fmt.Sprintf(format, args...),
135 })
136}
137
138func (l *MergeLogger) MergeError(entries ...interface{}) {
139 l.merge(line{
140 level: capnslog.ERROR,
141 str: fmt.Sprint(entries...),
142 })
143}
144
145func (l *MergeLogger) MergeErrorf(format string, args ...interface{}) {
146 l.merge(line{
147 level: capnslog.ERROR,
148 str: fmt.Sprintf(format, args...),
149 })
150}
151
152func (l *MergeLogger) merge(ln line) {
153 l.mu.Lock()
154
155 // increase count if the logger is merging the line
156 if status, ok := l.statusm[ln]; ok {
157 status.count++
158 l.mu.Unlock()
159 return
160 }
161
162 // initialize status of the line
163 l.statusm[ln] = &status{
164 period: defaultMergePeriod,
165 start: time.Now(),
166 }
167 // release the lock before IO operation
168 l.mu.Unlock()
169 // print out the line at its first time
170 l.PackageLogger.Logf(ln.level, ln.str)
171}
172
173func (l *MergeLogger) outputLoop() {
174 for now := range time.Tick(outputInterval) {
175 var outputs []line
176
177 l.mu.Lock()
178 for ln, status := range l.statusm {
179 if status.isInMergePeriod(now) {
180 continue
181 }
182 if status.isEmpty() {
183 delete(l.statusm, ln)
184 continue
185 }
186 outputs = append(outputs, ln.append(status.summary(now)))
187 status.reset(now)
188 }
189 l.mu.Unlock()
190
191 for _, o := range outputs {
192 l.PackageLogger.Logf(o.level, o.str)
193 }
194 }
195}