Matthias Andreas Benkard | 832a54e | 2019-01-29 09:27:38 +0100 | [diff] [blame^] | 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. |
| 22 | package lumberjack |
| 23 | |
| 24 | import ( |
| 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 | |
| 38 | const ( |
| 39 | backupTimeFormat = "2006-01-02T15-04-05.000" |
| 40 | compressSuffix = ".gz" |
| 41 | defaultMaxSize = 100 |
| 42 | ) |
| 43 | |
| 44 | // ensure we always implement io.WriteCloser |
| 45 | var _ 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. |
| 79 | type 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. |
| 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 | |
| 118 | var ( |
| 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 | os_Stat = 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. |
| 135 | func (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. |
| 165 | func (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. |
| 172 | func (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. |
| 186 | func (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. |
| 195 | func (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. |
| 208 | func (l *Logger) openNew() error { |
| 209 | err := os.MkdirAll(l.dir(), 0744) |
| 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(0644) |
| 216 | info, err := os_Stat(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). |
| 247 | func 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. |
| 264 | func (l *Logger) openExistingOrNew(writeLen int) error { |
| 265 | l.mill() |
| 266 | |
| 267 | filename := l.filename() |
| 268 | info, err := os_Stat(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 | // genFilename generates the name of the logfile from the current time. |
| 292 | func (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. |
| 304 | func (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. |
| 378 | func (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. |
| 387 | func (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 |
| 400 | func (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. |
| 433 | func (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. |
| 445 | func (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. |
| 453 | func (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. |
| 459 | func (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. |
| 468 | func 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 := os_Stat(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. |
| 523 | type logInfo struct { |
| 524 | timestamp time.Time |
| 525 | os.FileInfo |
| 526 | } |
| 527 | |
| 528 | // byFormatTime sorts by newest time formatted in the name. |
| 529 | type byFormatTime []logInfo |
| 530 | |
| 531 | func (b byFormatTime) Less(i, j int) bool { |
| 532 | return b[i].timestamp.After(b[j].timestamp) |
| 533 | } |
| 534 | |
| 535 | func (b byFormatTime) Swap(i, j int) { |
| 536 | b[i], b[j] = b[j], b[i] |
| 537 | } |
| 538 | |
| 539 | func (b byFormatTime) Len() int { |
| 540 | return len(b) |
| 541 | } |