qa: Add TestNode::assert_debug_log#14024
Conversation
fa8b2cf to
fa098df
Compare
fa098df to
fa0b5ca
Compare
| No more conflicts as of last run. |
|
Concept ACK |
|
Concept ACK asserting on the contents of the debug log, but I don't understand why a new RPC method is needed. Why not read the debug log file directly? |
|
@jnewbery I don't think it is possible to read from a file that is opened for writing on windows with python. |
I'm NACKish on this. I don't think we should be adding code to the product to work around a limitation in the test framework on a specific platform. |
fa0b5ca to
fa5a71a
Compare
|
Removed rpc |
|
Concept ACK. |
jnewbery
left a comment
There was a problem hiding this comment.
This is great. Tested ACK fa5a71a1498f6934e3d30499c1e17e01903f5659 (tested by asserting for a missing log).
I have a few nits inline.
test/functional/p2p_invalid_tx.py
Outdated
There was a problem hiding this comment.
Passing in an escaped string means that the printed assert when this fails looks a bit weird, but no big deal:
raise AssertionError(self._node_msg(msg))
AssertionError: [node 0] Expected message "8d7190866370e089916899a483a8df5ce7b495b04ffefc841ecd0d5779e9a0ca\ asdf\ from\ peer\=0\ was\ not\ accepted\:\ mandatory\-script\-verify\-flag\-failed\ \(Invalid\ OP_IF\ construction\)\ \(code\ 16\)" does not partially match log:
There was a problem hiding this comment.
Printing the log excerpt out in the assert is a bit confusing for anything that's parsing the test_framework log (since the timestamps at the start of the line will be interpreted as new log lines. Can I convince you to make the following change:
@@ -242,9 +242,10 @@ class TestNode():
with open(debug_log, encoding='utf-8') as dl:
dl.seek(prev_size)
log = dl.read()
+ print_log = " - " + "\n - ".join(log.splitlines())
for expected_msg in expected_msgs:
if re.search(expected_msg, log, flags=re.MULTILINE) is None:
- self._raise_assertion_error('Expected message "{}" does not partially match log:\n"{}"\n'.format(expected_msg, log))
+ self._raise_assertion_error('Expected message "{}" does not partially match log:\n\n{}\n\n'.format(expected_msg, print_log))
so that the printed log lines are prefixed with -.
I'd also be tempted to add a hint like:
self.log.error("Expected Log not raised. Check that bitcoind log format output has not changed!")
Changes to logging that cause tests to fail can be really annoying, so adding a hint is a friendly thing to do here.
|
ping @ryanofsky for review |
fa67fcb to
fad48e8
Compare
fad48e8 to
fa3e9f7
Compare
There was a problem hiding this comment.
utACK fad48e85d7a3f52d7df433e895689b19d117d157
Though I actually do think the previous code adding the tail log RPC (https://github.com/bitcoin/bitcoin/commits/fa0b5ca98e096e64a4bc94e69d1dd09e682f29fc) was nice because the tail command seems handy, and it would let us turn on log buffering in the future.
| with open(debug_log, encoding='utf-8') as dl: | ||
| dl.seek(prev_size) | ||
| log = dl.read() | ||
| print_log = " - " + "\n - ".join(log.splitlines()) |
There was a problem hiding this comment.
Might be more efficient to move this line before the _raise_assertion_error call in case the variable is unused.
There was a problem hiding this comment.
I think we don't optimize for performance in the test framework, so this should be fine.
| wait_until(self.is_node_stopped, timeout=timeout) | ||
|
|
||
| @contextlib.contextmanager | ||
| def assert_debug_log(self, expected_msgs): |
There was a problem hiding this comment.
I was surprised to see that this code actually works without adding RPCs before and after the yield to flush the log. But apparently there is a setbuf call in the logging code which disables buffering. Might be worth noting in a comment.
|
utACK fa3e9f7 |
fa3e9f7 qa: Add TestNode::assert_debug_log (MarcoFalke) Pull request description: Closes bitcoin#13006 Tree-SHA512: 8e2d2331039d70525a425aad65a4eaf9b83fb1f85a4260d69453176f04dbede6dd9b7bb4d5f089b46cf8f8c98571aa6ba7fac8fa6847bb3bdf6a6ad21a27b1a7
Github-Pull: bitcoin#14024 Rebased-From: fa3e9f7
Github-Pull: bitcoin#14024 Rebased-From: fa3e9f7
fa3e9f7 qa: Add TestNode::assert_debug_log (MarcoFalke) Pull request description: Closes bitcoin#13006 Tree-SHA512: 8e2d2331039d70525a425aad65a4eaf9b83fb1f85a4260d69453176f04dbede6dd9b7bb4d5f089b46cf8f8c98571aa6ba7fac8fa6847bb3bdf6a6ad21a27b1a7
Closes #13006