From 981142a7d5001fc24e665cd0c142c660177b70b5 Mon Sep 17 00:00:00 2001 From: Mariuso <2239962+mariuso@users.noreply.github.com> Date: Sun, 6 Jul 2025 00:07:25 +0200 Subject: [PATCH 1/2] Fix noisy error logging for zero-byte connections Addresses issue #236 where health checks and load balancer probes that connect and immediately disconnect generate unnecessary 'connection reset by peer' error logs. Changes: - Add hasReceivedData field to Conn struct to track data reception - Set flag in readLine() when SMTP data is successfully read - Only log connection errors if data was actually received - Add comprehensive test covering both scenarios This eliminates log spam from health checks while preserving error visibility for legitimate SMTP sessions. Fixes: https://github.com/emersion/go-smtp/issues/236 --- conn.go | 13 +++++-- server.go | 5 ++- server_test.go | 103 +++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 115 insertions(+), 6 deletions(-) diff --git a/conn.go b/conn.go index 88ea360f..07b6eafd 100644 --- a/conn.go +++ b/conn.go @@ -41,9 +41,10 @@ type Conn struct { dataResult chan error bytesReceived int64 // counts total size of chunks when BDAT is used - fromReceived bool - recipients []string - didAuth bool + fromReceived bool + recipients []string + didAuth bool + hasReceivedData bool // tracks if connection has sent any SMTP data } func newConn(c net.Conn, s *Server) *Conn { @@ -1305,7 +1306,11 @@ func (c *Conn) readLine() (string, error) { } } - return c.text.ReadLine() + line, err := c.text.ReadLine() + if err == nil { + c.hasReceivedData = true // Mark that connection sent data + } + return line, err } func (c *Conn) reset() { diff --git a/server.go b/server.go index ddcae036..c5d2a679 100644 --- a/server.go +++ b/server.go @@ -131,8 +131,9 @@ func (s *Server) Serve(l net.Listener) error { go func() { defer s.wg.Done() - err := s.handleConn(newConn(c, s)) - if err != nil { + conn := newConn(c, s) + err := s.handleConn(conn) + if err != nil && conn.hasReceivedData { s.ErrorLog.Printf("error handling %v: %s", c.RemoteAddr(), err) } }() diff --git a/server_test.go b/server_test.go index ed074310..7bb0173c 100644 --- a/server_test.go +++ b/server_test.go @@ -1650,3 +1650,106 @@ func TestServerDELIVERBY(t *testing.T) { t.Fatal("Incorrect BY parameter value:", fmt.Sprintf("expected %#v, got %#v", expectedDeliverByOpts, deliverByOpts)) } } + +func TestZeroByteConnectionLogging(t *testing.T) { + // Test for Issue #236: https://github.com/emersion/go-smtp/issues/236 + // Zero-byte connections (health checks) should not generate error logs + + t.Run("HealthCheckNoLogging", func(t *testing.T) { + // Capture error logs + var logBuffer bytes.Buffer + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + defer l.Close() + + be := new(backend) + s := smtp.NewServer(be) + s.Domain = "localhost" + s.ErrorLog = log.New(&logBuffer, "", 0) + + done := make(chan error, 1) + go func() { + done <- s.Serve(l) + }() + + // Simulate health check: connect and immediately close (no data sent) + conn, err := net.Dial("tcp", l.Addr().String()) + if err != nil { + t.Fatal(err) + } + + // Wait just enough for server to start processing, then force close + time.Sleep(10 * time.Millisecond) + if tcpConn, ok := conn.(*net.TCPConn); ok { + tcpConn.SetLinger(0) // Force RST to trigger "connection reset by peer" + } + conn.Close() + + // Wait for server to process the connection reset + time.Sleep(100 * time.Millisecond) + + s.Close() + <-done + + // Verify no error logs for zero-byte connection + logOutput := logBuffer.String() + if logOutput != "" { + t.Errorf("Expected no error logs for health check, but got: %s", logOutput) + } + }) + + t.Run("NormalErrorLogging", func(t *testing.T) { + // Verify that normal SMTP errors are still logged when data was sent + var logBuffer bytes.Buffer + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + defer l.Close() + + be := new(backend) + s := smtp.NewServer(be) + s.Domain = "localhost" + s.ErrorLog = log.New(&logBuffer, "", 0) + + done := make(chan error, 1) + go func() { + done <- s.Serve(l) + }() + + // Connect and send some SMTP data, then abruptly close + conn, err := net.Dial("tcp", l.Addr().String()) + if err != nil { + t.Fatal(err) + } + + // Read greeting + buffer := make([]byte, 1024) + conn.SetReadDeadline(time.Now().Add(1 * time.Second)) + conn.Read(buffer) + + // Send EHLO command (this marks the connection as having received data) + conn.Write([]byte("EHLO test\r\n")) + + // Wait for response and then abruptly close + time.Sleep(50 * time.Millisecond) + if tcpConn, ok := conn.(*net.TCPConn); ok { + tcpConn.SetLinger(0) // Force RST + } + conn.Close() + + // Wait for server to process the connection reset + time.Sleep(100 * time.Millisecond) + + s.Close() + <-done + + // Verify that error was logged (connection had sent data) + logOutput := logBuffer.String() + if !strings.Contains(logOutput, "error handling") { + t.Errorf("Expected error log for connection with data, but got: %s", logOutput) + } + }) +} From 5912d074d081e0da548c348fe3e54278deb97fef Mon Sep 17 00:00:00 2001 From: Mariuso <2239962+mariuso@users.noreply.github.com> Date: Sun, 6 Jul 2025 20:10:14 +0200 Subject: [PATCH 2/2] Fix zero-byte connections to return EOF instead of connection error When clients connect and immediately disconnect without sending data (common for health checks), return io.EOF instead of connection reset error. This prevents noisy error logs for normal health check behavior. - Modified readLine() to detect zero-byte connections and return EOF - Removed hasReceivedData check from error logging - Added tests to verify health checks don't generate error logs - Real connection errors are still properly logged --- conn.go | 11 +++++ server.go | 2 +- zero_byte_connection_test.go | 94 ++++++++++++++++++++++++++++++++++++ 3 files changed, 106 insertions(+), 1 deletion(-) create mode 100644 zero_byte_connection_test.go diff --git a/conn.go b/conn.go index 07b6eafd..afdefa4e 100644 --- a/conn.go +++ b/conn.go @@ -1309,6 +1309,17 @@ func (c *Conn) readLine() (string, error) { line, err := c.text.ReadLine() if err == nil { c.hasReceivedData = true // Mark that connection sent data + } else if err != nil && !c.hasReceivedData { + // If we haven't received any data and get a connection error, + // treat it as EOF (client connected and immediately disconnected) + if netErr, ok := err.(*net.OpError); ok && netErr.Op == "read" { + return "", io.EOF + } + // Also handle textproto connection errors + if strings.Contains(err.Error(), "connection reset by peer") || + strings.Contains(err.Error(), "broken pipe") { + return "", io.EOF + } } return line, err } diff --git a/server.go b/server.go index c5d2a679..a162b8da 100644 --- a/server.go +++ b/server.go @@ -133,7 +133,7 @@ func (s *Server) Serve(l net.Listener) error { conn := newConn(c, s) err := s.handleConn(conn) - if err != nil && conn.hasReceivedData { + if err != nil { s.ErrorLog.Printf("error handling %v: %s", c.RemoteAddr(), err) } }() diff --git a/zero_byte_connection_test.go b/zero_byte_connection_test.go new file mode 100644 index 00000000..f0e45ccd --- /dev/null +++ b/zero_byte_connection_test.go @@ -0,0 +1,94 @@ +package smtp_test + +import ( + "bytes" + "log" + "net" + "strings" + "testing" + "time" + + "github.com/emersion/go-smtp" +) + +// TestZeroByteConnection verifies that health check connections that +// connect and immediately disconnect don't generate error logs +func TestZeroByteConnection(t *testing.T) { + // Capture error logs + var logBuf bytes.Buffer + logger := log.New(&logBuf, "test: ", 0) + + be := &backend{} + s := smtp.NewServer(be) + s.ErrorLog = logger + defer s.Close() + + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + defer l.Close() + + go s.Serve(l) + + // Simulate health check connections + for i := 0; i < 5; i++ { + conn, err := net.Dial("tcp", l.Addr().String()) + if err != nil { + t.Fatal(err) + } + // Immediately close without sending any data + conn.Close() + } + + // Give server time to process connections + time.Sleep(100 * time.Millisecond) + + // Check logs + logs := logBuf.String() + if strings.Contains(logs, "error handling") { + t.Errorf("Zero-byte connections should not generate error logs, but got:\n%s", logs) + } +} + +// TestNormalConnectionError verifies that real connection errors are still logged +func TestNormalConnectionError(t *testing.T) { + // Capture error logs + var logBuf bytes.Buffer + logger := log.New(&logBuf, "test: ", 0) + + be := &backend{} + s := smtp.NewServer(be) + s.ErrorLog = logger + s.ReadTimeout = 50 * time.Millisecond // Short timeout to force error + defer s.Close() + + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + defer l.Close() + + go s.Serve(l) + + // Connect and send partial command + conn, err := net.Dial("tcp", l.Addr().String()) + if err != nil { + t.Fatal(err) + } + defer conn.Close() + + // Read greeting + buf := make([]byte, 1024) + conn.Read(buf) + + // Send partial command and wait for timeout + conn.Write([]byte("HELO")) + time.Sleep(100 * time.Millisecond) + + // Check that timeout error was logged + logs := logBuf.String() + if !strings.Contains(logs, "error handling") { + t.Error("Connection timeouts should still be logged") + } +} \ No newline at end of file