Merge pull request #141 from wneessen/136_debuglog_refactor

Refactor logging for clearer messaging direction

log/log.go

@@ -5,10 +5,26 @@
 // Package log implements a logger interface that can be used within the go-mail package
 package log
 
+const (
+	DirServerToClient Direction = iota // Server to Client communication
+	DirClientToServer                  // Client to Server communication
+)
+
+// Direction is a type wrapper for the direction a debug log message goes
+type Direction int
+
+// Log represents a log message type that holds a log Direction, a Format string
+// and a slice of Messages
+type Log struct {
+	Direction Direction
+	Format    string
+	Messages  []interface{}
+}
+
 // Logger is the log interface for go-mail
 type Logger interface {
-	Errorf(format string, v ...interface{})
+	Debugf(Log)
-	Warnf(format string, v ...interface{})
+	Infof(Log)
-	Infof(format string, v ...interface{})
+	Warnf(Log)
-	Debugf(format string, v ...interface{})
+	Errorf(Log)
 }

log/stdlog.go

@@ -50,29 +50,42 @@ func New(o io.Writer, l Level) *Stdlog {
 }
 
 // Debugf performs a Printf() on the debug logger
-func (l *Stdlog) Debugf(f string, v ...interface{}) {
+func (l *Stdlog) Debugf(lo Log) {
 	if l.l >= LevelDebug {
-		_ = l.debug.Output(CallDepth, fmt.Sprintf(f, v...))
+		f := fmt.Sprintf("%s %s", lo.directionPrefix(), lo.Format)
+		_ = l.debug.Output(CallDepth, fmt.Sprintf(f, lo.Messages...))
 	}
 }
 
 // Infof performs a Printf() on the info logger
-func (l *Stdlog) Infof(f string, v ...interface{}) {
+func (l *Stdlog) Infof(lo Log) {
 	if l.l >= LevelInfo {
-		_ = l.info.Output(CallDepth, fmt.Sprintf(f, v...))
+		f := fmt.Sprintf("%s %s", lo.directionPrefix(), lo.Format)
+		_ = l.info.Output(CallDepth, fmt.Sprintf(f, lo.Messages...))
 	}
 }
 
 // Warnf performs a Printf() on the warn logger
-func (l *Stdlog) Warnf(f string, v ...interface{}) {
+func (l *Stdlog) Warnf(lo Log) {
 	if l.l >= LevelWarn {
-		_ = l.warn.Output(CallDepth, fmt.Sprintf(f, v...))
+		f := fmt.Sprintf("%s %s", lo.directionPrefix(), lo.Format)
+		_ = l.warn.Output(CallDepth, fmt.Sprintf(f, lo.Messages...))
 	}
 }
 
 // Errorf performs a Printf() on the error logger
-func (l *Stdlog) Errorf(f string, v ...interface{}) {
+func (l *Stdlog) Errorf(lo Log) {
 	if l.l >= LevelError {
-		_ = l.err.Output(CallDepth, fmt.Sprintf(f, v...))
+		f := fmt.Sprintf("%s %s", lo.directionPrefix(), lo.Format)
+		_ = l.err.Output(CallDepth, fmt.Sprintf(f, lo.Messages...))
 	}
 }
+
+// directionPrefix will return a prefix string depending on the Direction.
+func (l Log) directionPrefix() string {
+	p := "C <-- S:"
+	if l.Direction == DirClientToServer {
+		p = "C --> S:"
+	}
+	return p
+}

log/stdlog_test.go

@@ -25,15 +25,20 @@ func TestDebugf(t *testing.T) {
 	var b bytes.Buffer
 	l := New(&b, LevelDebug)
 
-	l.Debugf("test %s", "foo")
+	l.Debugf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
-	expected := "DEBUG: test foo\n"
+	expected := "DEBUG: C <-- S: test foo\n"
+	if !strings.HasSuffix(b.String(), expected) {
+		t.Errorf("Expected %q, got %q", expected, b.String())
+	}
+	l.Debugf(Log{Direction: DirClientToServer, Format: "test %s", Messages: []interface{}{"foo"}})
+	expected = "DEBUG: C --> S: test foo\n"
 	if !strings.HasSuffix(b.String(), expected) {
 		t.Errorf("Expected %q, got %q", expected, b.String())
 	}
 
 	b.Reset()
 	l.l = LevelInfo
-	l.Debugf("test %s", "foo")
+	l.Debugf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
 	if b.String() != "" {
 		t.Error("Debug message was not expected to be logged")
 	}
@@ -43,15 +48,20 @@ func TestInfof(t *testing.T) {
 	var b bytes.Buffer
 	l := New(&b, LevelInfo)
 
-	l.Infof("test %s", "foo")
+	l.Infof(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
-	expected := " INFO: test foo\n"
+	expected := " INFO: C <-- S: test foo\n"
+	if !strings.HasSuffix(b.String(), expected) {
+		t.Errorf("Expected %q, got %q", expected, b.String())
+	}
+	l.Infof(Log{Direction: DirClientToServer, Format: "test %s", Messages: []interface{}{"foo"}})
+	expected = " INFO: C --> S: test foo\n"
 	if !strings.HasSuffix(b.String(), expected) {
 		t.Errorf("Expected %q, got %q", expected, b.String())
 	}
 
 	b.Reset()
 	l.l = LevelWarn
-	l.Infof("test %s", "foo")
+	l.Infof(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
 	if b.String() != "" {
 		t.Error("Info message was not expected to be logged")
 	}
@@ -61,15 +71,20 @@ func TestWarnf(t *testing.T) {
 	var b bytes.Buffer
 	l := New(&b, LevelWarn)
 
-	l.Warnf("test %s", "foo")
+	l.Warnf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
-	expected := " WARN: test foo\n"
+	expected := " WARN: C <-- S: test foo\n"
+	if !strings.HasSuffix(b.String(), expected) {
+		t.Errorf("Expected %q, got %q", expected, b.String())
+	}
+	l.Warnf(Log{Direction: DirClientToServer, Format: "test %s", Messages: []interface{}{"foo"}})
+	expected = " WARN: C --> S: test foo\n"
 	if !strings.HasSuffix(b.String(), expected) {
 		t.Errorf("Expected %q, got %q", expected, b.String())
 	}
 
 	b.Reset()
 	l.l = LevelError
-	l.Warnf("test %s", "foo")
+	l.Warnf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
 	if b.String() != "" {
 		t.Error("Warn message was not expected to be logged")
 	}
@@ -79,14 +94,20 @@ func TestErrorf(t *testing.T) {
 	var b bytes.Buffer
 	l := New(&b, LevelError)
 
-	l.Errorf("test %s", "foo")
+	l.Errorf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
-	expected := "ERROR: test foo\n"
+	expected := "ERROR: C <-- S: test foo\n"
 	if !strings.HasSuffix(b.String(), expected) {
 		t.Errorf("Expected %q, got %q", expected, b.String())
 	}
+	l.Errorf(Log{Direction: DirClientToServer, Format: "test %s", Messages: []interface{}{"foo"}})
+	expected = "ERROR: C --> S: test foo\n"
+	if !strings.HasSuffix(b.String(), expected) {
+		t.Errorf("Expected %q, got %q", expected, b.String())
+	}
+
 	b.Reset()
 	l.l = LevelError - 1
-	l.Warnf("test %s", "foo")
+	l.Errorf(Log{Direction: DirServerToClient, Format: "test %s", Messages: []interface{}{"foo"}})
 	if b.String() != "" {
 		t.Error("Error message was not expected to be logged")
 	}

smtp/smtp.go

@@ -60,14 +60,6 @@ type Client struct {
 	dsnrntype string // dsnrntype defines the recipient notify option in case DSN is enabled
 }
 
-// logDirection is a type wrapper for the direction a debug log message goes
-type logDirection int
-
-const (
-	logIn  logDirection = iota // Incoming log message
-	logOut                     // Outgoing log message
-)
-
 // Dial returns a new Client connected to an SMTP server at addr.
 // The addr must include a port, as in "mail.example.com:smtp".
 func Dial(addr string) (*Client, error) {
@@ -135,7 +127,7 @@ func (c *Client) Hello(localName string) error {
 
 // cmd is a convenience function that sends a command and returns the response
 func (c *Client) cmd(expectCode int, format string, args ...interface{}) (int, string, error) {
-	c.debugLog(logOut, format, args...)
+	c.debugLog(log.DirClientToServer, format, args...)
 	id, err := c.Text.Cmd(format, args...)
 	if err != nil {
 		return 0, "", err
@@ -143,7 +135,7 @@ func (c *Client) cmd(expectCode int, format string, args ...interface{}) (int, s
 	c.Text.StartResponse(id)
 	defer c.Text.EndResponse(id)
 	code, msg, err := c.Text.ReadResponse(expectCode)
-	c.debugLog(logIn, "%d %s", code, msg)
+	c.debugLog(log.DirServerToClient, "%d %s", code, msg)
 	return code, msg, err
 }
 
@@ -479,15 +471,11 @@ func (c *Client) SetDSNRcptNotifyOption(d string) {
 	c.dsnrntype = d
 }
 
-// debugLog checks if the debug flag is set and if so logs the provided message to StdErr
+// debugLog checks if the debug flag is set and if so logs the provided message to
-func (c *Client) debugLog(d logDirection, f string, a ...interface{}) {
+// the log.Logger interface
+func (c *Client) debugLog(d log.Direction, f string, a ...interface{}) {
 	if c.debug {
-		p := "C <-- S:"
+		c.logger.Debugf(log.Log{Direction: d, Format: f, Messages: a})
-		if d == logOut {
-			p = "C --> S:"
-		}
-		fs := fmt.Sprintf("%s %s", p, f)
-		c.logger.Debugf(fs, a...)
 	}
 }
 

smtp/smtp_test.go

@@ -777,9 +777,9 @@ func TestClient_SetLogger(t *testing.T) {
 	if c.logger == nil {
 		t.Errorf("Expected Logger to be set but received nil")
 	}
-	c.logger.Debugf("test")
+	c.logger.Debugf(log.Log{Direction: log.DirServerToClient, Format: "", Messages: []interface{}{"test"}})
 	c.SetLogger(nil)
-	c.logger.Debugf("test")
+	c.logger.Debugf(log.Log{Direction: log.DirServerToClient, Format: "", Messages: []interface{}{"test"}})
 }
 
 var newClientServer = `220 hello world