From 47de43abf3864b99465b5b033f420ce3d6e25e29 Mon Sep 17 00:00:00 2001
From: Cameron Sparr <cameronsparr@gmail.com>
Date: Tue, 11 Oct 2016 13:06:17 +0100
Subject: [PATCH] Use rfc3339 timestamps in telegraf log output

closes #1564

also add unit and benchmark tests
---
 CHANGELOG.md          |  2 ++
 logger/logger.go      |  6 +++--
 logger/logger_test.go | 62 +++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 68 insertions(+), 2 deletions(-)
 create mode 100644 logger/logger_test.go

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 43dfe1deb..280a51876 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -4,6 +4,8 @@
 
 ### Features
 
+- [#1564](https://github.com/influxdata/telegraf/issues/1564): Use RFC3339 timestamps in log output.
+
 ### Bugfixes
 
 - [#1949](https://github.com/influxdata/telegraf/issues/1949): Fix windows `net` plugin.
diff --git a/logger/logger.go b/logger/logger.go
index 21db2d411..49613c27d 100644
--- a/logger/logger.go
+++ b/logger/logger.go
@@ -4,6 +4,7 @@ import (
 	"io"
 	"log"
 	"os"
+	"time"
 
 	"github.com/influxdata/wlog"
 )
@@ -19,8 +20,8 @@ type telegrafLog struct {
 	writer io.Writer
 }
 
-func (t *telegrafLog) Write(p []byte) (n int, err error) {
-	return t.writer.Write(p)
+func (t *telegrafLog) Write(b []byte) (n int, err error) {
+	return t.writer.Write(append([]byte(time.Now().UTC().Format(time.RFC3339)+" "), b...))
 }
 
 // SetupLogging configures the logging output.
@@ -30,6 +31,7 @@ func (t *telegrafLog) Write(p []byte) (n int, err error) {
 //           interpreted as stderr. If there is an error opening the file the
 //           logger will fallback to stderr.
 func SetupLogging(debug, quiet bool, logfile string) {
+	log.SetFlags(0)
 	if debug {
 		wlog.SetLevel(wlog.DEBUG)
 	}
diff --git a/logger/logger_test.go b/logger/logger_test.go
new file mode 100644
index 000000000..8c0826e65
--- /dev/null
+++ b/logger/logger_test.go
@@ -0,0 +1,62 @@
+package logger
+
+import (
+	"bytes"
+	"io/ioutil"
+	"log"
+	"os"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestWriteLogToFile(t *testing.T) {
+	tmpfile, err := ioutil.TempFile("", "")
+	assert.NoError(t, err)
+	defer func() { os.Remove(tmpfile.Name()) }()
+
+	SetupLogging(false, false, tmpfile.Name())
+	log.Printf("I! TEST")
+	log.Printf("D! TEST") // <- should be ignored
+
+	f, err := ioutil.ReadFile(tmpfile.Name())
+	assert.NoError(t, err)
+	assert.Equal(t, f[19:], []byte("Z I! TEST\n"))
+}
+
+func TestDebugWriteLogToFile(t *testing.T) {
+	tmpfile, err := ioutil.TempFile("", "")
+	assert.NoError(t, err)
+	defer func() { os.Remove(tmpfile.Name()) }()
+
+	SetupLogging(true, false, tmpfile.Name())
+	log.Printf("D! TEST")
+
+	f, err := ioutil.ReadFile(tmpfile.Name())
+	assert.NoError(t, err)
+	assert.Equal(t, f[19:], []byte("Z D! TEST\n"))
+}
+
+func TestErrorWriteLogToFile(t *testing.T) {
+	tmpfile, err := ioutil.TempFile("", "")
+	assert.NoError(t, err)
+	defer func() { os.Remove(tmpfile.Name()) }()
+
+	SetupLogging(false, true, tmpfile.Name())
+	log.Printf("E! TEST")
+	log.Printf("I! TEST") // <- should be ignored
+
+	f, err := ioutil.ReadFile(tmpfile.Name())
+	assert.NoError(t, err)
+	assert.Equal(t, f[19:], []byte("Z E! TEST\n"))
+}
+
+func BenchmarkTelegrafLogWrite(b *testing.B) {
+	var msg = []byte("test")
+	var buf bytes.Buffer
+	w := newTelegrafWriter(&buf)
+	for i := 0; i < b.N; i++ {
+		buf.Reset()
+		w.Write(msg)
+	}
+}