natefinch / lumberjack

lumberjack is a log rolling package for Go
MIT License
4.76k stars 585 forks source link

Strange behavior in truncate #143

Closed thevirus20 closed 2 years ago

thevirus20 commented 2 years ago

Well, I have been using it since quite a sometime but I have got new requirement of generating a file containing a few comma separated value. I truncate it every 15 minute using cron, it worked for few days but lately I am getting strange issue of file getting to old size after app starts writing in it after truncating. So if at time of truncate file size was 700MB, it get truncated by cron but when app start writing again in it after few second, it start with 700MB with head -n1 file.log failing to show any output. nor vim works on file, Only tail -f file.log work confirming that its being written at the last, but sure what is the issue with the start/head of the file as it is not showing the output.

I am using it with Zap Logger

               writer := zapcore.AddSync(&lumberjack.Logger{
            Filename: "file.log",
            MaxSize:  10000,  //in MB
            Compress: false, //gzip
            MaxAge:   28,   //days
        })
        core := zapcore.NewCore(encoder, writer, level)
        cores = append(cores, core)

I even tried to truncate file using the app itself by creating a custom url like this and calling it from with cron instead of bash command.

      r.GET("/logs/truncate", func(ctx *fasthttp.RequestCtx) {

        file, err := os.OpenFile("file.log", os.O_CREATE|os.O_WRONLY, 0666)
        if err == nil {
            _ = file.Truncate(0)
            _, _ = fmt.Fprint(ctx, "success")
        } else {
            _, _ = fmt.Fprint(ctx, "error")
        }
    })

But this also doesn't worked, file size kept on increasing sometime. I have this code on 3 server and this issue has been happening randomly on 2 server. Though it has been mentioned in #25 and file itself about multi process write will result in improper behavior still What you think could be the issue here? Any workaround...? Also is there way to rotate the file based on time instead of size?

thevirus20 commented 2 years ago

This is how the content looks on windows after truncating the file using the url.

Screenshot 2021-10-27 at 1 24 51 AM

On server its like this.

Screenshot 2021-10-27 at 1 25 04 AM

The null or ^@ character have the same size as it was before truncate, this might be the reason head -n1/vim were failing as mentioned above.

Please check if this could be fixed somehow or any other workaround for this.

thevirus20 commented 2 years ago

It seems I needed to add call to Seek method as well, will check if this fixes the issue, will close this then.

_ , _ = file.Seek(0, 0)
thevirus20 commented 2 years ago

This doesn't work as well.

r.GET("/logs/truncate", func(ctx *fasthttp.RequestCtx) {

        file, err := os.OpenFile("file.log", os.O_CREATE|os.O_WRONLY, 0666)
        if err == nil {
            _ = file.Truncate(0)
            _ , _ = file.Seek(0, io.SeekStart)
            _, _ = fmt.Fprint(ctx, "success")
        } else {
            _, _ = fmt.Fprint(ctx, "error")
        }
    })

Although I have specified to rotate on 1500MB, still sometime it rotate the file say at 280MB then the issue with truncate start. I could have deleted the file, but as mentioned here #52 , it require program to restart to create the file. Is there a way to force rotate at least if I can't on time?

natefinch commented 2 years ago

You can't have other software fiddling with the file that lumberjack controls. Lumberjack needs to be the sole controller of the file. Lumberjack has an internal pointer to the file where it last wrote. If some outside process truncates the file, lumberjack doesn't know that, and will continue to write to the last place on disk where it thinks it should be writing.

I'm not sure why you'd use cron to truncate the file if you're using lumberjack to rotate it. Pick one or the other. They can't both work.

thevirus20 commented 2 years ago

Yes, as I mentioned I now truncate the file using the url based route which is called by the cron every 15 minute. I want it to rotate on 15 min, or at least is there way from the package to truncate or reset the pointer to start of the file? Another workaround is to reinitialized the logger every 15 min.