From 1c5c1e318cb6a8644171917c73f64ad07920f95d Mon Sep 17 00:00:00 2001 From: Winni Neessen Date: Wed, 2 Aug 2023 11:43:45 +0200 Subject: [PATCH] #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 | 24 ++++++++++++++++++++---- log/stdlog.go | 29 +++++++++++++++++++++-------- log/stdlog_test.go | 45 +++++++++++++++++++++++++++++++++------------ smtp/smtp.go | 24 ++++++------------------ smtp/smtp_test.go | 4 ++-- 5 files changed, 82 insertions(+), 44 deletions(-) diff --git a/log/log.go b/log/log.go index a40f540..8e95bfa 100644 --- a/log/log.go +++ b/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) } diff --git a/log/stdlog.go b/log/stdlog.go index 1a3017c..65ae6e1 100644 --- a/log/stdlog.go +++ b/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 +} diff --git a/log/stdlog_test.go b/log/stdlog_test.go index efaf00b..d8e781e 100644 --- a/log/stdlog_test.go +++ b/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") } diff --git a/smtp/smtp.go b/smtp/smtp.go index a11aba4..430889f 100644 --- a/smtp/smtp.go +++ b/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 -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}) } } diff --git a/smtp/smtp_test.go b/smtp/smtp_test.go index 62d0f0b..4d9f2e1 100644 --- a/smtp/smtp_test.go +++ b/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