imapclient: log traces of sensitive data with traceauth, and of bulk data with tracedata

Similar to the imapserver. This also fixes tracing of APPEND messages, which
was completely absent before.

imapclient/client.go

@@ -18,6 +18,7 @@ import (
 	"bufio"
 	"crypto/tls"
 	"fmt"
+	"log/slog"
 	"net"
 	"reflect"
 	"strings"
@@ -38,6 +39,8 @@ type Conn struct {
 	compress    bool // If compression is enabled, we must flush flateWriter and its target original bufio writer.
 	flateWriter *moxio.FlateWriter
 	flateBW     *bufio.Writer
+	tr          *moxio.TraceReader
+	tw          *moxio.TraceWriter
 
 	log       mlog.Log
 	panic     bool
@@ -74,14 +77,17 @@ func New(cid int64, conn net.Conn, xpanic bool) (client *Conn, rerr error) {
 	log := mlog.New("imapclient", nil).WithCid(cid)
 	c := Conn{
 		conn:         conn,
-		br:           bufio.NewReader(moxio.NewTraceReader(log, "CR: ", conn)),
 		log:          log,
 		panic:        xpanic,
 		CapAvailable: map[Capability]struct{}{},
 		CapEnabled:   map[Capability]struct{}{},
 	}
+	c.tr = moxio.NewTraceReader(log, "CR: ", &c)
+	c.br = bufio.NewReader(c.tr)
+
 	// Writes are buffered and write to Conn, which may panic.
-	c.bw = bufio.NewWriter(moxio.NewTraceWriter(log, "CW: ", &c))
+	c.tw = moxio.NewTraceWriter(log, "CW: ", &c)
+	c.bw = bufio.NewWriter(c.tw)
 
 	defer c.recover(&rerr)
 	tag := c.xnonspace()
@@ -139,8 +145,9 @@ func (c *Conn) xcheck(err error) {
 	}
 }
 
-// Write writes directly to the connection. Write errors do take the connection's
+// Write writes directly to underlying connection (TCP, TLS). For internal use
-// panic mode into account, i.e. Write can panic.
+// only, to implement io.Writer. Write errors do take the connection's panic mode
+// into account, i.e. Write can panic.
 func (c *Conn) Write(buf []byte) (n int, rerr error) {
 	defer c.recover(&rerr)
 
@@ -152,6 +159,12 @@ func (c *Conn) Write(buf []byte) (n int, rerr error) {
 	return n, nil
 }
 
+// Read reads directly from the underlying connection (TCP, TLS). For internal use
+// only, to implement io.Reader.
+func (c *Conn) Read(buf []byte) (n int, err error) {
+	return c.conn.Read(buf)
+}
+
 func (c *Conn) xflush() {
 	// Not writing any more when connection is broken.
 	if c.connBroken {
@@ -170,6 +183,17 @@ func (c *Conn) xflush() {
 	}
 }
 
+func (c *Conn) xtrace(level slog.Level) func() {
+	c.xflush()
+	c.tr.SetTrace(level)
+	c.tw.SetTrace(level)
+	return func() {
+		c.xflush()
+		c.tr.SetTrace(mlog.LevelTrace)
+		c.tw.SetTrace(mlog.LevelTrace)
+	}
+}
+
 // SetPanic sets whether errors cause a panic instead of returning errors.
 func (c *Conn) SetPanic(panic bool) {
 	c.panic = panic
@@ -291,10 +315,14 @@ func (c *Conn) Readline() (line string, rerr error) {
 // Callers should check rerr and result.Status being empty to check if a
 // continuation was read.
 func (c *Conn) ReadContinuation() (line string, untagged []Untagged, result Result, rerr error) {
+	defer c.recover(&rerr)
+
 	if !c.peek('+') {
 		untagged, result, rerr = c.Response()
-		c.xcheckf(rerr, "reading non-continuation response")
+		if result.Status == OK {
-		c.xerrorf("response status %q, expected OK", result.Status)
+			c.xerrorf("unexpected OK instead of continuation")
+		}
+		return
 	}
 	c.xtake("+ ")
 	line, err := c.Readline()

imapclient/cmds.go

@@ -50,24 +50,42 @@ func (c *Conn) Starttls(config *tls.Config) (untagged []Untagged, result Result,
 	err := tlsConn.Handshake()
 	c.xcheckf(err, "tls handshake")
 	c.conn = tlsConn
-	c.br = bufio.NewReader(moxio.NewTraceReader(c.log, "CR: ", tlsConn))
-	c.bw = bufio.NewWriter(moxio.NewTraceWriter(c.log, "CW: ", c))
 	return untagged, result, nil
 }
 
 // Login authenticates with username and password
 func (c *Conn) Login(username, password string) (untagged []Untagged, result Result, rerr error) {
 	defer c.recover(&rerr)
-	return c.Transactf("login %s %s", astring(username), astring(password))
+
+	c.LastTag = c.nextTag()
+	fmt.Fprintf(c.bw, "%s login %s ", c.LastTag, astring(username))
+	defer c.xtrace(mlog.LevelTraceauth)()
+	fmt.Fprintf(c.bw, "%s\r\n", astring(password))
+	c.xtrace(mlog.LevelTrace) // Restore.
+	return c.Response()
 }
 
 // Authenticate with plaintext password using AUTHENTICATE PLAIN.
 func (c *Conn) AuthenticatePlain(username, password string) (untagged []Untagged, result Result, rerr error) {
 	defer c.recover(&rerr)
 
-	untagged, result, rerr = c.Transactf("authenticate plain %s", base64.StdEncoding.EncodeToString(fmt.Appendf(nil, "\u0000%s\u0000%s", username, password)))
+	c.Commandf("", "authenticate plain")
-	return
+	_, untagged, result, rerr = c.ReadContinuation()
+	c.xcheckf(rerr, "reading continuation")
+	if result.Status != "" {
+		c.xerrorf("got result status %q, expected continuation", result.Status)
 	}
+	defer c.xtrace(mlog.LevelTraceauth)()
+	xw := base64.NewEncoder(base64.StdEncoding, c.bw)
+	fmt.Fprintf(xw, "\u0000%s\u0000%s", username, password)
+	xw.Close()
+	c.xtrace(mlog.LevelTrace) // Restore.
+	fmt.Fprintf(c.bw, "\r\n")
+	c.xflush()
+	return c.Response()
+}
+
+// todo: implement cram-md5, write its credentials as traceauth.
 
 // Authenticate with SCRAM-SHA-256(-PLUS) or SCRAM-SHA-1(-PLUS). With SCRAM, the
 // password is not exchanged in plaintext form, but only derived hashes are
@@ -100,7 +118,7 @@ func (c *Conn) AuthenticateSCRAM(method string, h func() hash.Hash, username, pa
 		line, untagged, result, rerr = c.ReadContinuation()
 		c.xcheckf(err, "read continuation")
 		if result.Status != "" {
-			c.xerrorf("unexpected status %q", result.Status)
+			c.xerrorf("got result status %q, expected continuation", result.Status)
 		}
 		buf, err := base64.StdEncoding.DecodeString(line)
 		c.xcheckf(err, "parsing base64 from remote")
@@ -146,13 +164,13 @@ func (c *Conn) CompressDeflate() (untagged []Untagged, result Result, rerr error
 
 	c.compress = true
 	c.flateWriter = fw
-	tw := moxio.NewTraceWriter(mlog.New("imapclient", nil), "CW: ", fw)
+	c.tw = moxio.NewTraceWriter(mlog.New("imapclient", nil), "CW: ", fw)
-	c.bw = bufio.NewWriter(tw)
+	c.bw = bufio.NewWriter(c.tw)
 
 	rc := c.xprefixConn()
 	fr := flate.NewReaderPartial(rc)
-	tr := moxio.NewTraceReader(mlog.New("imapclient", nil), "CR: ", fr)
+	c.tr = moxio.NewTraceReader(mlog.New("imapclient", nil), "CR: ", fr)
-	c.br = bufio.NewReader(tr)
+	c.br = bufio.NewReader(c.tr)
 
 	return
 }
@@ -303,9 +321,10 @@ func (c *Conn) Append(mailbox string, message Append, more ...Append) (untagged
 		// todo: for larger messages, use a synchronizing literal.
 
 		fmt.Fprintf(c.bw, " (%s)%s {%d+}\r\n", strings.Join(m.Flags, " "), date, m.Size)
-		c.xflush()
+		defer c.xtrace(mlog.LevelTracedata)()
-		_, err := io.Copy(c, m.Data)
+		_, err := io.Copy(c.bw, m.Data)
 		c.xcheckf(err, "write message data")
+		c.xtrace(mlog.LevelTrace) // Restore
 	}
 
 	fmt.Fprintf(c.bw, "\r\n")
@@ -428,8 +447,10 @@ func (c *Conn) replace(cmd string, num string, mailbox string, msg Append) (unta
 	// todo: encode mailbox
 	c.Commandf("", "%s %s %s (%s)%s ~{%d+}", cmd, num, astring(mailbox), strings.Join(msg.Flags, " "), date, msg.Size)
 
-	_, err := io.Copy(c, msg.Data)
+	defer c.xtrace(mlog.LevelTracedata)()
+	_, err := io.Copy(c.bw, msg.Data)
 	c.xcheckf(err, "write message data")
+	c.xtrace(mlog.LevelTrace)
 
 	fmt.Fprintf(c.bw, "\r\n")
 	c.xflush()

imapclient/parse.go

@@ -850,6 +850,7 @@ func (c *Conn) xliteral() []byte {
 	sync := c.take('+')
 	c.xtake("}")
 	c.xcrlf()
+	// todo: for some literals, read as tracedata
 	if size > 1<<20 {
 		c.xerrorf("refusing to read more than 1MB: %d", size)
 	}

imapserver/authenticate_test.go

@@ -135,8 +135,7 @@ func testAuthenticateSCRAM(t *testing.T, tls bool, method string, h func() hash.
 		tc.writelinef("%s authenticate %s %s", tc.client.LastTag, method, base64.StdEncoding.EncodeToString([]byte(clientFirst)))
 
 		xreadContinuation := func() []byte {
-			line, _, result, rerr := tc.client.ReadContinuation()
+			line, _, result, _ := tc.client.ReadContinuation()
-			tc.check(rerr, "read continuation")
 			if result.Status != "" {
 				tc.t.Fatalf("expected continuation")
 			}
@@ -200,8 +199,7 @@ func TestAuthenticateCRAMMD5(t *testing.T) {
 		tc.writelinef("%s authenticate CRAM-MD5", tc.client.LastTag)
 
 		xreadContinuation := func() []byte {
-			line, _, result, rerr := tc.client.ReadContinuation()
+			line, _, result, _ := tc.client.ReadContinuation()
-			tc.check(rerr, "read continuation")
 			if result.Status != "" {
 				tc.t.Fatalf("expected continuation")
 			}