Adds gzip compression to backup log files #16

donovansolms · Oct 27, 2015

This PR adds gzip compression to backup log files via the CompressBackups config option. Tests added and passed. Please let me know if I missed anything.
Note: We're using this library in production (including gzipped backups) with max size as 100MB. Compression doesn't have any noticeable performance impact aside from saving a lot of drive space.

donovansolms · Oct 27, 2015

I see the failed test on AppVeyor. I'll investigate the "The process cannot access the file because it is being used by another process" error and resolve.

natefinch · Oct 27, 2015

Thats super common if you have code that tries to delete or rename a file
before closing it on windows. It works on Linux but not windows.

On Tue, Oct 27, 2015, 10:40 AM Donovan Solms notifications@github.com
wrote:

I see the failed test on AppVeyor. I'll investigate the "The process
cannot access the file because it is being used by another process" error
and resolve.

—
Reply to this email directly or view it on GitHub
#16 (comment).

donovansolms · Oct 28, 2015

I've fixed the issue on Windows. The original file was being close with a defer but renamed before the defer could execute.

Let me know if you would like more tests for this feature, I'm happy to add them.

natefinch · Oct 28, 2015

natefinch reviewed Oct 28, 2015

View changes

You can't do that. What if the file is 500mb? You'll allocate 500mb of RÅM on this one line.
You should just open a new file, wrap the file in a gzipwriter and use io.copy to copy from the old file to the new.

Thanks for pointing that out, let me fix that.

natefinch · Oct 28, 2015

natefinch reviewed Oct 28, 2015

View changes

You don't really need this. This is not a general function that will be used by third parties... it's used in exactly one place, and we know the filename won't be empty. Plus, os.Open will return an error if you try to open an empy filename.

natefinch · Oct 28, 2015

natefinch reviewed Oct 28, 2015

View changes

please use the single line form of the if statement here

if err := compressLog(newname); err != nil {

donovansolms · Oct 28, 2015

I've fixed the large allocation issue, thanks for pointing that out. I also updated the code style to fit the rest with the single line form if. Finally I updated the test to verify that the compressed file actually contains the content originally written to it.

Please let me know if I misunderstood anything.

s7v7nislands · Oct 19, 2016

ping, will this merged?

natefinch · Oct 19, 2016

I'll take a look at this today. Sorry for the delay..

natefinch · Oct 24, 2016

natefinch requested changes Oct 24, 2016

View changes

This looks mostly ok (with a couple tweaks), but there's a piece that is missing. The problem comes with robustness - if the program goes down before finishing compressing the backup, it should figure that out when it starts back up and try again. This is a little tricky, but seems doable.

Also, I have one general style comment - many of the comments you have added state what the code is doing, rather than why its doing it. Most of the time, the what should be pretty obvious (there are exceptions, but not usually in simple code like this). I suggest removing most of the comments you added about what the code is doing, unless you think it's unclear what the code is intending to do.

this should really just be if l.CompressBackups { - no need to check == true.

The problem with this is that a simple log statement is now going to be blocked on gzipping a multi megabyte log file. This should probably be run in a goroutine so it won't block the program.... probably making this part of the deleteAll method (and renaming it to cleanup() or something) would be a good idea.

you can (and should) defer reader.Close() here even if you explicitly close it later... multiple closes are ok on files.

newhook · Oct 27, 2016

@donovansolms Are you planning on addressing Nate's comments? We need this code for our production systems, so if you are not going to be able to address them in short order I can take a look.

donovansolms · Oct 28, 2016

Hi, yes @newhook, apologies, will get to this over the weekend.

donovansolms · Oct 31, 2016

@natefinch Thanks for the review. I've made the style changes and added the robustness.

I moved the compression of logs to cleanup which is triggered on rotate. It now checks for any logs that have not been compressed and compresses them in a separate goroutine.

When a log file is missed due to the application going down while compressing, it will be compressed on the next rotate. For my use case that is acceptable, what is your opinion?

natefinch · Nov 1, 2016

I don't think it's ok to wait until the next rotate to compress the file. The problem is that instead of a nicely compressed backup (usually, what, like 10-20% of uncompressed size?), you'll have the full size log file there... which if you need that space, could screw you up.

And actually, this brings up an interesting point about compressed backups... it changes the math you need to do for how much space you're using. Before, 100MB max size with 3 backups meant the max you'd use is 400MB of disk space (main log + 3 backups)... but now that same config would be generally far less... but's it's nondeterministic just how much space you'd be using, since it would depend on the compression ratio.

I'm not a huge fan of nondeterministic results, but I'm not exactly sure how to fix that problem, so that people can know the max amount of disk space their configuration will use. Any suggestions on a nice user experience for this that doesn't totally break backwards compatibility would be good.

I'll review the actual changes probably tomorrow, maybe tonight if I have more time than I expect.

donovansolms · Nov 1, 2016

No problem. I'll add compressing the missed file(s) on startup (probably around openExistingOrNew) as well in the morning. I'll need a lock to ensure different routines don't attempt compressing the same file - if a log is rotated before the startup log compression completes.

I get what you are saying about calculating the max amount of space the configuration will use, I also don't have a clear answer to that at the moment.

newhook · Nov 1, 2016

I'm not sure I see a huge need to compress immediately especially if it makes the code more complex and potentially brittle. If you change the logging parameters (unless this has changed) log files are not cleaned up until rotation, so this seems to be a similar situation.

donovansolms · Nov 2, 2016

The change sounded more complicated than it turned out to be. After the log file is created or opened on startup, compressLogs is executed in a new goroutine. It is protected by the cmu mutex to avoid multiple routines attempting to compress the same files. This allows that compression not block the application on startup.

newhook · Nov 15, 2016

Is there something more to do for this PR?

natefinch · Nov 17, 2016

I'll take a look this weekend. Sorry, been slammed with other things lately.

newhook · Nov 17, 2016

I've merged this and have been using it production for a few days now. Seems to work! I think I'd prefer though if Close would block until any outstanding compression is complete.

natefinch · Nov 24, 2016

natefinch requested changes Nov 24, 2016

View changes

Looking better, still a few niggles. Sounds like this is something Canonical is going to want, so I may be able to work on this during work hours, which would greatly increase my ability to spend time on it, hopefully starting next week.

This doesn't actually do anything. It returns a new error that is then discarded. Ideas on how to handle errors from here are welcome, for sure. Generally one would just log them, but.... we're kind low level for that. Maybe let the user pass in a method to handle compression failures? I don't know.

includeCompressed is not doing what it seems like you're saying it's doing. It's not one or both, it's one or the other. When you use includeCompressed, it'll never return uncompressed files, because they don't have a matching extension. That's not exactly ok, since this could skip a file that hasn't been compressed yet.

This should probably not be called reader. Input or something would be better. Reader I generally reserve only for actual io.Reader values.

we should clean up the gz file... this will leave it hanging about.

donovansolms · Nov 24, 2016

Thanks for the update @natefinch. We're really busy in December, so I might not get to this before the end of the year. If you say Canonical might want it, is it not worth rather going with the suggestions in Issue #13 (Compressing rolled files) so as to not lock this to gzip?

natefinch · Nov 24, 2016

That's ok, I may tackle this myself next week.

howbazaar · Apr 5, 2017

ping... any progress?

natefinch · Apr 5, 2017

I'll take a look in the morning.

…

natefinch · Apr 5, 2017

It was late when I was looking at this, so I forgot where we were. I haven't really had the time to spend on this. I think this PR could be a starting off point, but it still needs a lot of thought. there's basically three things you have to think about:

The compression should happen on a background goroutine, to make sure that we don't block writes to the main log file for any longer than necessary.
The code currently looks for *.log files to determine how many backup files already exist on disk, so we need to modify that to ensure that it checks for compressed logs as well.
The code has to be smart enough to handle getting killed in the middle of compression. Thus, it'll need to look for uncompressed files on startup, as well as clean up any temporary files that were created while compressing.
We have to compress to a temporary file and then rename that file to the final name when it's finished, and then remove the uncompressed file.

howbazaar · Apr 5, 2017

How would you feel about juju devs picking this up?

natefinch · Apr 5, 2017

Please feel free. I'll give reviews high priority.

natefinch · May 31, 2017

This is implemented in #43

Adds gzip compression to backup log files

6cbcba3

Close the original log file without defer before remove

9d8e129

Fixed inefficient buffer copying in the compression function to use
io.Copy Updated code style to fit single line form 'if err' statement

6e836ae

Added robustness to compressed logs
Updated style

6a482fa

Added compression on startup for (possibly) missed files

23f742a

natefinch closed this May 31, 2017

@@ -205,6 +214,14 @@ func (l *Logger) openNew() error {
          			return fmt.Errorf("can't rename log file: %s", err)
          		}
+        +		// Compress the backup if enabled
+        +		if l.CompressBackups == true {
+        +			err := compressLog(newname)

@@ -205,6 +211,13 @@ func (l *Logger) openNew() error {
          			return fmt.Errorf("can't rename log file: %s", err)
          		}
+        +		// Compress the backup if enabled
+        +		if l.CompressBackups == true {

@@ -205,6 +211,13 @@ func (l *Logger) openNew() error {
          			return fmt.Errorf("can't rename log file: %s", err)
          		}
+        +		// Compress the backup if enabled
+        +		if l.CompressBackups == true {
+        +			if err := compressLog(newname); err != nil {

+        +	defer l.cmu.Unlock()
+        +	files, err := l.oldLogFiles(false)
+        +	if err != nil {
+        +		fmt.Errorf("Unable to compress log files: %s", err)

+        +// directory as the current log file, sorted by ModTime. Setting
+        +// includeCompressed to true will include files with the given
+        +// compressFileExtension into the returned list
+        +func (l *Logger) oldLogFiles(includeCompressed bool) ([]logInfo, error) {

natefinch/lumberjack

Adds gzip compression to backup log files #16

donovansolms commented Oct 27, 2015

donovansolms commented Oct 27, 2015

natefinch commented Oct 27, 2015

donovansolms commented Oct 28, 2015

natefinch reviewed Oct 28, 2015

View changes

natefinch reviewed Oct 28, 2015

View changes

natefinch reviewed Oct 28, 2015

View changes

donovansolms commented Oct 28, 2015

s7v7nislands commented Oct 19, 2016

natefinch commented Oct 19, 2016

natefinch requested changes Oct 24, 2016

View changes

newhook commented Oct 27, 2016

donovansolms commented Oct 28, 2016

donovansolms commented Oct 31, 2016

natefinch commented Nov 1, 2016

donovansolms commented Nov 1, 2016 •

Edited 1 time

donovansolms
Nov 1, 2016

newhook commented Nov 1, 2016

donovansolms commented Nov 2, 2016

newhook commented Nov 15, 2016

natefinch commented Nov 17, 2016

newhook commented Nov 17, 2016

natefinch requested changes Nov 24, 2016

View changes

donovansolms commented Nov 24, 2016 •

Edited 1 time

donovansolms
Nov 24, 2016

natefinch commented Nov 24, 2016

howbazaar commented Apr 5, 2017

natefinch commented Apr 5, 2017

natefinch commented Apr 5, 2017 •

Edited 1 time

natefinch
Apr 5, 2017

howbazaar commented Apr 5, 2017

natefinch commented Apr 5, 2017

natefinch commented May 31, 2017

natefinch closed this May 31, 2017

natefinch/lumberjack

Join GitHub today

Adds gzip compression to backup log files #16

Conversation

donovansolms commented Oct 27, 2015

donovansolms commented Oct 27, 2015

natefinch commented Oct 27, 2015

donovansolms commented Oct 28, 2015

natefinch reviewed Oct 28, 2015 View changes

natefinch reviewed Oct 28, 2015 View changes

natefinch reviewed Oct 28, 2015 View changes

donovansolms commented Oct 28, 2015

s7v7nislands commented Oct 19, 2016

natefinch commented Oct 19, 2016

natefinch requested changes Oct 24, 2016 View changes

newhook commented Oct 27, 2016

donovansolms commented Oct 28, 2016

donovansolms commented Oct 31, 2016

natefinch commented Nov 1, 2016

donovansolms commented Nov 1, 2016 • edited Edited 1 time donovansolms Nov 1, 2016

newhook commented Nov 1, 2016

donovansolms commented Nov 2, 2016

newhook commented Nov 15, 2016

natefinch commented Nov 17, 2016

newhook commented Nov 17, 2016

natefinch requested changes Nov 24, 2016 View changes

donovansolms commented Nov 24, 2016 • edited Edited 1 time donovansolms Nov 24, 2016

natefinch commented Nov 24, 2016

howbazaar commented Apr 5, 2017

natefinch commented Apr 5, 2017

natefinch commented Apr 5, 2017 • edited Edited 1 time natefinch Apr 5, 2017

howbazaar commented Apr 5, 2017

natefinch commented Apr 5, 2017

natefinch commented May 31, 2017

natefinch closed this May 31, 2017

natefinch reviewed Oct 28, 2015

View changes

natefinch reviewed Oct 28, 2015

View changes

natefinch reviewed Oct 28, 2015

View changes

natefinch requested changes Oct 24, 2016

View changes

donovansolms commented Nov 1, 2016 •

Edited 1 time

donovansolms
Nov 1, 2016

natefinch requested changes Nov 24, 2016

View changes

donovansolms commented Nov 24, 2016 •

Edited 1 time

donovansolms
Nov 24, 2016

natefinch commented Apr 5, 2017 •

Edited 1 time

natefinch
Apr 5, 2017