From 1d3854aa5fa6fa0ab1bbcba9a1b4587ed0ddb2a0 Mon Sep 17 00:00:00 2001
From: Renan DelValle <rdelval@users.noreply.github.com>
Date: Thu, 10 Jan 2019 16:58:59 -0800
Subject: [PATCH] Trace level for logger (#94)

* Add trace level to print out response thrift objects. Allows user to control whether these are printed or not to avoid pollution.

* Using named parameters to be more explicit about what is being set for LevelLogger.

* Adding TracePrint and TracePrintln. Inlined library level prefixes.
---
 logger.go | 32 ++++++++++++++++++++++++++------
 realis.go | 26 +++++++++++++++++++++-----
 retry.go  |  2 +-
 3 files changed, 48 insertions(+), 12 deletions(-)

diff --git a/logger.go b/logger.go
index 54a901f..c46ae10 100644
--- a/logger.go
+++ b/logger.go
@@ -31,29 +31,49 @@ func (NoopLogger) Println(a ...interface{}) {}
 type LevelLogger struct {
 	Logger
 	debug bool
+	trace bool
 }
 
 func (l *LevelLogger) EnableDebug(enable bool) {
 	l.debug = enable
 }
 
+func (l *LevelLogger) EnableTrace(enable bool) {
+	l.trace = enable
+}
+
 func (l LevelLogger) DebugPrintf(format string, a ...interface{}) {
 	if l.debug {
-		l.Print("[DEBUG] ")
-		l.Printf(format, a...)
+		l.Printf("[DEBUG] "+format, a...)
 	}
 }
 
 func (l LevelLogger) DebugPrint(a ...interface{}) {
 	if l.debug {
-		l.Print("[DEBUG] ")
-		l.Print(a...)
+		l.Print(append([]interface{}{"[DEBUG] "}, a)...)
 	}
 }
 
 func (l LevelLogger) DebugPrintln(a ...interface{}) {
 	if l.debug {
-		l.Print("[DEBUG] ")
-		l.Println(a...)
+		l.Println(append([]interface{}{"[DEBUG] "}, a)...)
+	}
+}
+
+func (l LevelLogger) TracePrintf(format string, a ...interface{}) {
+	if l.trace {
+		l.Printf("[TRACE] "+format, a...)
+	}
+}
+
+func (l LevelLogger) TracePrint(a ...interface{}) {
+	if l.trace {
+		l.Print(append([]interface{}{"[TRACE] "}, a)...)
+	}
+}
+
+func (l LevelLogger) TracePrintln(a ...interface{}) {
+	if l.trace {
+		l.Println(append([]interface{}{"[TRACE] "}, a)...)
 	}
 }
diff --git a/realis.go b/realis.go
index 2597738..d274fd0 100644
--- a/realis.go
+++ b/realis.go
@@ -112,6 +112,7 @@ type RealisConfig struct {
 	clientkey, clientcert       string
 	options                     []ClientOption
 	debug                       bool
+	trace                       bool
 	zkOptions                   []ZKOpt
 }
 
@@ -216,7 +217,7 @@ func ZookeeperOptions(opts ...ZKOpt) ClientOption {
 // Using the word set to avoid name collision with Interface.
 func SetLogger(l Logger) ClientOption {
 	return func(config *RealisConfig) {
-		config.logger = &LevelLogger{l, false}
+		config.logger = &LevelLogger{Logger: l}
 	}
 }
 
@@ -227,6 +228,13 @@ func Debug() ClientOption {
 	}
 }
 
+// Enable debug statements.
+func Trace() ClientOption {
+	return func(config *RealisConfig) {
+		config.trace = true
+	}
+}
+
 func newTJSONTransport(url string, timeout int, config *RealisConfig) (thrift.TTransport, error) {
 	trans, err := defaultTTransport(url, timeout, config)
 	if err != nil {
@@ -262,7 +270,7 @@ func NewRealisClient(options ...ClientOption) (Realis, error) {
 	// Default configs
 	config.timeoutms = 10000
 	config.backoff = defaultBackoff
-	config.logger = &LevelLogger{log.New(os.Stdout, "realis: ", log.Ltime|log.Ldate|log.LUTC), false}
+	config.logger = &LevelLogger{Logger: log.New(os.Stdout, "realis: ", log.Ltime|log.Ldate|log.LUTC)}
 
 	// Save options to recreate client if a connection error happens
 	config.options = options
@@ -276,16 +284,23 @@ func NewRealisClient(options ...ClientOption) (Realis, error) {
 
 	// Turn off all logging (including debug)
 	if config.logger == nil {
-		config.logger = &LevelLogger{NoopLogger{}, false}
+		config.logger = &LevelLogger{Logger: NoopLogger{}}
 	}
 
 	// Set a logger if debug has been set to true but no logger has been set
 	if config.logger == nil && config.debug {
-		config.logger = &LevelLogger{log.New(os.Stdout, "realis: ", log.Ltime|log.Ldate|log.LUTC), true}
+		config.logger = &LevelLogger{
+			Logger: log.New(os.Stdout, "realis: ", log.Ltime|log.Ldate|log.LUTC),
+			debug:  true,
+		}
 	}
 
+	config.logger.debug = config.debug
+	config.logger.trace = config.trace
+
 	// Note, by this point, a LevelLogger should have been created.
 	config.logger.EnableDebug(config.debug)
+	config.logger.EnableTrace(config.trace)
 
 	config.logger.DebugPrintln("Number of options applied to config: ", len(options))
 
@@ -350,7 +365,7 @@ func NewRealisClient(options ...ClientOption) (Realis, error) {
 		client:         aurora.NewAuroraSchedulerManagerClientFactory(config.transport, config.protoFactory),
 		readonlyClient: aurora.NewReadOnlySchedulerClientFactory(config.transport, config.protoFactory),
 		adminClient:    aurora.NewAuroraAdminClientFactory(config.transport, config.protoFactory),
-		logger:         LevelLogger{config.logger, config.debug},
+		logger:         LevelLogger{Logger: config.logger, debug: config.debug, trace: config.trace},
 		lock:           &sync.Mutex{}}, nil
 }
 
@@ -546,6 +561,7 @@ func (r *realisClient) GetInstanceIds(key *aurora.JobKey, states map[aurora.Sche
 }
 
 func (r *realisClient) GetJobUpdateSummaries(jobUpdateQuery *aurora.JobUpdateQuery) (*aurora.Response, error) {
+
 	r.logger.DebugPrintf("GetJobUpdateSummaries Thrift Payload: %+v\n", jobUpdateQuery)
 
 	resp, retryErr := r.thriftCallWithRetries(func() (*aurora.Response, error) {
diff --git a/retry.go b/retry.go
index 17b5c1a..e442ee3 100644
--- a/retry.go
+++ b/retry.go
@@ -148,7 +148,7 @@ func (r *realisClient) thriftCallWithRetries(thriftCall auroraThriftCall) (*auro
 
 			resp, clientErr = thriftCall()
 
-			r.logger.DebugPrintf("Aurora Thrift Call ended resp: %v clientErr: %v\n", resp, clientErr)
+			r.logger.TracePrintf("Aurora Thrift Call ended resp: %v clientErr: %v\n", resp, clientErr)
 		}()
 
 		// Check if our thrift call is returning an error. This is a retriable event as we don't know