Adding support for securing error logs (#1001)

Co-authored-by: Daniel Firsht <[email protected]>

client.go

@@ -727,6 +727,14 @@ type HostClient struct {
 	// extra slashes are removed, special characters are encoded.
 	DisablePathNormalizing bool
 
+	// Will not log potentially sensitive content in error logs
+	//
+	// This option is useful for servers that handle sensitive data
+	// in the request/response.
+	//
+	// Client logs full errors by default.
+	SecureErrorLogMessage bool
+
 	// Maximum duration for waiting for a free connection.
 	//
 	// By default will not waiting, return ErrNoFreeConns immediately
@@ -1332,6 +1340,12 @@ func (c *HostClient) doNonNilReqResp(req *Request, resp *Response) (bool, error)
 		panic("BUG: resp cannot be nil")
 	}
 
+	// Secure header error logs configuration
+	resp.secureErrorLogMessage = c.SecureErrorLogMessage
+	resp.Header.secureErrorLogMessage = c.SecureErrorLogMessage
+	req.secureErrorLogMessage = c.SecureErrorLogMessage
+	req.Header.secureErrorLogMessage = c.SecureErrorLogMessage
+
 	if c.IsTLS != bytes.Equal(req.uri.Scheme(), strHTTPS) {
 		return false, ErrHostClientRedirectToDifferentScheme
 	}

header.go

@@ -35,6 +35,7 @@ type ResponseHeader struct {
 	statusCode         int
 	contentLength      int
 	contentLengthBytes []byte
+	secureErrorLogMessage     bool
 
 	contentType []byte
 	server      []byte
@@ -65,6 +66,7 @@ type RequestHeader struct {
 
 	contentLength      int
 	contentLengthBytes []byte
+	secureErrorLogMessage     bool
 
 	method      []byte
 	requestURI  []byte
@@ -1354,6 +1356,11 @@ func (h *ResponseHeader) tryRead(r *bufio.Reader, n int) error {
 
 		// This is for go 1.6 bug. See https://github.com/golang/go/issues/14121 .
 		if err == bufio.ErrBufferFull {
+			if h.secureErrorLogMessage {
+				return &ErrSmallBuffer{
+					error: fmt.Errorf("error when reading response headers"),
+				}
+			}
 			return &ErrSmallBuffer{
 				error: fmt.Errorf("error when reading response headers: %s", errSmallBuffer),
 			}
@@ -1364,15 +1371,15 @@ func (h *ResponseHeader) tryRead(r *bufio.Reader, n int) error {
 	b = mustPeekBuffered(r)
 	headersLen, errParse := h.parse(b)
 	if errParse != nil {
-		return headerError("response", err, errParse, b)
+		return headerError("response", err, errParse, b, h.secureErrorLogMessage)
 	}
 	mustDiscard(r, headersLen)
 	return nil
 }
 
-func headerError(typ string, err, errParse error, b []byte) error {
+func headerError(typ string, err, errParse error, b []byte, secureErrorLogMessage bool) error {
 	if errParse != errNeedMore {
-		return headerErrorMsg(typ, errParse, b)
+		return headerErrorMsg(typ, errParse, b, secureErrorLogMessage)
 	}
 	if err == nil {
 		return errNeedMore
@@ -1385,14 +1392,17 @@ func headerError(typ string, err, errParse error, b []byte) error {
 	}
 
 	if err != bufio.ErrBufferFull {
-		return headerErrorMsg(typ, err, b)
+		return headerErrorMsg(typ, err, b, secureErrorLogMessage)
 	}
 	return &ErrSmallBuffer{
-		error: headerErrorMsg(typ, errSmallBuffer, b),
+		error: headerErrorMsg(typ, errSmallBuffer, b, secureErrorLogMessage),
 	}
 }
 
-func headerErrorMsg(typ string, err error, b []byte) error {
+func headerErrorMsg(typ string, err error, b []byte, secureErrorLogMessage bool) error {
+	if secureErrorLogMessage {
+		return fmt.Errorf("error when reading %s headers: %s. Buffer size=%d", typ, err, len(b))
+	}
 	return fmt.Errorf("error when reading %s headers: %s. Buffer size=%d, contents: %s", typ, err, len(b), bufferSnippet(b))
 }
 
@@ -1444,7 +1454,7 @@ func (h *RequestHeader) tryRead(r *bufio.Reader, n int) error {
 	b = mustPeekBuffered(r)
 	headersLen, errParse := h.parse(b)
 	if errParse != nil {
-		return headerError("request", err, errParse, b)
+		return headerError("request", err, errParse, b, h.secureErrorLogMessage)
 	}
 	mustDiscard(r, headersLen)
 	return nil
@@ -1724,6 +1734,9 @@ func (h *ResponseHeader) parseFirstLine(buf []byte) (int, error) {
 	// parse protocol
 	n := bytes.IndexByte(b, ' ')
 	if n < 0 {
+		if h.secureErrorLogMessage {
+			return 0, fmt.Errorf("cannot find whitespace in the first line of response")
+		}
 		return 0, fmt.Errorf("cannot find whitespace in the first line of response %q", buf)
 	}
 	h.noHTTP11 = !bytes.Equal(b[:n], strHTTP11)
@@ -1732,9 +1745,15 @@ func (h *ResponseHeader) parseFirstLine(buf []byte) (int, error) {
 	// parse status code
 	h.statusCode, n, err = parseUintBuf(b)
 	if err != nil {
+		if h.secureErrorLogMessage {
+			return 0, fmt.Errorf("cannot parse response status code: %s", err)
+		}
 		return 0, fmt.Errorf("cannot parse response status code: %s. Response %q", err, buf)
 	}
 	if len(b) > n && b[n] != ' ' {
+		if h.secureErrorLogMessage {
+			return 0, fmt.Errorf("unexpected char at the end of status code")
+		}
 		return 0, fmt.Errorf("unexpected char at the end of status code. Response %q", buf)
 	}
 
@@ -1754,6 +1773,9 @@ func (h *RequestHeader) parseFirstLine(buf []byte) (int, error) {
 	// parse method
 	n := bytes.IndexByte(b, ' ')
 	if n <= 0 {
+		if h.secureErrorLogMessage {
+			return 0, fmt.Errorf("cannot find http request method")
+		}
 		return 0, fmt.Errorf("cannot find http request method in %q", buf)
 	}
 	h.method = append(h.method[:0], b[:n]...)
@@ -1767,6 +1789,9 @@ func (h *RequestHeader) parseFirstLine(buf []byte) (int, error) {
 		n = len(b)
 		protoStr = strHTTP10
 	} else if n == 0 {
+		if h.secureErrorLogMessage {
+			return 0, fmt.Errorf("requestURI cannot be empty")
+		}
 		return 0, fmt.Errorf("requestURI cannot be empty in %q", buf)
 	} else if !bytes.Equal(b[n+1:], strHTTP11) {
 		h.noHTTP11 = true

header_test.go

@@ -2399,6 +2399,31 @@ func TestResponseHeaderReadError(t *testing.T) {
 	testResponseHeaderReadError(t, h, "HTTP/1.1 200 OK\r\nContent-Length: 123\r\nContent-Type: text/html\r\n")
 }
 
+func TestResponseHeaderReadErrorSecureLog(t *testing.T) {
+	h := &ResponseHeader{
+		secureErrorLogMessage: true,
+	}
+
+	// incorrect first line
+	testResponseHeaderReadSecuredError(t, h, "fo")
+	testResponseHeaderReadSecuredError(t, h, "foobarbaz")
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1")
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 ")
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 s")
+
+	// non-numeric status code
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 foobar OK\r\nContent-Length: 123\r\nContent-Type: text/html\r\n\r\n")
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 123foobar OK\r\nContent-Length: 123\r\nContent-Type: text/html\r\n\r\n")
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 foobar344 OK\r\nContent-Length: 123\r\nContent-Type: text/html\r\n\r\n")
+
+
+	// no headers
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 200 OK\r\n")
+
+	// no trailing crlf
+	testResponseHeaderReadSecuredError(t, h, "HTTP/1.1 200 OK\r\nContent-Length: 123\r\nContent-Type: text/html\r\n")
+}
+
 func TestRequestHeaderReadError(t *testing.T) {
 	t.Parallel()
 
@@ -2417,14 +2442,47 @@ func TestRequestHeaderReadError(t *testing.T) {
 	testRequestHeaderReadError(t, h, "POST /a HTTP/1.1\r\nHost: bb\r\nContent-Type: aa\r\nContent-Length: dff\r\n\r\nqwerty")
 }
 
+func TestRequestHeaderReadSecuredError(t *testing.T) {
+	t.Parallel()
+
+	h := &RequestHeader{
+		secureErrorLogMessage: true,
+	}
+
+	// incorrect first line
+	testRequestHeaderReadSecuredError(t, h, "fo")
+	testRequestHeaderReadSecuredError(t, h, "GET ")
+	testRequestHeaderReadSecuredError(t, h, "GET / HTTP/1.1\r")
+
+	// missing RequestURI
+	testRequestHeaderReadSecuredError(t, h, "GET  HTTP/1.1\r\nHost: google.com\r\n\r\n")
+
+	// post with invalid content-length
+	testRequestHeaderReadSecuredError(t, h, "POST /a HTTP/1.1\r\nHost: bb\r\nContent-Type: aa\r\nContent-Length: dff\r\n\r\nqwerty")
+}
+
 func testResponseHeaderReadError(t *testing.T, h *ResponseHeader, headers string) {
 	r := bytes.NewBufferString(headers)
 	br := bufio.NewReader(r)
 	err := h.Read(br)
 	if err == nil {
 		t.Fatalf("Expecting error when reading response header %q", headers)
 	}
+	// make sure response header works after error
+	testResponseHeaderReadSuccess(t, h, "HTTP/1.1 200 OK\r\nContent-Type: foo/bar\r\nContent-Length: 12345\r\n\r\nsss",
+		200, 12345, "foo/bar", "sss")
+}
 
+func testResponseHeaderReadSecuredError(t *testing.T, h *ResponseHeader, headers string) {
+	r := bytes.NewBufferString(headers)
+	br := bufio.NewReader(r)
+	err := h.Read(br)
+	if err == nil {
+		t.Fatalf("Expecting error when reading response header %q", headers)
+	}
+	if strings.Contains(err.Error(), headers) {
+		t.Fatalf("Not expecting header content in err %q", err)
+	}
 	// make sure response header works after error
 	testResponseHeaderReadSuccess(t, h, "HTTP/1.1 200 OK\r\nContent-Type: foo/bar\r\nContent-Length: 12345\r\n\r\nsss",
 		200, 12345, "foo/bar", "sss")
@@ -2443,6 +2501,21 @@ func testRequestHeaderReadError(t *testing.T, h *RequestHeader, headers string)
 		-2, "/foo/bar", "aaaa", "", "", "xxx")
 }
 
+func testRequestHeaderReadSecuredError(t *testing.T, h *RequestHeader, headers string) {
+	r := bytes.NewBufferString(headers)
+	br := bufio.NewReader(r)
+	err := h.Read(br)
+	if err == nil {
+		t.Fatalf("Expecting error when reading request header %q", headers)
+	}
+	if strings.Contains(err.Error(), headers) {
+		t.Fatalf("Not expecting header content in err %q", err)
+	}
+	// make sure request header works after error
+	testRequestHeaderReadSuccess(t, h, "GET /foo/bar HTTP/1.1\r\nHost: aaaa\r\n\r\nxxx",
+		-2, "/foo/bar", "aaaa", "", "", "xxx")
+}
+
 func testResponseHeaderReadSuccess(t *testing.T, h *ResponseHeader, headers string, expectedStatusCode, expectedContentLength int,
 	expectedContentType, expectedTrailer string) {
 	r := bytes.NewBufferString(headers)

http.go

@@ -41,6 +41,7 @@ type Request struct {
 
 	multipartForm         *multipart.Form
 	multipartFormBoundary string
+	secureErrorLogMessage        bool
 
 	// Group bool members in order to reduce Request object size.
 	parsedURI      bool
@@ -88,6 +89,7 @@ type Response struct {
 	SkipBody bool
 
 	keepBodyBuffer bool
+	secureErrorLogMessage bool
 
 	// Remote TCPAddr from concurrently net.Conn
 	raddr net.Addr
@@ -1368,6 +1370,9 @@ func (req *Request) Write(w *bufio.Writer) error {
 	if hasBody {
 		_, err = w.Write(body)
 	} else if len(body) > 0 {
+		if req.secureErrorLogMessage {
+			return fmt.Errorf("non-zero body for non-POST request")
+		}
 		return fmt.Errorf("non-zero body for non-POST request. body=%q", body)
 	}
 	return err

server.go

@@ -312,6 +312,14 @@ type Server struct {
 	// are suppressed in order to limit output log traffic.
 	LogAllErrors bool
 
+	// Will not log potentially sensitive content in error logs
+	//
+	// This option is useful for servers that handle sensitive data
+	// in the request/response.
+	//
+	// Server logs all full errors by default.
+	SecureErrorLogMessage bool
+
 	// Header names are passed as-is without normalization
 	// if this option is set.
 	//
@@ -2055,6 +2063,12 @@ func (s *Server) serveConn(c net.Conn) (err error) {
 		ctx.Response.Header.noDefaultContentType = s.NoDefaultContentType
 		ctx.Response.Header.noDefaultDate = s.NoDefaultDate
 
+		// Secure header error logs configuration
+		ctx.Request.Header.secureErrorLogMessage = s.SecureErrorLogMessage
+		ctx.Response.Header.secureErrorLogMessage = s.SecureErrorLogMessage
+		ctx.Request.secureErrorLogMessage = s.SecureErrorLogMessage
+		ctx.Response.secureErrorLogMessage = s.SecureErrorLogMessage
+
 		if err == nil {
 			if s.ReadTimeout > 0 {
 				if err := c.SetReadDeadline(time.Now().Add(s.ReadTimeout)); err != nil {