Merge lp:~jamesodhunt/snappy/log-filename+lineno-onlyh-for-loglevel-error-and-above into lp:~snappy-dev/snappy/snappy-moved-to-github

[James Hunt]

Don't include filename+line number unless logging levels ERROR and above.

Logging the filename+line number for every log entry is overkill unless the level is ERROR or higher:

* logger/logger.go: Format(): Don't include filename+line number unless
  logging levels ERROR and above.
* logger/logger_test.go:
  - Assert new log format behaviour.
  - TestWrite(): Now tests all log levels.
  - TestFormat(): Now tests all log levels.

[John Lenton (chipaca)]

Nice.

Shame loggo doesn't give you a way to not compute line numbers when not needed (as it's relatively expensive).

review: Approve

=== modified file 'logger/logger.go'
--- logger/logger.go	2015-03-19 10:29:09 +0000
+++ logger/logger.go	2015-03-27 16:54:17 +0000
@@ -94,6 +94,11 @@
 // Format handles how each log entry should appear.
 // Note that the timestamp field is not used as syslog adds that for us.
 func (l *LogWriter) Format(level loggo.Level, module, filename string, line int, timestamp time.Time, message string) string {
+	if level < loggo.ERROR {
+		// keep it relatively succinct for low priority messages
+		return fmt.Sprintf("%s:%s:%s", level, module, message)
+	}
+
 	return fmt.Sprintf("%s:%s:%s:%d:%s", level, module, filename, line, message)
 }
 

=== modified file 'logger/logger_test.go'
--- logger/logger_test.go	2015-03-19 11:08:04 +0000
+++ logger/logger_test.go	2015-03-27 16:54:17 +0000
@@ -27,6 +27,8 @@
 
 var mockWriter *MockLogWriter
 
+var loggoLevels = []string{"DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"}
+
 func mockGetSyslog(priority syslog.Priority, tag string) (w logWriterInterface, err error) {
 	mockWriter = &MockLogWriter{}
 	return mockWriter, nil
@@ -122,18 +124,41 @@
 	t := time.Now()
 	strTime := fmt.Sprintf("%s", t)
 
-	w.Write(loggo.DEBUG, "module", "filename", 1234, t, "a message")
-	lines := readLines()
-	c.Assert(len(lines), Equals, 1)
-
-	c.Assert(sliceContainsString(lines, "module"), Equals, true)
-	c.Assert(sliceContainsString(lines, "filename"), Equals, true)
-	c.Assert(sliceContainsString(lines, "1234"), Equals, true)
-
-	// We discard the timestamp as syslog adds that itself
-	c.Assert(sliceContainsString(lines, strTime), Equals, false)
-
-	c.Assert(sliceContainsString(lines, "a message"), Equals, true)
+	for _, l := range loggoLevels {
+		level := stringToLogLevel(l)
+
+		w.Write(level, "module", "filename", 1234, t, "a message")
+		lines := readLines()
+
+		if level < loggo.ERROR {
+			c.Assert(len(lines), Equals, 1)
+		} else {
+			c.Assert(len(lines) > 1, Equals, true)
+
+			c.Assert(sliceContainsString(lines, "filename"), Equals, true)
+			c.Assert(sliceContainsString(lines, "1234"), Equals, true)
+		}
+
+		c.Assert(sliceContainsString(lines, "module"), Equals, true)
+
+		// We discard the timestamp as syslog adds that itself
+		c.Assert(sliceContainsString(lines, strTime), Equals, false)
+
+		c.Assert(sliceContainsString(lines, "a message"), Equals, true)
+	}
+
+}
+
+// Convert a loggo log level string representation into a real log
+// level.
+func stringToLogLevel(name string) loggo.Level {
+	level, ok := loggo.ParseLevel(name)
+
+	if !ok {
+		panic(fmt.Sprintf("unknown loggo level string: %q", name))
+	}
+
+	return level
 }
 
 func (ts *LoggerTestSuite) TestFormat(c *C) {
@@ -142,11 +167,17 @@
 	c.Assert(w, Not(IsNil))
 	c.Assert(w.systemLog, Not(IsNil))
 
-	out := w.Format(loggo.ERROR, "module", "filename", 1234, time.Now(), "a message")
-
-	expected := fmt.Sprintf("%s:%s:%s:%d:%s", "ERROR", "module", "filename", 1234, "a message")
-
-	c.Assert(out, Equals, expected)
+	for _, l := range loggoLevels {
+		level := stringToLogLevel(l)
+
+		if level < loggo.ERROR {
+			out := w.Format(level, "module", "filename", 1234, time.Now(), "a message")
+			c.Assert(out, Equals, fmt.Sprintf("%s:%s:%s", l, "module", "a message"))
+		} else {
+			out := w.Format(level, "module", "filename", 1234, time.Now(), "a message")
+			c.Assert(out, Equals, fmt.Sprintf("%s:%s:%s:%d:%s", l, "module", "filename", 1234, "a message"))
+		}
+	}
 }
 
 func (ts *LoggerTestSuite) TestLogStackTrace(c *C) {
@@ -223,9 +254,8 @@
 
 func (ts *LoggerTestSuite) TestLogLevels(c *C) {
 	msg := "an error message"
-	levels := []string{"DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"}
 
-	for _, level := range levels {
+	for _, level := range loggoLevels {
 		ts.checkLogLevel(c, level, msg)
 	}
 }