blob: 866b6f7a8946350d2b5989a41a3f9c1891f8b01a [file] [log] [blame]
Scott Baker2c1c4822019-10-16 11:02:41 -07001// 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
15package logutil
16
17import (
18 "fmt"
19 "sync"
20 "time"
21
22 "github.com/coreos/pkg/capnslog"
23)
24
25var (
26 defaultMergePeriod = time.Second
27 defaultTimeOutputScale = 10 * time.Millisecond
28
29 outputInterval = time.Second
30)
31
32// line represents a log line that can be printed out
33// through capnslog.PackageLogger.
34type line struct {
35 level capnslog.LogLevel
36 str string
37}
38
39func (l line) append(s string) line {
40 return line{
41 level: l.level,
42 str: l.str + " " + s,
43 }
44}
45
46// status represents the merge status of a line.
47type status struct {
48 period time.Duration
49
50 start time.Time // start time of latest merge period
51 count int // number of merged lines from starting
52}
53
54func (s *status) isInMergePeriod(now time.Time) bool {
55 return s.period == 0 || s.start.Add(s.period).After(now)
56}
57
58func (s *status) isEmpty() bool { return s.count == 0 }
59
60func (s *status) summary(now time.Time) string {
61 ts := s.start.Round(defaultTimeOutputScale)
62 took := now.Round(defaultTimeOutputScale).Sub(ts)
63 return fmt.Sprintf("[merged %d repeated lines in %s]", s.count, took)
64}
65
66func (s *status) reset(now time.Time) {
67 s.start = now
68 s.count = 0
69}
70
71// MergeLogger supports merge logging, which merges repeated log lines
72// and prints summary log lines instead.
73//
74// For merge logging, MergeLogger prints out the line when the line appears
75// at the first time. MergeLogger holds the same log line printed within
76// defaultMergePeriod, and prints out summary log line at the end of defaultMergePeriod.
77// It stops merging when the line doesn't appear within the
78// defaultMergePeriod.
79type MergeLogger struct {
80 *capnslog.PackageLogger
81
82 mu sync.Mutex // protect statusm
83 statusm map[line]*status
84}
85
86func NewMergeLogger(logger *capnslog.PackageLogger) *MergeLogger {
87 l := &MergeLogger{
88 PackageLogger: logger,
89 statusm: make(map[line]*status),
90 }
91 go l.outputLoop()
92 return l
93}
94
95func (l *MergeLogger) MergeInfo(entries ...interface{}) {
96 l.merge(line{
97 level: capnslog.INFO,
98 str: fmt.Sprint(entries...),
99 })
100}
101
102func (l *MergeLogger) MergeInfof(format string, args ...interface{}) {
103 l.merge(line{
104 level: capnslog.INFO,
105 str: fmt.Sprintf(format, args...),
106 })
107}
108
109func (l *MergeLogger) MergeNotice(entries ...interface{}) {
110 l.merge(line{
111 level: capnslog.NOTICE,
112 str: fmt.Sprint(entries...),
113 })
114}
115
116func (l *MergeLogger) MergeNoticef(format string, args ...interface{}) {
117 l.merge(line{
118 level: capnslog.NOTICE,
119 str: fmt.Sprintf(format, args...),
120 })
121}
122
123func (l *MergeLogger) MergeWarning(entries ...interface{}) {
124 l.merge(line{
125 level: capnslog.WARNING,
126 str: fmt.Sprint(entries...),
127 })
128}
129
130func (l *MergeLogger) MergeWarningf(format string, args ...interface{}) {
131 l.merge(line{
132 level: capnslog.WARNING,
133 str: fmt.Sprintf(format, args...),
134 })
135}
136
137func (l *MergeLogger) MergeError(entries ...interface{}) {
138 l.merge(line{
139 level: capnslog.ERROR,
140 str: fmt.Sprint(entries...),
141 })
142}
143
144func (l *MergeLogger) MergeErrorf(format string, args ...interface{}) {
145 l.merge(line{
146 level: capnslog.ERROR,
147 str: fmt.Sprintf(format, args...),
148 })
149}
150
151func (l *MergeLogger) merge(ln line) {
152 l.mu.Lock()
153
154 // increase count if the logger is merging the line
155 if status, ok := l.statusm[ln]; ok {
156 status.count++
157 l.mu.Unlock()
158 return
159 }
160
161 // initialize status of the line
162 l.statusm[ln] = &status{
163 period: defaultMergePeriod,
164 start: time.Now(),
165 }
166 // release the lock before IO operation
167 l.mu.Unlock()
168 // print out the line at its first time
169 l.PackageLogger.Logf(ln.level, ln.str)
170}
171
172func (l *MergeLogger) outputLoop() {
173 for now := range time.Tick(outputInterval) {
174 var outputs []line
175
176 l.mu.Lock()
177 for ln, status := range l.statusm {
178 if status.isInMergePeriod(now) {
179 continue
180 }
181 if status.isEmpty() {
182 delete(l.statusm, ln)
183 continue
184 }
185 outputs = append(outputs, ln.append(status.summary(now)))
186 status.reset(now)
187 }
188 l.mu.Unlock()
189
190 for _, o := range outputs {
191 l.PackageLogger.Logf(o.level, o.str)
192 }
193 }
194}