Implement debug logging in SMTP client

Resolves #101.

Since we now have full control over the SMTP client we can also access the message input and output.

This PR introduces a new debug logging feature. Via the `Client.WithDebugLog` the user can enable this feature. It will then make use of the new `smtp/Client.SetDebugLog` method. Once the flag is set to true, the SMTP client will start logging incoming and outgoing messages to os.Stderr.

Log directions will be output accordingly

client.go

@@ -130,6 +130,9 @@ type Client struct {
 
 	// user is the SMTP AUTH username
 	user string
+
+	// dl enables the debug logging on the SMTP client
+	dl bool
 }
 
 // Option returns a function that can be used for grouping Client options
@@ -240,6 +243,15 @@ func WithSSL() Option {
 	}
 }
 
+// WithDebugLog tells the client to log incoming and outgoing messages of the SMTP client
+// to StdErr
+func WithDebugLog() Option {
+	return func(c *Client) error {
+		c.dl = true
+		return nil
+	}
+}
+
 // WithHELO tells the client to use the provided string as HELO/EHLO greeting host
 func WithHELO(h string) Option {
 	return func(c *Client) error {
@@ -397,6 +409,11 @@ func (c *Client) SetSSL(s bool) {
 	c.ssl = s
 }
 
+// SetDebugLog tells the Client whether debug logging is enabled or not
+func (c *Client) SetDebugLog(s bool) {
+	c.dl = s
+}
+
 // SetTLSConfig overrides the current *tls.Config with the given *tls.Config value
 func (c *Client) SetTLSConfig(co *tls.Config) error {
 	if co == nil {
@@ -461,6 +478,9 @@ func (c *Client) DialWithContext(pc context.Context) error {
 	if err != nil {
 		return err
 	}
+	if c.dl {
+		c.sc.SetDebugLog()
+	}
 	if err := c.sc.Hello(c.helo); err != nil {
 		return err
 	}

client_test.go

@@ -105,6 +105,7 @@ func TestNewClientWithOptions(t *testing.T) {
 		{"WithDSNRcptNotifyType()", WithDSNRcptNotifyType(DSNRcptNotifySuccess), false},
 		{"WithDSNRcptNotifyType() wrong option", WithDSNRcptNotifyType("FAIL"), true},
 		{"WithoutNoop()", WithoutNoop(), false},
+		{"WithDebugLog()", WithDebugLog(), false},
 
 		{
 			"WithDSNRcptNotifyType() NEVER combination",
@@ -542,6 +543,30 @@ func TestClient_DialWithContext(t *testing.T) {
 	}
 }
 
+// TestClient_DialWithContext_Debug tests the DialWithContext method for the Client object with debug
+// logging enabled on the SMTP client
+func TestClient_DialWithContext_Debug(t *testing.T) {
+	c, err := getTestConnection(true)
+	if err != nil {
+		t.Skipf("failed to create test client: %s. Skipping tests", err)
+	}
+	c.SetDebugLog(true)
+	ctx := context.Background()
+	if err := c.DialWithContext(ctx); err != nil {
+		t.Errorf("failed to dial with context: %s", err)
+		return
+	}
+	if c.co == nil {
+		t.Errorf("DialWithContext didn't fail but no connection found.")
+	}
+	if c.sc == nil {
+		t.Errorf("DialWithContext didn't fail but no SMTP client found.")
+	}
+	if err := c.Close(); err != nil {
+		t.Errorf("failed to close connection: %s", err)
+	}
+}
+
 // TestClient_DialWithContextInvalidHost tests the DialWithContext method with intentional breaking
 // for the Client object
 func TestClient_DialWithContextInvalidHost(t *testing.T) {
@@ -1087,7 +1112,6 @@ func getTestConnection(auth bool) (*Client, error) {
 	if th == "" {
 		return nil, fmt.Errorf("no TEST_HOST set")
 	}
-	fmt.Printf("XXX: TEST_HOST: %s\n", th)
 	tp := 25
 	if tps := os.Getenv("TEST_PORT"); tps != "" {
 		tpi, err := strconv.Atoi(tps)

smtp/smtp.go

@@ -32,8 +32,10 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"log"
 	"net"
 	"net/textproto"
+	"os"
 	"strings"
 )
 
@@ -55,8 +57,19 @@ type Client struct {
 	localName  string // the name to use in HELO/EHLO
 	didHello   bool   // whether we've said HELO/EHLO
 	helloError error  // the error from the hello
+
+	debug  bool        // debug logging is enabled
+	logger *log.Logger // logger will be used for debug logging
 }
 
+// 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) {
@@ -81,6 +94,7 @@ func NewClient(conn net.Conn, host string) (*Client, error) {
 	}
 	c := &Client{Text: text, conn: conn, serverName: host, localName: "localhost"}
 	_, c.tls = conn.(*tls.Conn)
+
 	return c, nil
 }
 
@@ -119,6 +133,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...)
 	id, err := c.Text.Cmd(format, args...)
 	if err != nil {
 		return 0, "", err
@@ -126,6 +141,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)
 	return code, msg, err
 }
 
@@ -415,6 +431,24 @@ func (c *Client) Quit() error {
 	return c.Text.Close()
 }
 
+// SetDebugLog enables the debug logging for incoming and outgoing SMTP messages
+func (c *Client) SetDebugLog() {
+	c.debug = true
+	c.logger = log.New(os.Stderr, "[DEBUG] ", log.LstdFlags|log.Lmsgprefix)
+}
+
+// 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{}) {
+	if c.debug {
+		p := "S <-- C:"
+		if d == logOut {
+			p = "C --> S:"
+		}
+		fs := fmt.Sprintf("%s %s", p, f)
+		c.logger.Printf(fs, a...)
+	}
+}
+
 // validateLine checks to see if a line has CR or LF as per RFC 5321.
 func validateLine(line string) error {
 	if strings.ContainsAny(line, "\n\r") {

smtp/smtp_test.go

@@ -633,6 +633,34 @@ func TestNewClient(t *testing.T) {
 	}
 }
 
+// TestClient_SetDebugLog tests the Client method with the Client.SetDebugLog method
+// to enable debug logging
+func TestClient_SetDebugLog(t *testing.T) {
+	server := strings.Join(strings.Split(newClientServer, "\n"), "\r\n")
+
+	var cmdbuf strings.Builder
+	bcmdbuf := bufio.NewWriter(&cmdbuf)
+	out := func() string {
+		if err := bcmdbuf.Flush(); err != nil {
+			t.Errorf("failed to flush: %s", err)
+		}
+		return cmdbuf.String()
+	}
+	var fake faker
+	fake.ReadWriter = bufio.NewReadWriter(bufio.NewReader(strings.NewReader(server)), bcmdbuf)
+	c, err := NewClient(fake, "fake.host")
+	if err != nil {
+		t.Fatalf("NewClient: %v\n(after %v)", err, out())
+	}
+	defer func() {
+		_ = c.Close()
+	}()
+	c.SetDebugLog()
+	if !c.debug {
+		t.Errorf("Expected DebugLog flag to be true but received false")
+	}
+}
+
 var newClientServer = `220 hello world
 250-mx.google.com at your service
 250-SIZE 35651584