Scott Baker | 2d89798 | 2019-09-24 11:50:08 -0700 | [diff] [blame] | 1 | // 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 |
| 16 | |
| 17 | import ( |
| 18 | "fmt" |
| 19 | "sync" |
| 20 | "time" |
| 21 | |
| 22 | "github.com/coreos/pkg/capnslog" |
| 23 | ) |
| 24 | |
| 25 | var ( |
| 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. |
| 34 | type line struct { |
| 35 | level capnslog.LogLevel |
| 36 | str string |
| 37 | } |
| 38 | |
| 39 | func (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. |
| 47 | type 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 | |
| 54 | func (s *status) isInMergePeriod(now time.Time) bool { |
| 55 | return s.period == 0 || s.start.Add(s.period).After(now) |
| 56 | } |
| 57 | |
| 58 | func (s *status) isEmpty() bool { return s.count == 0 } |
| 59 | |
| 60 | func (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 | |
| 66 | func (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. |
| 79 | type MergeLogger struct { |
| 80 | *capnslog.PackageLogger |
| 81 | |
| 82 | mu sync.Mutex // protect statusm |
| 83 | statusm map[line]*status |
| 84 | } |
| 85 | |
| 86 | func 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 | |
| 95 | func (l *MergeLogger) MergeInfo(entries ...interface{}) { |
| 96 | l.merge(line{ |
| 97 | level: capnslog.INFO, |
| 98 | str: fmt.Sprint(entries...), |
| 99 | }) |
| 100 | } |
| 101 | |
| 102 | func (l *MergeLogger) MergeInfof(format string, args ...interface{}) { |
| 103 | l.merge(line{ |
| 104 | level: capnslog.INFO, |
| 105 | str: fmt.Sprintf(format, args...), |
| 106 | }) |
| 107 | } |
| 108 | |
| 109 | func (l *MergeLogger) MergeNotice(entries ...interface{}) { |
| 110 | l.merge(line{ |
| 111 | level: capnslog.NOTICE, |
| 112 | str: fmt.Sprint(entries...), |
| 113 | }) |
| 114 | } |
| 115 | |
| 116 | func (l *MergeLogger) MergeNoticef(format string, args ...interface{}) { |
| 117 | l.merge(line{ |
| 118 | level: capnslog.NOTICE, |
| 119 | str: fmt.Sprintf(format, args...), |
| 120 | }) |
| 121 | } |
| 122 | |
| 123 | func (l *MergeLogger) MergeWarning(entries ...interface{}) { |
| 124 | l.merge(line{ |
| 125 | level: capnslog.WARNING, |
| 126 | str: fmt.Sprint(entries...), |
| 127 | }) |
| 128 | } |
| 129 | |
| 130 | func (l *MergeLogger) MergeWarningf(format string, args ...interface{}) { |
| 131 | l.merge(line{ |
| 132 | level: capnslog.WARNING, |
| 133 | str: fmt.Sprintf(format, args...), |
| 134 | }) |
| 135 | } |
| 136 | |
| 137 | func (l *MergeLogger) MergeError(entries ...interface{}) { |
| 138 | l.merge(line{ |
| 139 | level: capnslog.ERROR, |
| 140 | str: fmt.Sprint(entries...), |
| 141 | }) |
| 142 | } |
| 143 | |
| 144 | func (l *MergeLogger) MergeErrorf(format string, args ...interface{}) { |
| 145 | l.merge(line{ |
| 146 | level: capnslog.ERROR, |
| 147 | str: fmt.Sprintf(format, args...), |
| 148 | }) |
| 149 | } |
| 150 | |
| 151 | func (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 | |
| 172 | func (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 | } |