From 9f6da0e77c52c07f3fbc934a1a9249a05fe48c4e Mon Sep 17 00:00:00 2001
From: Anthony Bishopric <git@anthonybishopric.com>
Date: Wed, 19 Mar 2014 09:02:00 -0700
Subject: [PATCH] Defer formatting of log values in Levelf(), Levelln()

The Level() family of log methods defer formatting of log
values until it is confident that the log level needs them.
This change allows that deferral to happen at the Levelf()
and Levelln() levels too.

This commit also adds benchmarks to demonstrate the improved
performance of these functions
---
 entry.go       | 44 ++++++++++++++++++++++++--------------
 logrus_test.go | 58 ++++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 86 insertions(+), 16 deletions(-)

diff --git a/entry.go b/entry.go
index e343a27..863e89d 100644
--- a/entry.go
+++ b/entry.go
@@ -129,67 +129,79 @@ func (entry *Entry) Panic(args ...interface{}) {
 // Entry Printf family functions
 
 func (entry *Entry) Debugf(format string, args ...interface{}) {
-	entry.Debug(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Debug {
+		entry.Debug(fmt.Sprintf(format, args...))
+	}
 }
 
 func (entry *Entry) Infof(format string, args ...interface{}) {
-	entry.Info(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Info {
+		entry.Info(fmt.Sprintf(format, args...))
+	}
 }
 
 func (entry *Entry) Printf(format string, args ...interface{}) {
-	entry.Info(fmt.Sprintf(format, args...))
+	entry.Info(format, args...)
 }
 
 func (entry *Entry) Warnf(format string, args ...interface{}) {
-	entry.Warn(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Warn {
+		entry.Warn(fmt.Sprintf(format, args...))
+	}
 }
 
 func (entry *Entry) Warningf(format string, args ...interface{}) {
-	entry.Warn(fmt.Sprintf(format, args...))
+	entry.Warnf(format, args...)
 }
 
 func (entry *Entry) Errorf(format string, args ...interface{}) {
-	entry.Error(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Error {
+		entry.Error(fmt.Sprintf(format, args...))
+	}
 }
 
 func (entry *Entry) Fatalf(format string, args ...interface{}) {
-	entry.Fatal(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Fatal {
+		entry.Fatal(fmt.Sprintf(format, args...))
+	}
 }
 
 func (entry *Entry) Panicf(format string, args ...interface{}) {
-	entry.Panic(fmt.Sprintf(format, args...))
+	if entry.logger.Level >= Panic {
+		entry.Panic(fmt.Sprintf(format, args...))
+	}
 }
 
 // Entry Println family functions
 
 func (entry *Entry) Debugln(args ...interface{}) {
-	entry.Debug(fmt.Sprint(args...))
+	entry.Debug(args...)
 }
 
 func (entry *Entry) Infoln(args ...interface{}) {
-	entry.Info(fmt.Sprint(args...))
+	entry.Info(args...)
 }
 
 func (entry *Entry) Println(args ...interface{}) {
-	entry.Info(fmt.Sprint(args...))
+	entry.Info(args...)
 }
 
 func (entry *Entry) Warnln(args ...interface{}) {
-	entry.Warn(fmt.Sprint(args...))
+	entry.Warn(args...)
 }
 
 func (entry *Entry) Warningln(args ...interface{}) {
-	entry.Warn(fmt.Sprint(args...))
+	entry.Warn(args...)
 }
 
 func (entry *Entry) Errorln(args ...interface{}) {
-	entry.Error(fmt.Sprint(args...))
+	entry.Error(args...)
 }
 
 func (entry *Entry) Fatalln(args ...interface{}) {
-	entry.Fatal(fmt.Sprint(args...))
+	entry.Fatal(args...)
 }
 
 func (entry *Entry) Panicln(args ...interface{}) {
-	entry.Panic(fmt.Sprint(args...))
+	entry.Panic(args...)
 }
diff --git a/logrus_test.go b/logrus_test.go
index 64baa40..5889db5 100644
--- a/logrus_test.go
+++ b/logrus_test.go
@@ -3,7 +3,9 @@ package logrus
 import (
 	"bytes"
 	"encoding/json"
+	"io/ioutil"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 )
@@ -50,3 +52,59 @@ func TestWarn(t *testing.T) {
 		assert.Equal(t, fields["level"], "warning")
 	})
 }
+
+type SlowString string
+
+func (s SlowString) String() string {
+	time.Sleep(time.Millisecond)
+	return string(s)
+}
+
+func getLogAtLevel(l Level) *Logger {
+	log := New()
+	log.Level = l
+	log.Out = ioutil.Discard
+	return log
+}
+
+func BenchmarkLevelDisplayed(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Info(SlowString("foo"))
+	}
+}
+
+func BenchmarkLevelHidden(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Debug(SlowString("foo"))
+	}
+}
+
+func BenchmarkLevelfDisplayed(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Infof("%s", SlowString("foo"))
+	}
+}
+
+func BenchmarkLevelfHidden(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Debugf("%s", SlowString("foo"))
+	}
+}
+
+func BenchmarkLevellnDisplayed(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Infoln(SlowString("foo"))
+	}
+}
+
+func BenchmarkLevellnHidden(b *testing.B) {
+	log := getLogAtLevel(Info)
+	for i := 0; i < b.N; i++ {
+		log.Debugln(SlowString("foo"))
+	}
+}