chore(rpcclient): show body in errors upon non-OK HTTP codes (fixes #2422)

[grepsuzette]

When an RPC server responds with a 500 Internal Error, it sends a jsonrpc with the error that happened (as explained in #2422 and #2236).

Note: Querying a fake address triggers a 500 error: gnokey query auth/accounts/g1fjh9y7ausp27dqsdq0qrcsnmgvwm6829v20000, reviewers can use that to test on their own.

Even though the rpc server communicates some error, gnokey gives:

--= Error =--
Data: unable to call RPC method abci_query, invalid status code received, 500 
Msg Traces: 
    0  /me/gno/tm2/pkg/crypto/keys/client/query.go:94 - querying
--= /Error =--

This PR adds the body of the response sent by the server to that error.

--= Error =--
Data: unable to call RPC method abci_query, invalid status code received, 500. Response body: "\n
{\"rpcversion\":2,\"id\":\"\",\"error\":{\"code\":-32603,\"message\":\"internal error\"
,\"data\":\"assignment to entry in nil map\"}}"
Msg Traces:
    0  /gno/tm2/pkg/crypto/keys/client/query.go:94 - querying
--= /Error =--

It's quite ugly, I'll give you that.
But it has the advantage of simplicity.

Fixes #2422, addresses #2236

[codecov]

Codecov Report

Attention: Patch coverage is 0% with 5 lines in your changes missing coverage. Please review.

Project coverage is 54.94%. Comparing base (fadf622) to head (76974d3).

Files	Patch %	Lines
tm2/pkg/bft/rpc/lib/client/http/client.go	0.00%	4 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #2501      +/-   ##
==========================================
- Coverage   55.01%   54.94%   -0.08%     
==========================================
  Files         595      587       -8     
  Lines       79662    79308     -354     
==========================================
- Hits        43830    43578     -252     
+ Misses      32514    32465      -49     
+ Partials     3318     3265      -53     

Flag	Coverage Δ
contribs/gnodev	26.00% <ø> (ø)
contribs/gnofaucet	14.46% <ø> (ø)
contribs/gnokeykc	0.00% <ø> (ø)
contribs/gnomd	0.00% <ø> (ø)
gno.land	64.24% <ø> (ø)
tm2	54.38% <0.00%> (+0.01%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[thehowl]

Suggested change

	"invalid status code received, %d. Response body: %q",
	"invalid status code received, %d. Response body:\n%s",

what do you think?

maybe also strings.ReplaceAll(string(responseBody), "\n", "\n\t").

[grepsuzette]

We actually lost the display of server errors for non 2xx codes in #350.
Had another branch where tried to decode the jsonrpc ABCIError if possible in #2631. It was embarrasingly long so prepared this short PR instead, hence %s or %q.

%s kind of tries to format things, with \n being shown on many lines. But if it's about showing nice things, #2631 was nicer as it decoded the ABCIError. If it's about showing raw stuffs from the server in case of a 500 (a rare occurence), I think %q does the job. In the end it's mostly the same, there is perhaps just less ambiguity with %q, everything being packed together in an unmistakably compact way (with ugly \" quotes).

What is best for users? I think seeing the ABCIError from the server is the most important thing (it's valuable as it saves time). 5xx is supposed to be pretty rare.

If you're comfortable with %s we can use %s. I perhaps lack the notion of how frequently those messages will be shown.

[thehowl]

Hey. Sorry for the slow turnaround here. I needed to double-check some information, and I lost track of this discussion.

The thing is, most often the users of the rpcclient understand how to handle errors and print useful information. An example is the keys client itself, which will print the logs I'm familiar with and I'm pretty sure you are too:

gno/tm2/pkg/crypto/keys/client/maketx.go

Lines 206 to 216 in 2e56ecf

	bres, err := SignAndBroadcastHandler(cfg, nameOrBech32, tx, pass)
	if err != nil {
	return errors.Wrap(err, "broadcast tx")
	}
	if bres.CheckTx.IsErr() {
	return errors.Wrap(bres.CheckTx.Error, "check transaction failed: log:%s", bres.CheckTx.Log)
	}
	if bres.DeliverTx.IsErr() {
	io.Println("TX HASH: ", base64.StdEncoding.EncodeToString(bres.Hash))
	return errors.Wrap(bres.DeliverTx.Error, "deliver transaction failed: log:%s", bres.DeliverTx.Log)
	}

So, it seems that for the RPC server to return a non-200, and thus have an error here, there needs to be a specific condition. My research has turned up this specific code, which seems to line up with the error you're seeing:

gno/tm2/pkg/bft/rpc/lib/server/http_server.go

Lines 142 to 175 in 2e56ecf

	func RecoverAndLogHandler(handler http.Handler, logger *slog.Logger) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
	// Wrap the ResponseWriter to remember the status
	rww := &ResponseWriterWrapper{-1, w}
	begin := time.Now()
	rww.Header().Set("X-Server-Time", fmt.Sprintf("%v", begin.Unix()))
	defer func() {
	// Send a 500 error if a panic happens during a handler.
	// Without this, Chrome & Firefox were retrying aborted ajax requests,
	// at least to my localhost.
	if e := recover(); e != nil {
	switch e := e.(type) {
	case types.RPCResponse:
	WriteRPCResponseHTTP(rww, e)
	case error:
	logger.Error(
	"Panic in RPC HTTP handler", "err", e, "stack",
	string(debug.Stack()),
	)
	WriteRPCResponseHTTPError(rww, http.StatusInternalServerError,
	types.RPCInternalError(types.JSONRPCStringID(""), e))
	default: // handle string type and any other types
	logger.Error(
	"Panic in RPC HTTP handler", "err", e, "stack",
	string(debug.Stack()),
	)
	WriteRPCResponseHTTPError(rww, http.StatusInternalServerError,
	types.RPCInternalError(types.JSONRPCStringID(""), fmt.Errorf("%v", e)))
	}
	}

Now, this kind of error will happen quite exceptionally, as in general the panic must escape the handlers and only be caught into this point.

So, I think we can have a simple handling for any 500 return here, where we simply try to parse the value of .error.data (can be in a simple struct{ Error struct { Data string json:"data"}json:"error" }, and if that unmarshaling succeeds add it to the error message.

Other cases where there are errors in the RPC handler generate an RPC response with 200 status code, and so the client won't return an error (although it will be contained within the resp).

[grepsuzette]

So, I think we can have a simple handling for any 500 return here, where we simply try to parse the value of .error.data (can be in a simple struct{ Error struct { Data string json:"data"}json:"error" }, and if that unmarshaling succeeds add it to the error message.

Is this understanding correct:

• Remove the possibility of the rpc server to send any 500 code altogether (following the idea you provided),
• discard current fix.

I can handle it, but I'll need you to suggest a concise Git commit title for this as a confirmation ;)

[thehowl]

Remove the possibility of the rpc server to send any 500 code altogether (following the idea you provided),

Mhh. Could be an idea. Don't know.

I guess one counter-argument is that the server sends this response in the recover, so it may send it even in the case of a batch JSON-RPC request.

So I'm more inclined towards updating this existing PR and handling the error, extracting .error.data and putting it in the error message.

@kristovatlas, please take a look on whether it makes sense for us to avoid printing information for internal errors caught in the recover like this. I think they're useful for local development, but likely needs to be disabled in prod + have a way to catch these with something like sentry (or glitchtip, its open-source continuation), in a production deployment.