New feature: log rotation #426

tzdybal · 2017-12-07T15:36:32Z

Changes in logger/glog and cmd/geth to implement highly configurable log rotation.
This resolves #421.

This is limited to time & size based rotation + log compression.

tzdybal · 2017-12-07T15:39:19Z

I'll add one more thing - parsing of human readable sizes (like 512K, 10M, 2G).

whilei · 2017-12-07T17:33:50Z

cmd/geth/flags.go

+		Value: 0,
+	}
+	LogMaxTotalSizeFlag = cli.IntFlag{
+		Name:  "log-max-total-size,log-maxtotalsize",


I suggest naming this log-total-max-size,log-totalmaxsize to stick with the convention established where <max|min>-size and max-age are "syntax units." What do you think?

whilei · 2017-12-07T17:34:39Z

cmd/geth/flags.go

+		Value: 0,
+	}
+	LogIntervalFlag = cli.StringFlag{
+		Name:  "log-interval",


And this one may log-rotate-interval to avoid confusion with log-status which also controls an interval. And/or log-rotation-interval?

whilei · 2017-12-07T17:37:39Z

cmd/geth/flags.go

+		Usage: "Maximum age of the oldest log file, valid time units: 'ns', 'us' (or 'µs'), 'ms', 's', 'm', 'h'",
+		Value: "0",
+	}
+	LogCompressFlag = cli.BoolFlag{


Should we make this a BoolTFlag to enable by default?

I guess this would entail establishing defaults for max/min size and age as well, but if we're going to be generating the logs anyways it might be reasonable.

I didn't want to change the default behavior of keeping logs forever by default.
Enabling compression by default seems very reasonable, min/max size also, but I'm not sure about the max age and total size.
My new proposition for default values:

compression: true

rotation-interval: hourly,

min-size: 1MB or less?

max-size: I think 10-20 MB should be OK for hourly rotaiton interval (I was running with 50MB limit for few hours, and only time-based rotation happened)

max-age, total-max-size - 0 (keep logs forever)

This gives usable logs - easy to seek by date/time, fine-grained if we wan't to remove old ones, compressed files are quite small so they are easy to search even with editor (not only grep).

I think we should run geth version with output/log split, with default level/verbosity/etc, for some time, and find sane defaults for log rotation empirically.

Those defaults seem very reasonable to me. And agree that we should get an empirical sense. We can also, after getting an averaged empirical sense for a timeframe, do a little extrapolation to give a general sense of log growth too. Like if geth makes 50MB of logs a day running full time, then it will make 350MB a week...

whilei · 2017-12-07T17:38:26Z

cmd/geth/flags.go

+	}
+	LogMaxAgeFlag = cli.StringFlag{
+		Name:  "log-max-age,log-maxage",
+		Usage: "Maximum age of the oldest log file, valid time units: 'ns', 'us' (or 'µs'), 'ms', 's', 'm', 'h'",


Can we also add 'd' and 'w' for days and weeks? For me at least that would be convenient ;)

And wait a second... max age of oldest log file in nanoseconds?

The units are copied from documentation of time.ParseDuration function. I'll change this, i think 'h', 'd', 'w' should be sufficient. What do you think?

Yea, I think those'll be fine

whilei · 2017-12-07T17:39:41Z

Running notes as I review...

A couple of questions:

~~Are logs ever deleted? Or only gzipped?~~ Yep.

whilei · 2017-12-07T17:42:57Z

cmd/geth/main.go

@@ -223,6 +230,40 @@ func makeCLIApp() (app *cli.App) {

 		runtime.GOMAXPROCS(runtime.NumCPU())

+		// log-rotation options


Maybe we can shove this logic off to its own file cmd/geth/log_context.go? I've also got a bunch of this kind of stuff from the display logs too and it feels yucky to clutter main.go with all this logic.

whilei · 2017-12-07T17:50:38Z

logger/glog/glog.go

+// shouldRotate checks if we need to rotate the current log file
+func (sb *syncBuffer) shouldRotate(len int, now time.Time) bool {
+	newLen := sb.nbytes + uint64(len)
+	if newLen <= MinSize {


What about adding

if MaxSize == 0 { return false }

or?

Oh I see, nm. Because we might not care about size, but care just about age. Gotcha.

whilei · 2017-12-07T18:01:06Z

logger/glog/glog.go

+func (sb *syncBuffer) rotateOld(now time.Time) {
+	logs, err := getLogFiles()
+	if err != nil {
+		sb.logger.exit(err)


Just an idea -- what about using Fatal(err) here (and below)? sb.logger.exit will write the error to fmt which is stdout and since normally geth logs go through stderr some users might not catch it if they're using 2> redirect?

whilei · 2017-12-07T18:02:31Z

logger/glog/glog.go

+				return logFiles[i].timestamp < logFiles[j].timestamp
+			})
+			return logFiles, nil
+		}


Should we handle this err?

This is a bit tricky loop construct from glog itself ;) It searches for first usable logging directory (configured one or temporary directory). To be consistent with rest of glog, we're complaining only when no directories work for us.

whilei · 2017-12-07T18:04:10Z

logger/glog/glog.go

+	return logs
+}
+
+func extractTimestamp(logFile, preffix string) string {


Minor spelling error: "preffix" should be "prefix"

whilei · 2017-12-07T18:06:41Z

logger/glog/glog_test.go

@@ -428,6 +432,309 @@ func TestLogBacktraceAt(t *testing.T) {
 	}
 }

+func TestExtractTimestamp(t *testing.T) {
+	preffix := fmt.Sprintf("%s.%s.%s.log.", "geth_test", "sampleHost", "sampleUser")


s/preffix/prefix cuz I'm a spelling nazi

:%s/preffix/prefix/g ;)

whilei · 2017-12-07T18:07:13Z

logger/glog/glog_test.go

+		{"valid WARNIG", preffix + "WARNING.20171202-210922.13848", "20171202-210922"},
+		{"valid gzipped", preffix + "WARNING.20171202-210922.13848.gz", "20171202-210922"},
+		{"extra long filename", preffix + "WARNING.20171202-210922.13848.gz.bak", "20171202-210922"},
+		{"to short filename", preffix + "WARNING.20171202-21092", ""},


I need to :set spell before next commit ;)

whilei · 2017-12-07T23:52:28Z

cmd/geth/main.go

@@ -223,6 +229,11 @@ func makeCLIApp() (app *cli.App) {

 		runtime.GOMAXPROCS(runtime.NumCPU())

+		err := setupLogRotation(ctx)


🌮 git add cmd/geth/*

whilei · 2017-12-08T22:32:45Z

cmd/geth/log_context.go

+	return time.Duration(value), nil
+}
+
+// reinventing the wheel to avoid external dependency


tzdybal added 6 commits December 6, 2017 00:58

Initial import of log-rotation functionality

79edbcb

This is limited to time & size based rotation + log compression.

Fully functional log rotation + some unit tests

01b70a0

Gzip test and bugfix

580a19e

Testing - WIP

cac33d3

Rotation of old files - tests + bugfixes

eeee153

Flags for log rotation

15831d9

tzdybal requested review from sudachen and whilei December 7, 2017 15:36

whilei reviewed Dec 7, 2017

View reviewed changes

Addressing review comments

4a7c911

whilei reviewed Dec 7, 2017

View reviewed changes

tzdybal added 2 commits December 8, 2017 12:14

missing file

3dc585f

max-total-size -> total-max-size

edf0bd0

whilei approved these changes Dec 8, 2017

View reviewed changes

Parsing size and age suffixes

21448dc

whilei approved these changes Dec 8, 2017

View reviewed changes

log-rotation: improved flag handling and defaults

e9cc8bd

whilei reviewed Dec 8, 2017

View reviewed changes

cmd/geth/log_context.go

return time.Duration(value), nil

}

// reinventing the wheel to avoid external dependency

Copy link

Contributor

whilei Dec 8, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:)

whilei approved these changes Dec 8, 2017

View reviewed changes

whilei added the Type: Feature label Dec 11, 2017

Merge remote-tracking branch 'upstream/master' into feature/log-rotation

f361e0b

tzdybal mentioned this pull request Dec 11, 2017

improve logging, separate display/debug logs #423

Merged

4 tasks

tzdybal merged commit f361e0b into master Dec 12, 2017

whilei deleted the feature/log-rotation branch February 19, 2018 13:32

tzdybal restored the feature/log-rotation branch March 27, 2018 12:30

tzdybal deleted the feature/log-rotation branch March 27, 2018 12:36

wangfenjin mentioned this pull request Oct 13, 2021

How to do log rotation? ethereum/go-ethereum#23723

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

New feature: log rotation #426

New feature: log rotation #426

tzdybal commented Dec 7, 2017 •

edited

Loading

tzdybal commented Dec 7, 2017

whilei Dec 7, 2017 •

edited

Loading

tzdybal Dec 8, 2017

whilei Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017

tzdybal Dec 7, 2017

whilei Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017

whilei Dec 7, 2017

tzdybal Dec 7, 2017

whilei Dec 7, 2017

whilei commented Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017

whilei Dec 7, 2017

whilei Dec 7, 2017

whilei Dec 7, 2017

whilei Dec 7, 2017

tzdybal Dec 7, 2017

whilei Dec 7, 2017

whilei Dec 7, 2017

tzdybal Dec 7, 2017

whilei Dec 7, 2017

tzdybal Dec 7, 2017

whilei Dec 7, 2017

tzdybal Dec 8, 2017

whilei Dec 8, 2017

		@@ -223,6 +230,40 @@ func makeCLIApp() (app *cli.App) {

		runtime.GOMAXPROCS(runtime.NumCPU())

		// log-rotation options

		@@ -223,6 +229,11 @@ func makeCLIApp() (app *cli.App) {

		runtime.GOMAXPROCS(runtime.NumCPU())

		err := setupLogRotation(ctx)

New feature: log rotation #426

New feature: log rotation #426

Conversation

tzdybal commented Dec 7, 2017 • edited Loading

tzdybal commented Dec 7, 2017

whilei Dec 7, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

whilei Dec 7, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

whilei Dec 7, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

whilei commented Dec 7, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tzdybal commented Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017 •

edited

Loading

whilei Dec 7, 2017 •

edited

Loading

whilei commented Dec 7, 2017 •

edited

Loading