In Python the meaning of args or argsn is that argsn is fully ignored when args is a list with at least one element. However, the RPC server accepts mixed positional and named args in the same RPC.
Fix the debug log by always printing both. Also, add a new _json_dumps helper to avoid bloated code.
Can be tested via --tracerpc on a call that uses named args mixed with positional args.
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.
For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/31955.
See the guideline for information on the review process.
| Type | Reviewers |
|---|---|
| ACK | i-am-yuvi, rkrux, musaHaruna, ryanofsky |
If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.
Approach ACK
Correct me if I misunderstood:
In Python, when a function accepts both positional(*args) and keyword(**argsn) arguments, for which args is handled as a tuple and argsn as dictionary where Python doesn’t merge them automatically into a combined list.
The RPC server accepts a single call which includes both positional as well as keyword. That means if a caller provides both, the server expects to receive both types together. In that case, the original code(logging part) ignores the argsn when there were args present - hiding the fact that both kinds were sent. This leads to debugging ambiguity because the debug log might not show the complete set of parameters the RPC server receives.
104@@ -105,14 +105,19 @@ def _request(self, method, path, postdata):
105 self.__conn.request(method, path, postdata, headers)
106 return self._get_response()
107
108+ def _json_dumps(self, obj):
Tested ACK fac1dd9dffba1033245c283bc0468e801c14e910
I could see the difference:
-1-> getblockcount {} - without changes
-1-> getblockcount [] {} - with changes
In Python the meaning of args or argsn is that argsn is fully ignored when args is a list with at least one element.
The following code prints argsn fine in this scenario.
0def f(name, *args, **argsn):
1 print(name)
2 print(args)
3 print(argsn)
4
5f("titlehere", [1,2], a=10, b=30)
0titlehere
1([1, 2],)
2{'a': 10, 'b': 30}
I don’t think it’s a generic Python thing. I believe argsn not being logged was due to the following older line, if args is there (not empty list notably), argsn is ignored in the log.
0json.dumps(args or argsn, default=serialization_fallback, ensure_ascii=self.ensure_ascii),
args or argsn in your print: print(args or argsn), then argsn is omitted from the print if the args list has at least one element. This should be true in general for all versions of Python that are supported. The changes in this pull request are fixing the problem, as explained in the pull request description.
Yes, correct, I agree. The PR description statement I highlighted in my comment led me to believe that argsn is ignored always in any function if args is a list with at least 1 element, which I found to be confusing to read and hence verified it with an example. The issue as I understand is with the usage of args or argsn as the first argument to the json.dumps function, which this PR correctly fixes.
The only concern is with the first statement in the PR description, which is too generic.
In Python the meaning of args or argsn is that argsn is fully ignored when args is a list with at least one element.
There may be a formatting issue. For me the pull description says (with code blocks):
In Python the meaning of
args or argsnis thatargsnis fully ignored whenargsis a list with at least one element.
However, for you it seems to say:
In Python the meaning of args or argsn is that argsn is fully ignored when args is a list with at least one element.
Obviously, the two have different meaning (and the second doesn’t really make sense). I am not sure how to fix this. What client are you using to access the description?
201@@ -197,7 +202,7 @@ def _get_response(self):
202 response = json.loads(responsedata, parse_float=decimal.Decimal)
203 elapsed = time.time() - req_start_time
204 if "error" in response and response["error"] is None:
re: #31955 (review)
Older code and doesn’t need to be fixed in this PR but this line seems buggy to me, Idk how these 2 conditions can be true at the same time.
The code and behavior here could probably be improved, but this is just trying to reduce noise in log output and avoid showing "error": null in JSONRPC v1 responses when the error field is present and null.
201@@ -197,7 +202,7 @@ def _get_response(self):
202 response = json.loads(responsedata, parse_float=decimal.Decimal)
203 elapsed = time.time() - req_start_time
204 if "error" in response and response["error"] is None:
205- log.debug("<-%s- [%.6f] %s" % (response["id"], elapsed, json.dumps(response["result"], default=serialization_fallback, ensure_ascii=self.ensure_ascii)))
206+ log.debug("<-%s- [%.6f] %s" % (response["id"], elapsed, self._json_dumps(response["result"])))
207 else:
208 log.debug("<-- [%.6f] %s" % (elapsed, responsedata))
The RPC request seems to be logged with the AuthServiceProxy.__id_count but the corresponding non erroneous response doesn’t seem to be. @maflcko Do you know the reason for it and should we improve it later?
0-30-> getreceivedbyaddress
1<-- [0.000553] {"jsonrpc":"2.0"...
s after the elapsed time but something maybe for another PR.
re: #31955 (review)
The RPC request seems to be logged with the
AuthServiceProxy.__id_countbut the corresponding non erroneous response doesn’t seem to be. @maflcko Do you know the reason for it and should we improve it later?
It looks like response["id"] is explicitly logged in the v1 case and responsedata which includes the "id" field is logged in the v2/error case, so the id should be present in both cases. Probably output could be improved and make more consistent though.
tACK fac1dd9dffba1033245c283bc0468e801c14e910
I ran the wallet_timelock test by passing both positional and named arguments in the first listunspent RPC.
0coin_before = node.listunspent(1, maxconf=1, include_unsafe=True)
I can see both kinds of arguments being logged.
0-28-> listunspent [1] {"maxconf": 1, "include_unsafe": true}
1<-- [0.000553] {"jsonrpc":"2.0","result":[{"txid":"c0bbea0efd29a1c72e264efeb4eb53096741ebf3d309cabcec343b96e21a59ed","vout":0,"address":"bcrt1q8npfane52r5fn45yp8murqrhce7vdff24a25mf","label":"timelock⌛🔓"...
Mentioned few points that can be addressed in other PRs.
Tested ACK fac1dd9
with change: ``DEBUG:BitcoinRPC:-1-> getblockhash [] {} { “jsonrpc”: “2.0”, “method”: “getblockhash”, “params”: {}, “id”: 1 }
without change:
DEBUG:RPC Test:Testing Positional Arguments Only
DEBUG:BitcoinRPC:-1-> getblockhash {}
{
"jsonrpc": "2.0",
"method": "getblockhash",
"params": {},
"id": 1
}
Also the new helper function helped makes the json.dumps reusable, and avoid repetition, it made the funtionality easier to graps