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{})
- Warnf(format string, v ...interface{})
- Infof(format string, v ...interface{})
- Debugf(format string, v ...interface{})
+ Debugf(Log)
+ Infof(Log)
+ Warnf(Log)
+ 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")
- expected := "DEBUG: test foo\n"
+ l.Debugf(Log{Direction: DirServerToClient, 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())
+ }
+ 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")
- expected := " INFO: test foo\n"
+ l.Infof(Log{Direction: DirServerToClient, 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())
+ }
+ 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")
- expected := " WARN: test foo\n"
+ l.Warnf(Log{Direction: DirServerToClient, 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())
+ }
+ 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")
- expected := "ERROR: test foo\n"
+ l.Errorf(Log{Direction: DirServerToClient, 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())
+ }
+ 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,15 +127,15 @@ 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
  }
  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
-func (c *Client) debugLog(d logDirection, f string, a ...interface{}) {
+// debugLog checks if the debug flag is set and if so logs the provided message to
+// the log.Logger interface
+func (c *Client) debugLog(d log.Direction, f string, a ...interface{}) {
  if c.debug {
- p := "C <-- S:"
- if d == logOut {
- p = "C --> S:"
- }
- fs := fmt.Sprintf("%s %s", p, f)
- c.logger.Debugf(fs, a...)
+ c.logger.Debugf(log.Log{Direction: d, Format: f, Messages: 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