refactor: log usage was in too many submodules

In order to make logging configurable to turn on/off dumping raw bytes, logging needed to be centralized a bit. For now, all log.Print{f,ln} and log.Fatal{,f}() calls should be just in proxy.go where the output can be controlled.
voutilad · Dec 16, 2020 · d6cd147 · d6cd147
1 parent c25507c
commit d6cd147
Show file tree

Hide file tree

Showing 4 changed files with 47 additions and 52 deletions.
diff --git a/bolt/bolt.go b/bolt/bolt.go
@@ -4,7 +4,6 @@ import (
 	"encoding/binary"
 	"errors"
 	"fmt"
-	"log"
 )
 
 type Message struct {
@@ -67,36 +66,6 @@ func TypeFromByte(b byte) Type {
 	}
 }
 
-const MAX_BYTES int = 32
-
-// Crude logging routine for helping debug bolt Messages. Tries not to clutter
-// output too much due to large messages while trying to deliniate who logged
-// the message.
-func LogMessage(who string, msg *Message) {
-	end := MAX_BYTES
-	suffix := fmt.Sprintf("...+%d bytes", len(msg.Data))
-	if len(msg.Data) < MAX_BYTES {
-		end = len(msg.Data)
-		suffix = ""
-	}
-
-	switch msg.T {
-	case HelloMsg:
-		// make sure we don't print the secrets in a Hello!
-		log.Printf("[%s] <%s>: %#v\n\n", who, msg.T, msg.Data[:4])
-	case BeginMsg, FailureMsg:
-		log.Printf("[%s] <%s>: %#v\n%s\n", who, msg.T, msg.Data[:end], msg.Data)
-	default:
-		log.Printf("[%s] <%s>: %#v%s\n", who, msg.T, msg.Data[:end], suffix)
-	}
-}
-
-func LogMessages(who string, messages []*Message) {
-	for _, msg := range messages {
-		LogMessage(who, msg)
-	}
-}
-
 // Try to extract the BoltMsg from some given bytes.
 func IdentifyType(buf []byte) Type {
 

diff --git a/bolt/conn.go b/bolt/conn.go
@@ -6,7 +6,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"log"
+	//	"log"
 
 	"github.com/gobwas/ws"
 )
@@ -68,11 +68,11 @@ func NewDirectConn(c io.ReadWriteCloser) DirectConn {
 			message, err := dc.readMessage()
 			if err != nil {
 				if err == io.EOF {
-					log.Println("direct bolt connection hung-up")
+					// log.Println("direct bolt connection hung-up")
 					close(msgchan)
 					return
 				}
-				log.Printf("direct bolt connection disconnect: %s\n", err)
+				// log.Printf("direct bolt connection disconnect: %s\n", err)
 				return
 			}
 			msgchan <- message
@@ -187,11 +187,11 @@ func NewWsConn(c io.ReadWriteCloser) WsConn {
 			messages, err := ws.readMessages()
 			if err != nil {
 				if err == io.EOF {
-					log.Println("bolt ws connection hung-up")
+					// log.Println("bolt ws connection hung-up")
 					close(msgchan)
 					return
 				}
-				log.Printf("ws bolt connection disconnect: %s\n", err)
+				// log.Printf("ws bolt connection disconnect: %s\n", err)
 				return
 			}
 			for _, message := range messages {

diff --git a/bolt/validate.go b/bolt/validate.go
@@ -3,7 +3,6 @@ package bolt
 import (
 	"bytes"
 	"errors"
-	"log"
 )
 
 // Mode of a Bolt Transaction for determining cluster routing
@@ -56,8 +55,6 @@ func ValidateHandshake(client, server []byte) ([]byte, error) {
 
 	chosen := make([]byte, 4)
 
-	log.Printf("HANDSHAKE: client=%#v, server=%#v\n", client, server)
-
 	// find max(clientVersion)
 	clientVersion := []byte{0x0, 0x0, 0x0, 0x0}
 	for i := 0; i < 4; i++ {
@@ -69,8 +66,6 @@ func ValidateHandshake(client, server []byte) ([]byte, error) {
 		// XXX: we assume nobody cares about patch level or lower
 	}
 
-	log.Printf("HANDSHAKE: clientVersion=%#v\n", clientVersion)
-
 	// our hacky min() logic
 	if clientVersion[3] > server[3] {
 		// differing major number, client newer
@@ -87,8 +82,6 @@ func ValidateHandshake(client, server []byte) ([]byte, error) {
 		copy(chosen, clientVersion)
 	}
 
-	log.Printf("HANDSHAKE: chosen=%#v\n", chosen)
-
 	return chosen, nil
 }
 
@@ -99,7 +92,7 @@ func ValidateMode(buf []byte) (Mode, error) {
 	if IdentifyType(buf) == BeginMsg {
 		tinyMap, _, err := ParseTinyMap(buf[4:])
 		if err != nil {
-			log.Fatal(err)
+			panic(err)
 		}
 
 		value, found := tinyMap["mode"]

diff --git a/proxy.go b/proxy.go
@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"crypto/tls"
 	"flag"
+	"fmt"
 	"io"
 	"log"
 	"net"
@@ -21,8 +22,40 @@ import (
 	"github.com/gobwas/ws"
 )
 
-// A basic idle timeout duration for now
-const MAX_IDLE_MINS int = 30
+const (
+	// A basic idle timeout duration for now
+	MAX_IDLE_MINS int = 30
+	// max bytes to display in logs in debug mode
+	MAX_BYTES int = 32
+)
+
+// Crude logging routine for helping debug bolt Messages. Tries not to clutter
+// output too much due to large messages while trying to deliniate who logged
+// the message.
+func logMessage(who string, msg *bolt.Message) {
+	end := MAX_BYTES
+	suffix := fmt.Sprintf("...+%d bytes", len(msg.Data))
+	if len(msg.Data) < MAX_BYTES {
+		end = len(msg.Data)
+		suffix = ""
+	}
+
+	switch msg.T {
+	case bolt.HelloMsg:
+		// make sure we don't print the secrets in a Hello!
+		log.Printf("[%s] <%s>: %#v\n\n", who, msg.T, msg.Data[:4])
+	case bolt.BeginMsg, bolt.FailureMsg:
+		log.Printf("[%s] <%s>: %#v\n%s\n", who, msg.T, msg.Data[:end], msg.Data)
+	default:
+		log.Printf("[%s] <%s>: %#v%s\n", who, msg.T, msg.Data[:end], suffix)
+	}
+}
+
+func logMessages(who string, messages []*bolt.Message) {
+	for _, msg := range messages {
+		logMessage(who, msg)
+	}
+}
 
 // Primary Transaction server-side event handler, collecting Messages from
 // the backend Bolt server and writing them to the given client.
@@ -43,12 +76,12 @@ func handleTx(client, server bolt.BoltConn, ack chan<- bool, halt <-chan bool) {
 		select {
 		case msg, ok := <-server.R():
 			if ok {
-				bolt.LogMessage("P<-S", msg)
+				logMessage("P<-S", msg)
 				err := client.WriteMessage(msg)
 				if err != nil {
 					panic(err)
 				}
-				bolt.LogMessage("C<-P", msg)
+				logMessage("C<-P", msg)
 
 				// if know the server side is saying goodbye,
 				// we abort the loop
@@ -227,7 +260,7 @@ func handleBoltConn(client bolt.BoltConn, clientVersion []byte, b *backend.Backe
 		log.Println("timed out waiting for client to auth")
 		return
 	}
-	bolt.LogMessage("C->P", hello)
+	logMessage("C->P", hello)
 
 	if hello.T != bolt.HelloMsg {
 		log.Println("expected HelloMsg, got:", hello.T)
@@ -253,7 +286,7 @@ func handleBoltConn(client bolt.BoltConn, clientVersion []byte, b *backend.Backe
 			0x8d, 0x63, 0x6f, 0x6e, 0x6e, 0x65, 0x63, 0x74, 0x69, 0x6f, 0x6e, 0x5f, 0x69, 0x64,
 			0x86, 0x62, 0x6f, 0x6c, 0x74, 0x2d, 0x34,
 			0x00, 0x00}}
-	bolt.LogMessage("P->C", &success)
+	logMessage("P->C", &success)
 	err = client.WriteMessage(&success)
 	if err != nil {
 		log.Fatal(err)
@@ -272,7 +305,7 @@ func handleBoltConn(client bolt.BoltConn, clientVersion []byte, b *backend.Backe
 		case m, ok := <-client.R():
 			if ok {
 				msg = m
-				bolt.LogMessage("C->P", msg)
+				logMessage("C->P", msg)
 			} else {
 				log.Println("potential client hangup")
 				select {
@@ -392,7 +425,7 @@ func handleBoltConn(client bolt.BoltConn, clientVersion []byte, b *backend.Backe
 				// TODO: figure out best way to handle failed writes
 				panic(err)
 			}
-			bolt.LogMessage("P->S", msg)
+			logMessage("P->S", msg)
 		} else {
 			// we have no connection since there's no tx...
 			// handle only specific, simple messages