From 63cf438edcd2f02d0653422e08250f49dcfb17e5 Mon Sep 17 00:00:00 2001
From: "Guy M. Allard" <allard.guy.m@gmail.com>
Date: Sun, 22 Apr 2018 17:48:56 -0400
Subject: [PATCH] Reduce logging resource utilization:

Tests run using stompngo_examples/publish.

// Old code, with many HexData calls at runtime
// 1000 messages

real	9m18.706s
user	0m9.964s
sys	0m2.716s

real	9m21.936s
user	0m10.280s
sys	0m2.868s

real	9m22.222s
user	0m9.656s
sys	0m2.752s

// New code, with optional HexData calls depending on a logger present
// 1000 messages

real	9m10.223s
user	0m1.468s
sys	0m2.500s

real	9m22.370s
user	0m1.448s
sys	0m2.552s

real	9m24.794s
user	0m1.456s
sys	0m2.348s

// Old code, with many HexData calls at runtime
// 5000 messages

real	46m9.885s
user	0m50.092s
sys	0m13.928s

// New code, with optional HexData calls depending on a logger present
// 5000 messages

real	46m6.997s
user	0m7.216s
sys	0m12.000s
---
 connection.go | 14 ++++++++++++++
 reader.go     | 16 ++++++++++++----
 writer.go     |  8 ++++++--
 3 files changed, 32 insertions(+), 6 deletions(-)

diff --git a/connection.go b/connection.go
index 3b45131..41bb6ba 100644
--- a/connection.go
+++ b/connection.go
@@ -185,6 +185,20 @@ func (c *Connection) log(v ...interface{}) {
 }
 
 /*
+	Log data if possible (extended / abbreviated) logic).
+*/
+func (c *Connection) logx(v ...interface{}) {
+	_, fn, ld, ok := runtime.Caller(1)
+
+	if ok {
+		c.logger.Printf("%s %s %d %v\n", c.session, fn, ld, v)
+	} else {
+		c.logger.Print(c.session, v)
+	}
+	return
+}
+
+/*
 	Shutdown heartbeats
 */
 func (c *Connection) shutdownHeartBeats() {
diff --git a/reader.go b/reader.go
index ea865ae..3f3998e 100644
--- a/reader.go
+++ b/reader.go
@@ -43,8 +43,12 @@ readLoop:
 		default:
 		}
 		//
-		c.log("RDR_RECEIVE_FRAME", f.Command, f.Headers, HexData(f.Body),
-			"RDR_RECEIVE_ERR", e)
+		logLock.Lock()
+		if c.logger != nil {
+			c.logx("RDR_RECEIVE_FRAME", f.Command, f.Headers, HexData(f.Body),
+				"RDR_RECEIVE_ERR", e)
+		}
+		logLock.Unlock()
 		if e != nil {
 			//debug.PrintStack()
 			f.Headers = append(f.Headers, "connection_read_error", e.Error())
@@ -100,8 +104,12 @@ readLoop:
 			default:
 				ps.drmc++
 				if ps.drmc > ps.dra {
-					c.log("RDR_DROPM", ps.drmc, sid, m.Command,
-						m.Headers, HexData(m.Body))
+					logLock.Lock()
+					if c.logger != nil {
+						c.logx("RDR_DROPM", ps.drmc, sid, m.Command,
+							m.Headers, HexData(m.Body))
+					}
+					logLock.Unlock()
 				} else {
 					ps.md <- md
 				}
diff --git a/writer.go b/writer.go
index d1fae01..e1e6611 100644
--- a/writer.go
+++ b/writer.go
@@ -36,8 +36,12 @@ writerLoop:
 		case d := <-c.output:
 			c.log("WTR_WIREWRITE start")
 			c.wireWrite(d)
-			c.log("WTR_WIREWRITE COMPLETE", d.frame.Command, d.frame.Headers,
-				HexData(d.frame.Body))
+			logLock.Lock()
+			if c.logger != nil {
+				c.logx("WTR_WIREWRITE COMPLETE", d.frame.Command, d.frame.Headers,
+					HexData(d.frame.Body))
+			}
+			logLock.Unlock()
 			if d.frame.Command == DISCONNECT {
 				break writerLoop // we are done with this connection
 			}
-- 
2.11.4.GIT