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 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} 196