Use rfc3339 timestamps in telegraf log output

closes #1564

also add unit and benchmark tests

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.

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) {
+func (t *telegrafLog) Write(b []byte) (n int, err error) {
-	return t.writer.Write(p)
+	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)
 	}

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)
+	}
+}