1// Package lumberjack provides a rolling logger.
  2//
  3// Note that this is v2.0 of lumberjack, and should be imported using gopkg.in
  4// thusly:
  5//
  6//   import "gopkg.in/natefinch/lumberjack.v2"
  7//
  8// The package name remains simply lumberjack, and the code resides at
  9// https://github.com/natefinch/lumberjack under the v2.0 branch.
 10//
 11// Lumberjack is intended to be one part of a logging infrastructure.
 12// It is not an all-in-one solution, but instead is a pluggable
 13// component at the bottom of the logging stack that simply controls the files
 14// to which logs are written.
 15//
 16// Lumberjack plays well with any logging package that can write to an
 17// io.Writer, including the standard library's log package.
 18//
 19// Lumberjack assumes that only one process is writing to the output files.
 20// Using the same lumberjack configuration from multiple processes on the same
 21// machine will result in improper behavior.
 22package lumberjack
 23
 24import (
 25	"compress/gzip"
 26	"errors"
 27	"fmt"
 28	"io"
 29	"io/ioutil"
 30	"os"
 31	"path/filepath"
 32	"sort"
 33	"strings"
 34	"sync"
 35	"time"
 36)
 37
 38const (
 39	backupTimeFormat = "2006-01-02T15-04-05.000"
 40	compressSuffix   = ".gz"
 41	defaultMaxSize   = 100
 42)
 43
 44// ensure we always implement io.WriteCloser
 45var _ io.WriteCloser = (*Logger)(nil)
 46
 47// Logger is an io.WriteCloser that writes to the specified filename.
 48//
 49// Logger opens or creates the logfile on first Write.  If the file exists and
 50// is less than MaxSize megabytes, lumberjack will open and append to that file.
 51// If the file exists and its size is >= MaxSize megabytes, the file is renamed
 52// by putting the current time in a timestamp in the name immediately before the
 53// file's extension (or the end of the filename if there's no extension). A new
 54// log file is then created using original filename.
 55//
 56// Whenever a write would cause the current log file exceed MaxSize megabytes,
 57// the current file is closed, renamed, and a new log file created with the
 58// original name. Thus, the filename you give Logger is always the "current" log
 59// file.
 60//
 61// Backups use the log file name given to Logger, in the form
 62// `name-timestamp.ext` where name is the filename without the extension,
 63// timestamp is the time at which the log was rotated formatted with the
 64// time.Time format of `2006-01-02T15-04-05.000` and the extension is the
 65// original extension.  For example, if your Logger.Filename is
 66// `/var/log/foo/server.log`, a backup created at 6:30pm on Nov 11 2016 would
 67// use the filename `/var/log/foo/server-2016-11-04T18-30-00.000.log`
 68//
 69// Cleaning Up Old Log Files
 70//
 71// Whenever a new logfile gets created, old log files may be deleted.  The most
 72// recent files according to the encoded timestamp will be retained, up to a
 73// number equal to MaxBackups (or all of them if MaxBackups is 0).  Any files
 74// with an encoded timestamp older than MaxAge days are deleted, regardless of
 75// MaxBackups.  Note that the time encoded in the timestamp is the rotation
 76// time, which may differ from the last time that file was written to.
 77//
 78// If MaxBackups and MaxAge are both 0, no old log files will be deleted.
 79type Logger struct {
 80	// Filename is the file to write logs to.  Backup log files will be retained
 81	// in the same directory.  It uses <processname>-lumberjack.log in
 82	// os.TempDir() if empty.
 83	Filename string `json:"filename" yaml:"filename"`
 84
 85	// MaxSize is the maximum size in megabytes of the log file before it gets
 86	// rotated. It defaults to 100 megabytes.
 87	MaxSize int `json:"maxsize" yaml:"maxsize"`
 88
 89	// MaxAge is the maximum number of days to retain old log files based on the
 90	// timestamp encoded in their filename.  Note that a day is defined as 24
 91	// hours and may not exactly correspond to calendar days due to daylight
 92	// savings, leap seconds, etc. The default is not to remove old log files
 93	// based on age.
 94	MaxAge int `json:"maxage" yaml:"maxage"`
 95
 96	// MaxBackups is the maximum number of old log files to retain.  The default
 97	// is to retain all old log files (though MaxAge may still cause them to get
 98	// deleted.)
 99	MaxBackups int `json:"maxbackups" yaml:"maxbackups"`
100
101	// LocalTime determines if the time used for formatting the timestamps in
102	// backup files is the computer's local time.  The default is to use UTC
103	// time.
104	LocalTime bool `json:"localtime" yaml:"localtime"`
105
106	// Compress determines if the rotated log files should be compressed
107	// using gzip. The default is not to perform compression.
108	Compress bool `json:"compress" yaml:"compress"`
109
110	size int64
111	file *os.File
112	mu   sync.Mutex
113
114	millCh    chan bool
115	startMill sync.Once
116}
117
118var (
119	// currentTime exists so it can be mocked out by tests.
120	currentTime = time.Now
121
122	// os_Stat exists so it can be mocked out by tests.
123	osStat = os.Stat
124
125	// megabyte is the conversion factor between MaxSize and bytes.  It is a
126	// variable so tests can mock it out and not need to write megabytes of data
127	// to disk.
128	megabyte = 1024 * 1024
129)
130
131// Write implements io.Writer.  If a write would cause the log file to be larger
132// than MaxSize, the file is closed, renamed to include a timestamp of the
133// current time, and a new log file is created using the original log file name.
134// If the length of the write is greater than MaxSize, an error is returned.
135func (l *Logger) Write(p []byte) (n int, err error) {
136	l.mu.Lock()
137	defer l.mu.Unlock()
138
139	writeLen := int64(len(p))
140	if writeLen > l.max() {
141		return 0, fmt.Errorf(
142			"write length %d exceeds maximum file size %d", writeLen, l.max(),
143		)
144	}
145
146	if l.file == nil {
147		if err = l.openExistingOrNew(len(p)); err != nil {
148			return 0, err
149		}
150	}
151
152	if l.size+writeLen > l.max() {
153		if err := l.rotate(); err != nil {
154			return 0, err
155		}
156	}
157
158	n, err = l.file.Write(p)
159	l.size += int64(n)
160
161	return n, err
162}
163
164// Close implements io.Closer, and closes the current logfile.
165func (l *Logger) Close() error {
166	l.mu.Lock()
167	defer l.mu.Unlock()
168	return l.close()
169}
170
171// close closes the file if it is open.
172func (l *Logger) close() error {
173	if l.file == nil {
174		return nil
175	}
176	err := l.file.Close()
177	l.file = nil
178	return err
179}
180
181// Rotate causes Logger to close the existing log file and immediately create a
182// new one.  This is a helper function for applications that want to initiate
183// rotations outside of the normal rotation rules, such as in response to
184// SIGHUP.  After rotating, this initiates compression and removal of old log
185// files according to the configuration.
186func (l *Logger) Rotate() error {
187	l.mu.Lock()
188	defer l.mu.Unlock()
189	return l.rotate()
190}
191
192// rotate closes the current file, moves it aside with a timestamp in the name,
193// (if it exists), opens a new file with the original filename, and then runs
194// post-rotation processing and removal.
195func (l *Logger) rotate() error {
196	if err := l.close(); err != nil {
197		return err
198	}
199	if err := l.openNew(); err != nil {
200		return err
201	}
202	l.mill()
203	return nil
204}
205
206// openNew opens a new log file for writing, moving any old log file out of the
207// way.  This methods assumes the file has already been closed.
208func (l *Logger) openNew() error {
209	err := os.MkdirAll(l.dir(), 0755)
210	if err != nil {
211		return fmt.Errorf("can't make directories for new logfile: %s", err)
212	}
213
214	name := l.filename()
215	mode := os.FileMode(0600)
216	info, err := osStat(name)
217	if err == nil {
218		// Copy the mode off the old logfile.
219		mode = info.Mode()
220		// move the existing file
221		newname := backupName(name, l.LocalTime)
222		if err := os.Rename(name, newname); err != nil {
223			return fmt.Errorf("can't rename log file: %s", err)
224		}
225
226		// this is a no-op anywhere but linux
227		if err := chown(name, info); err != nil {
228			return err
229		}
230	}
231
232	// we use truncate here because this should only get called when we've moved
233	// the file ourselves. if someone else creates the file in the meantime,
234	// just wipe out the contents.
235	f, err := os.OpenFile(name, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, mode)
236	if err != nil {
237		return fmt.Errorf("can't open new logfile: %s", err)
238	}
239	l.file = f
240	l.size = 0
241	return nil
242}
243
244// backupName creates a new filename from the given name, inserting a timestamp
245// between the filename and the extension, using the local time if requested
246// (otherwise UTC).
247func backupName(name string, local bool) string {
248	dir := filepath.Dir(name)
249	filename := filepath.Base(name)
250	ext := filepath.Ext(filename)
251	prefix := filename[:len(filename)-len(ext)]
252	t := currentTime()
253	if !local {
254		t = t.UTC()
255	}
256
257	timestamp := t.Format(backupTimeFormat)
258	return filepath.Join(dir, fmt.Sprintf("%s-%s%s", prefix, timestamp, ext))
259}
260
261// openExistingOrNew opens the logfile if it exists and if the current write
262// would not put it over MaxSize.  If there is no such file or the write would
263// put it over the MaxSize, a new file is created.
264func (l *Logger) openExistingOrNew(writeLen int) error {
265	l.mill()
266
267	filename := l.filename()
268	info, err := osStat(filename)
269	if os.IsNotExist(err) {
270		return l.openNew()
271	}
272	if err != nil {
273		return fmt.Errorf("error getting log file info: %s", err)
274	}
275
276	if info.Size()+int64(writeLen) >= l.max() {
277		return l.rotate()
278	}
279
280	file, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY, 0644)
281	if err != nil {
282		// if we fail to open the old log file for some reason, just ignore
283		// it and open a new log file.
284		return l.openNew()
285	}
286	l.file = file
287	l.size = info.Size()
288	return nil
289}
290
291// filename generates the name of the logfile from the current time.
292func (l *Logger) filename() string {
293	if l.Filename != "" {
294		return l.Filename
295	}
296	name := filepath.Base(os.Args[0]) + "-lumberjack.log"
297	return filepath.Join(os.TempDir(), name)
298}
299
300// millRunOnce performs compression and removal of stale log files.
301// Log files are compressed if enabled via configuration and old log
302// files are removed, keeping at most l.MaxBackups files, as long as
303// none of them are older than MaxAge.
304func (l *Logger) millRunOnce() error {
305	if l.MaxBackups == 0 && l.MaxAge == 0 && !l.Compress {
306		return nil
307	}
308
309	files, err := l.oldLogFiles()
310	if err != nil {
311		return err
312	}
313
314	var compress, remove []logInfo
315
316	if l.MaxBackups > 0 && l.MaxBackups < len(files) {
317		preserved := make(map[string]bool)
318		var remaining []logInfo
319		for _, f := range files {
320			// Only count the uncompressed log file or the
321			// compressed log file, not both.
322			fn := f.Name()
323			if strings.HasSuffix(fn, compressSuffix) {
324				fn = fn[:len(fn)-len(compressSuffix)]
325			}
326			preserved[fn] = true
327
328			if len(preserved) > l.MaxBackups {
329				remove = append(remove, f)
330			} else {
331				remaining = append(remaining, f)
332			}
333		}
334		files = remaining
335	}
336	if l.MaxAge > 0 {
337		diff := time.Duration(int64(24*time.Hour) * int64(l.MaxAge))
338		cutoff := currentTime().Add(-1 * diff)
339
340		var remaining []logInfo
341		for _, f := range files {
342			if f.timestamp.Before(cutoff) {
343				remove = append(remove, f)
344			} else {
345				remaining = append(remaining, f)
346			}
347		}
348		files = remaining
349	}
350
351	if l.Compress {
352		for _, f := range files {
353			if !strings.HasSuffix(f.Name(), compressSuffix) {
354				compress = append(compress, f)
355			}
356		}
357	}
358
359	for _, f := range remove {
360		errRemove := os.Remove(filepath.Join(l.dir(), f.Name()))
361		if err == nil && errRemove != nil {
362			err = errRemove
363		}
364	}
365	for _, f := range compress {
366		fn := filepath.Join(l.dir(), f.Name())
367		errCompress := compressLogFile(fn, fn+compressSuffix)
368		if err == nil && errCompress != nil {
369			err = errCompress
370		}
371	}
372
373	return err
374}
375
376// millRun runs in a goroutine to manage post-rotation compression and removal
377// of old log files.
378func (l *Logger) millRun() {
379	for range l.millCh {
380		// what am I going to do, log this?
381		_ = l.millRunOnce()
382	}
383}
384
385// mill performs post-rotation compression and removal of stale log files,
386// starting the mill goroutine if necessary.
387func (l *Logger) mill() {
388	l.startMill.Do(func() {
389		l.millCh = make(chan bool, 1)
390		go l.millRun()
391	})
392	select {
393	case l.millCh <- true:
394	default:
395	}
396}
397
398// oldLogFiles returns the list of backup log files stored in the same
399// directory as the current log file, sorted by ModTime
400func (l *Logger) oldLogFiles() ([]logInfo, error) {
401	files, err := ioutil.ReadDir(l.dir())
402	if err != nil {
403		return nil, fmt.Errorf("can't read log file directory: %s", err)
404	}
405	logFiles := []logInfo{}
406
407	prefix, ext := l.prefixAndExt()
408
409	for _, f := range files {
410		if f.IsDir() {
411			continue
412		}
413		if t, err := l.timeFromName(f.Name(), prefix, ext); err == nil {
414			logFiles = append(logFiles, logInfo{t, f})
415			continue
416		}
417		if t, err := l.timeFromName(f.Name(), prefix, ext+compressSuffix); err == nil {
418			logFiles = append(logFiles, logInfo{t, f})
419			continue
420		}
421		// error parsing means that the suffix at the end was not generated
422		// by lumberjack, and therefore it's not a backup file.
423	}
424
425	sort.Sort(byFormatTime(logFiles))
426
427	return logFiles, nil
428}
429
430// timeFromName extracts the formatted time from the filename by stripping off
431// the filename's prefix and extension. This prevents someone's filename from
432// confusing time.parse.
433func (l *Logger) timeFromName(filename, prefix, ext string) (time.Time, error) {
434	if !strings.HasPrefix(filename, prefix) {
435		return time.Time{}, errors.New("mismatched prefix")
436	}
437	if !strings.HasSuffix(filename, ext) {
438		return time.Time{}, errors.New("mismatched extension")
439	}
440	ts := filename[len(prefix) : len(filename)-len(ext)]
441	return time.Parse(backupTimeFormat, ts)
442}
443
444// max returns the maximum size in bytes of log files before rolling.
445func (l *Logger) max() int64 {
446	if l.MaxSize == 0 {
447		return int64(defaultMaxSize * megabyte)
448	}
449	return int64(l.MaxSize) * int64(megabyte)
450}
451
452// dir returns the directory for the current filename.
453func (l *Logger) dir() string {
454	return filepath.Dir(l.filename())
455}
456
457// prefixAndExt returns the filename part and extension part from the Logger's
458// filename.
459func (l *Logger) prefixAndExt() (prefix, ext string) {
460	filename := filepath.Base(l.filename())
461	ext = filepath.Ext(filename)
462	prefix = filename[:len(filename)-len(ext)] + "-"
463	return prefix, ext
464}
465
466// compressLogFile compresses the given log file, removing the
467// uncompressed log file if successful.
468func compressLogFile(src, dst string) (err error) {
469	f, err := os.Open(src)
470	if err != nil {
471		return fmt.Errorf("failed to open log file: %v", err)
472	}
473	defer f.Close()
474
475	fi, err := osStat(src)
476	if err != nil {
477		return fmt.Errorf("failed to stat log file: %v", err)
478	}
479
480	if err := chown(dst, fi); err != nil {
481		return fmt.Errorf("failed to chown compressed log file: %v", err)
482	}
483
484	// If this file already exists, we presume it was created by
485	// a previous attempt to compress the log file.
486	gzf, err := os.OpenFile(dst, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, fi.Mode())
487	if err != nil {
488		return fmt.Errorf("failed to open compressed log file: %v", err)
489	}
490	defer gzf.Close()
491
492	gz := gzip.NewWriter(gzf)
493
494	defer func() {
495		if err != nil {
496			os.Remove(dst)
497			err = fmt.Errorf("failed to compress log file: %v", err)
498		}
499	}()
500
501	if _, err := io.Copy(gz, f); err != nil {
502		return err
503	}
504	if err := gz.Close(); err != nil {
505		return err
506	}
507	if err := gzf.Close(); err != nil {
508		return err
509	}
510
511	if err := f.Close(); err != nil {
512		return err
513	}
514	if err := os.Remove(src); err != nil {
515		return err
516	}
517
518	return nil
519}
520
521// logInfo is a convenience struct to return the filename and its embedded
522// timestamp.
523type logInfo struct {
524	timestamp time.Time
525	os.FileInfo
526}
527
528// byFormatTime sorts by newest time formatted in the name.
529type byFormatTime []logInfo
530
531func (b byFormatTime) Less(i, j int) bool {
532	return b[i].timestamp.After(b[j].timestamp)
533}
534
535func (b byFormatTime) Swap(i, j int) {
536	b[i], b[j] = b[j], b[i]
537}
538
539func (b byFormatTime) Len() int {
540	return len(b)
541}