From f84524edc8450faf592bdf7a4772fb9119bc37d2 Mon Sep 17 00:00:00 2001 From: Thane Thomson Date: Fri, 12 May 2023 08:00:24 -0400 Subject: [PATCH 1/2] rpc: Truncate response data in response failure logs Signed-off-by: Thane Thomson --- rpc/jsonrpc/server/http_json_handler.go | 6 +++--- rpc/jsonrpc/server/http_server.go | 24 ++++++++++++++++++++++-- rpc/jsonrpc/server/http_uri_handler.go | 8 ++++---- 3 files changed, 29 insertions(+), 9 deletions(-) diff --git a/rpc/jsonrpc/server/http_json_handler.go b/rpc/jsonrpc/server/http_json_handler.go index 8d746c7a224..aabe94b49af 100644 --- a/rpc/jsonrpc/server/http_json_handler.go +++ b/rpc/jsonrpc/server/http_json_handler.go @@ -25,7 +25,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han fmt.Errorf("error reading request body: %w", err), ) if wErr := WriteRPCResponseHTTPError(w, http.StatusBadRequest, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } return } @@ -48,7 +48,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han if err := json.Unmarshal(b, &request); err != nil { res := types.RPCParseError(fmt.Errorf("error unmarshaling request: %w", err)) if wErr := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } return } @@ -122,7 +122,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han wErr = WriteRPCResponseHTTP(w, responses...) } if wErr != nil { - logger.Error("failed to write responses", "res", responses, "err", wErr) + logger.Error("failed to write responses", "res", truncateLoggedResponse(responses), "err", wErr) } } } diff --git a/rpc/jsonrpc/server/http_server.go b/rpc/jsonrpc/server/http_server.go index 3b7cbfec87c..bc276805813 100644 --- a/rpc/jsonrpc/server/http_server.go +++ b/rpc/jsonrpc/server/http_server.go @@ -19,6 +19,10 @@ import ( types "github.com/cometbft/cometbft/rpc/jsonrpc/types" ) +// Setting this value to 900 should allow one to keep short response failures +// in the logs, but limit overall line length to < 1024 characters. +const maxWriteErrorResponseLen int = 900 + // Config is a RPC server configuration. type Config struct { // see netutil.LimitListener @@ -188,7 +192,7 @@ func RecoverAndLogHandler(handler http.Handler, logger log.Logger) http.Handler // If RPCResponse if res, ok := e.(types.RPCResponse); ok { if wErr := WriteRPCResponseHTTP(rww, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } } else { // Panics can contain anything, attempt to normalize it as an error. @@ -207,7 +211,7 @@ func RecoverAndLogHandler(handler http.Handler, logger log.Logger) http.Handler res := types.RPCInternalError(types.JSONRPCIntID(-1), err) if wErr := WriteRPCResponseHTTPError(rww, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } } } @@ -277,3 +281,19 @@ func Listen(addr string, maxOpenConnections int) (listener net.Listener, err err return listener, nil } + +// Logging of RPC responses can sometimes result in very long log lines. +// See https://github.com/cometbft/cometbft/issues/654 +func truncateLoggedResponse(res interface{}) string { + var s string + b, err := json.Marshal(res) + if err != nil { + s = fmt.Sprintf("%s", res) + } else { + s = string(b) + } + if len(s) > maxWriteErrorResponseLen { + s = s[:maxWriteErrorResponseLen] + " ... (truncated)" + } + return s +} diff --git a/rpc/jsonrpc/server/http_uri_handler.go b/rpc/jsonrpc/server/http_uri_handler.go index 134eff20f03..d9dacf581cf 100644 --- a/rpc/jsonrpc/server/http_uri_handler.go +++ b/rpc/jsonrpc/server/http_uri_handler.go @@ -27,7 +27,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit return func(w http.ResponseWriter, r *http.Request) { res := types.RPCMethodNotFoundError(dummyID) if wErr := WriteRPCResponseHTTPError(w, http.StatusNotFound, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } } } @@ -45,7 +45,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit fmt.Errorf("error converting http params to arguments: %w", err), ) if wErr := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", res, "err", wErr) + logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) } return } @@ -58,7 +58,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit if err != nil { if err := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, types.RPCInternalError(dummyID, err)); err != nil { - logger.Error("failed to write response", "res", result, "err", err) + logger.Error("failed to write response", "res", truncateLoggedResponse(result), "err", err) return } return @@ -71,7 +71,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit err = WriteRPCResponseHTTP(w, resp) } if err != nil { - logger.Error("failed to write response", "res", result, "err", err) + logger.Error("failed to write response", "res", truncateLoggedResponse(result), "err", err) return } } From 48e4d2e0d0e212f79e45de8ac048b60ff8cc7fac Mon Sep 17 00:00:00 2001 From: Thane Thomson Date: Sun, 14 May 2023 07:12:33 -0400 Subject: [PATCH 2/2] rpc: Remove response logging for errors Signed-off-by: Thane Thomson --- rpc/jsonrpc/server/http_json_handler.go | 6 +++--- rpc/jsonrpc/server/http_server.go | 24 ++---------------------- rpc/jsonrpc/server/http_uri_handler.go | 8 ++++---- 3 files changed, 9 insertions(+), 29 deletions(-) diff --git a/rpc/jsonrpc/server/http_json_handler.go b/rpc/jsonrpc/server/http_json_handler.go index aabe94b49af..8e5b363f151 100644 --- a/rpc/jsonrpc/server/http_json_handler.go +++ b/rpc/jsonrpc/server/http_json_handler.go @@ -25,7 +25,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han fmt.Errorf("error reading request body: %w", err), ) if wErr := WriteRPCResponseHTTPError(w, http.StatusBadRequest, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } return } @@ -48,7 +48,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han if err := json.Unmarshal(b, &request); err != nil { res := types.RPCParseError(fmt.Errorf("error unmarshaling request: %w", err)) if wErr := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } return } @@ -122,7 +122,7 @@ func makeJSONRPCHandler(funcMap map[string]*RPCFunc, logger log.Logger) http.Han wErr = WriteRPCResponseHTTP(w, responses...) } if wErr != nil { - logger.Error("failed to write responses", "res", truncateLoggedResponse(responses), "err", wErr) + logger.Error("failed to write responses", "err", wErr) } } } diff --git a/rpc/jsonrpc/server/http_server.go b/rpc/jsonrpc/server/http_server.go index bc276805813..4393abf29df 100644 --- a/rpc/jsonrpc/server/http_server.go +++ b/rpc/jsonrpc/server/http_server.go @@ -19,10 +19,6 @@ import ( types "github.com/cometbft/cometbft/rpc/jsonrpc/types" ) -// Setting this value to 900 should allow one to keep short response failures -// in the logs, but limit overall line length to < 1024 characters. -const maxWriteErrorResponseLen int = 900 - // Config is a RPC server configuration. type Config struct { // see netutil.LimitListener @@ -192,7 +188,7 @@ func RecoverAndLogHandler(handler http.Handler, logger log.Logger) http.Handler // If RPCResponse if res, ok := e.(types.RPCResponse); ok { if wErr := WriteRPCResponseHTTP(rww, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } } else { // Panics can contain anything, attempt to normalize it as an error. @@ -211,7 +207,7 @@ func RecoverAndLogHandler(handler http.Handler, logger log.Logger) http.Handler res := types.RPCInternalError(types.JSONRPCIntID(-1), err) if wErr := WriteRPCResponseHTTPError(rww, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } } } @@ -281,19 +277,3 @@ func Listen(addr string, maxOpenConnections int) (listener net.Listener, err err return listener, nil } - -// Logging of RPC responses can sometimes result in very long log lines. -// See https://github.com/cometbft/cometbft/issues/654 -func truncateLoggedResponse(res interface{}) string { - var s string - b, err := json.Marshal(res) - if err != nil { - s = fmt.Sprintf("%s", res) - } else { - s = string(b) - } - if len(s) > maxWriteErrorResponseLen { - s = s[:maxWriteErrorResponseLen] + " ... (truncated)" - } - return s -} diff --git a/rpc/jsonrpc/server/http_uri_handler.go b/rpc/jsonrpc/server/http_uri_handler.go index d9dacf581cf..6381d91d70f 100644 --- a/rpc/jsonrpc/server/http_uri_handler.go +++ b/rpc/jsonrpc/server/http_uri_handler.go @@ -27,7 +27,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit return func(w http.ResponseWriter, r *http.Request) { res := types.RPCMethodNotFoundError(dummyID) if wErr := WriteRPCResponseHTTPError(w, http.StatusNotFound, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } } } @@ -45,7 +45,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit fmt.Errorf("error converting http params to arguments: %w", err), ) if wErr := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, res); wErr != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(res), "err", wErr) + logger.Error("failed to write response", "err", wErr) } return } @@ -58,7 +58,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit if err != nil { if err := WriteRPCResponseHTTPError(w, http.StatusInternalServerError, types.RPCInternalError(dummyID, err)); err != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(result), "err", err) + logger.Error("failed to write response", "err", err) return } return @@ -71,7 +71,7 @@ func makeHTTPHandler(rpcFunc *RPCFunc, logger log.Logger) func(http.ResponseWrit err = WriteRPCResponseHTTP(w, resp) } if err != nil { - logger.Error("failed to write response", "res", truncateLoggedResponse(result), "err", err) + logger.Error("failed to write response", "err", err) return } }