natefinch / lumberjack

lumberjack is a log rolling package for Go
MIT License
4.8k stars 591 forks source link

Rotation loses data #34

Closed alejandro-molina closed 7 years ago

alejandro-molina commented 7 years ago

testing this code with sleep works, but without sleep, it's losing the file that should contain "1"

dir, err := ioutil.TempDir("/tmp", "testrotation")

if err != nil {
    log.Fatal(err)
}

fmt.Println(dir)

tmpfn := filepath.Join(dir, "tmpfile.txt")
logger := &lumberjack.Logger{
    Filename:   tmpfn,
    MaxSize:    1, //rotate logs if it reaches 1 megabyte
}

log.SetOutput(logger)

log.Println("1")
logger.Rotate()
log.Println("2")
time.Sleep(2000 * time.Millisecond)
logger.Rotate()
log.Println("3")
natefinch commented 7 years ago

So, this is a bug, technically. But in reality, it's not something that should ever get hit.

The problem is that the backup files are expected to always be unique because of their timestamp. However, the timestamp only has millisecond resolution. If you rotate the file twice during the same millisecond, then both backup files will have the same name, and you'll end up overwriting the first one.

This could be mitigated by changing the resolution of the timestamp to go down to the microsecond or even nanosecond resolution.... however, in a real system, you'd basically never actually rotate logs twice in the same millisecond.

If this is actually causing a bug in production code, I could change the timestamp, but this is non-trivial, since we have to be backward compatible with existing backup files that use the old timestamp.

Thanks for bringing this to my attention. While I don't think anyone would actually hit this in production, it is something to think about for any future iterations. And again, if this actually causes problems with you code, please let me know and I will fix it.