#136: Refactor logging for clearer messaging direction

The logging system in the smtp.go and log package has been refactored. A new custom log type `Log` was introduced, that includes the message direction, format and arguments. The `Logger` interface and the `Stdlog` implementation were modified to accept this new type. This change provides a clearer understanding of message direction inside logs, allowing for easier debugging and reduced complexity. This change does not affect features or disrupt user functionality. Additionally, it allows for custom implementations of the log.Logger interface to without being forced to use the C --> S/C <-- S direction logging.

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