Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tests: add invalid P2P message tests #14522

Merged
merged 3 commits into from Nov 6, 2018

Conversation

Projects
None yet
8 participants
@jamesob
Copy link
Member

commented Oct 19, 2018

  • Adds p2p_invalid_messages.py: tests based on behavior for dealing with invalid and malformed P2P messages. Includes a test verifying that we can't DoS a node by spamming it with large invalid messages.
  • Adds TestNode.assert_memory_usage_stable: a context manager that allows us to ensure memory usage doesn't significantly increase on a node during some test.
  • Adds P2PConnection.send_raw_message: which allows us to construct and send messages with tweaked headers.

@fanquake fanquake added the Tests label Oct 19, 2018

@DrahtBot

This comment has been minimized.

Copy link
Contributor

commented Oct 20, 2018

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #14519 (tests: add utility to easily profile node performance with perf by jamesob)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

Show resolved Hide resolved test/functional/p2p_invalid_messages.py Outdated

@jamesob jamesob force-pushed the jamesob:2018-10-invalid-msgs-test branch Oct 23, 2018

@jamesob

This comment has been minimized.

Copy link
Member Author

commented Oct 23, 2018

Addressed @practicalswift nits.

@conscott

This comment has been minimized.

Copy link
Contributor

commented Oct 23, 2018

ACK dfbb8624c3747f4e9e76c9b9a051e973857a15c3

@jamesob jamesob force-pushed the jamesob:2018-10-invalid-msgs-test branch Oct 24, 2018

@jamesob

This comment has been minimized.

Copy link
Member Author

commented Oct 24, 2018

Pushed a small change to ensure get_mem_rss() failure is handled gracefully on Windows.

test/functional/test_framework/test_node.py Outdated
if perc_increase_memory_usage > perc_increase_allowed:
self._raise_assertion_error(
"Memory usage increased over threshold of {}% from {} to {} ({}%)".format(
perc_increase_allowed, before_memory_usage, after_memory_usage,

This comment has been minimized.

Copy link
@conscott

conscott Oct 25, 2018

Contributor

Since you are displaying as a % instead of decimal, I think you just need to multiply by 100

.format(perc_increase_allowed*100, 
        before_memory_usage, 
        after_memory_usage, 
        perc_increase_memory_usage*100)

Now it'll show something like
Memory usage increased over threshold of 3.0%....

Show resolved Hide resolved test/functional/test_framework/test_node.py Outdated
@laanwj

This comment has been minimized.

Copy link
Member

commented Oct 31, 2018

looks good to me, thanks for adding testing for this particular corner

@laanwj

This comment has been minimized.

Copy link
Member

commented Oct 31, 2018

checked: fails on FreeBSD:

user@vm13:~/bitcoin % test/functional/p2p_invalid_messages.py
2018-10-31T20:28:53.767000Z TestFramework (INFO): Initializing test directory /tmp/testw9nvke44
2018-10-31T20:28:54.336000Z TestFramework (ERROR): Unexpected exception caught during testing
Traceback (most recent call last):
  File "/usr/home/user/bitcoin/test/functional/test_framework/test_framework.py", line 172, in main
    self.run_test()
  File "test/functional/p2p_invalid_messages.py", line 69, in run_test
    with node.assert_memory_usage_stable(perc_increase_allowed=0.03):
  File "/usr/local/lib/python3.6/contextlib.py", line 81, in __enter__
    return next(self.gen)
  File "/usr/home/user/bitcoin/test/functional/test_framework/test_node.py", line 291, in assert_memory_usage_stable
    before_memory_usage = self.get_mem_rss()
  File "/usr/home/user/bitcoin/test/functional/test_framework/test_node.py", line 129, in get_mem_rss
    "ps h -o rss {}".format(self.process.pid), shell=True).strip())
ValueError: invalid literal for int() with base 10: b'RSS\n49084'
2018-10-31T20:28:54.405000Z TestFramework (INFO): Stopping nodes
2018-10-31T20:28:54.676000Z TestFramework (WARNING): Not cleaning up dir /tmp/testw9nvke44
2018-10-31T20:28:54.676000Z TestFramework (ERROR): Test failed. Test logging available at /tmp/testw9nvke44/test_framework.log
2018-10-31T20:28:54.677000Z TestFramework (ERROR): Hint: Call /usr/home/user/bitcoin/test/functional/combine_logs.py '/tmp/testw9nvke44' to consolidate all logs

@jamesob jamesob force-pushed the jamesob:2018-10-invalid-msgs-test branch Nov 1, 2018

@jamesob

This comment has been minimized.

Copy link
Member Author

commented Nov 1, 2018

Addressed feedback from @laanwj and @conscott; thanks for the looks.

jamesob added some commits Oct 19, 2018

tests: add utility to assert node memory usage hasn't increased
Adds a utility to get resident set size memory usage for a test
node and a context manager that allows assertions based upon
maximum memory use increase.
tests: add tests for invalid P2P messages
E.g., ensure that we can't DoS a node by sending it a bunch of large,
unrecognized messages.

@jamesob jamesob force-pushed the jamesob:2018-10-invalid-msgs-test branch to d20a9fa Nov 1, 2018

@conscott

This comment has been minimized.

Copy link
Contributor

commented Nov 6, 2018

Tested Re-ACK d20a9fa

@laanwj

This comment has been minimized.

Copy link
Member

commented Nov 6, 2018

utACK d20a9fa

@laanwj laanwj merged commit d20a9fa into bitcoin:master Nov 6, 2018

2 checks passed

continuous-integration/appveyor/pr AppVeyor build succeeded
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details

laanwj added a commit that referenced this pull request Nov 6, 2018

Merge #14522: tests: add invalid P2P message tests
d20a9fa tests: add tests for invalid P2P messages (James O'Beirne)
62f94d3 tests: add P2PConnection.send_raw_message (James O'Beirne)
5aa31f6 tests: add utility to assert node memory usage hasn't increased (James O'Beirne)

Pull request description:

  - Adds `p2p_invalid_messages.py`: tests based on behavior for dealing with invalid and malformed P2P messages. Includes a test verifying that we can't DoS a node by spamming it with large invalid messages.
  - Adds `TestNode.assert_memory_usage_stable`: a context manager that allows us to ensure memory usage doesn't significantly increase on a node during some test.
  - Adds `P2PConnection.send_raw_message`: which allows us to construct and send messages with tweaked headers.

Tree-SHA512: 720a4894c1e6d8f1551b2ae710e5b06c9e4f281524623957cb01599be9afea82671dc26d6152281de0acb87720f0c53b61e2b27d40434d30e525dd9e31fa671f

@jamesob jamesob deleted the jamesob:2018-10-invalid-msgs-test branch Nov 6, 2018

@MarcoFalke
Copy link
Member

left a comment

Concept ACK. Nice tests!

self.log.warning("Unable to detect memory usage (RSS) - skipping memory check.")
return

perc_increase_memory_usage = 1 - (float(before_memory_usage) / after_memory_usage)

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

You are taking after_memory_usage as reference, so a increase of n% in the memory usage will result always in perc_increase_memory_usage < n%.

For example you double the memory usage from 1GB to 2GB, this will give you 50%:

>>> 1 - (1 / 2)
0.5

Also you don't need the float conversion with /

try:
return int(subprocess.check_output(
"ps h -o rss {}".format(self.process.pid),
shell=True, stderr=subprocess.DEVNULL).strip())

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

Why is shell required here?

# isn't installed or doesn't work as expected, e.g. OpenBSD.
#
# We could later use something like `psutils` to work across platforms.
except Exception:

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

I'd prefer to explicitly catch subprocess.SubprocessError and ValueError, so that KeyError et al is not caught.

"""
if not (self.running and self.process):
self.log.warning("Couldn't get memory usage; process isn't running.")
return None

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

Couldn't this be an assert? How is this different from calling an RPC method when the node is not running?

self.log.info("Sending a message with incorrect size of {}".format(wrong_size))

# Unmodified message should submit okay.
node.p2p.send_and_ping(msg)

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

nit: Could assert debug log for unknown message type?

#
# Send a message with a too-long command name.
#
node.p2p.send_message(msg_nametoolong("foobar"))

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

Could assert debug log with the exact error?

except IOError:
pass

node.p2p.wait_for_disconnect(timeout=10)

This comment has been minimized.

Copy link
@MarcoFalke

MarcoFalke Nov 6, 2018

Member

Could assert debug log?

@MarcoFalke

This comment has been minimized.

Copy link
Member

commented Nov 7, 2018

Also, the test fails on macOS (with OSError: [Errno 41] Protocol wrong type for socket printed to stderr):

stdout:
2018-11-07T18:35:07.995000Z TestFramework (INFO): Initializing test directory /var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/test_runner_₿_🏃_20181107_182921/p2p_invalid_messages_46
2018-11-07T18:35:08.836000Z TestFramework.node0 (ERROR): Unable to get memory usage
Traceback (most recent call last):
  File "/Users/travis/build/MarcoFalke/btc_nightly/bitcoin/test/functional/test_framework/test_node.py", line 130, in get_mem_rss
    shell=True, stderr=subprocess.DEVNULL).strip())
ValueError: invalid literal for int() with base 10: b'RSS\n 71200'
2018-11-07T18:35:08.838000Z TestFramework (INFO): Sending a bunch of large, junk messages to test memory exhaustion. May take a bit...
2018-11-07T18:35:20.251000Z TestFramework (INFO): Waiting for node to drop junk messages.
2018-11-07T18:35:20.330000Z TestFramework.node0 (ERROR): Unable to get memory usage
Traceback (most recent call last):
  File "/Users/travis/build/MarcoFalke/btc_nightly/bitcoin/test/functional/test_framework/test_node.py", line 130, in get_mem_rss
    shell=True, stderr=subprocess.DEVNULL).strip())
ValueError: invalid literal for int() with base 10: b'RSS\n 80896'
2018-11-07T18:35:20.331000Z TestFramework.node0 (WARNING): Unable to detect memory usage (RSS) - skipping memory check.
2018-11-07T18:35:20.393000Z TestFramework.mininode (WARNING): Connection lost to 127.0.0.1:11368 due to [Errno 41] Protocol wrong type for socket
2018-11-07T18:35:20.495000Z TestFramework (INFO): Sending a message with incorrect size of 2
2018-11-07T18:35:20.659000Z TestFramework (INFO): Sending a message with incorrect size of 77
2018-11-07T18:35:20.836000Z TestFramework (INFO): Sending a message with incorrect size of 78
2018-11-07T18:35:21.010000Z TestFramework (INFO): Sending a message with incorrect size of 79
2018-11-07T18:35:21.442000Z TestFramework (INFO): Stopping nodes
2018-11-07T18:35:21.803000Z TestFramework (INFO): Cleaning up /var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/test_runner_₿_🏃_20181107_182921/p2p_invalid_messages_46 on exit
2018-11-07T18:35:21.803000Z TestFramework (INFO): Tests successful
stderr:
Fatal write error on socket transport
protocol: <test_framework.mininode.P2PDataStore object at 0x103d87e48>
transport: <_SelectorSocketTransport fd=10 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
  File "/usr/local/Cellar/python/3.6.5_1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/selector_events.py", line 761, in write
    n = self._sock.send(data)
OSError: [Errno 41] Protocol wrong type for socket

laanwj added a commit that referenced this pull request Nov 12, 2018

Merge #14693: test_node: get_mem_rss fixups
fa9ed38 test_node: get_mem_rss fixups (MarcoFalke)

Pull request description:

  Follow up to #14522:

  * Fix math (Memory usage increase relative to previous memory usage, not final memory usage)
  * remove `shell=True`
  * assert that the node is running
  * Make it work on BSD-like systems

Tree-SHA512: fc1b4f88173914b6cb6373655cffd781044a0c146339e3fa90da03b197faa20954567a77335965b857d29d27f32661698b6a0340f0c616f643b8c4510cd360c2
@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 21, 2019

I'm very late to this party, but my opinion is that testing memory usage is very useful, but should not be part of a functional test suite. Functional tests should test the functionality of the product, ie the outputs that are triggered by passing in various inputs. Memory usage is related to the implementation of the product. As the follow-on problems with this PR show, making rigid tests that depend on implementation details are brittle when run over different platforms.

I think that this code could be very useful when incorporated into a soak testing framework, but that it shouldn't be included in our functional test suite.

@jamesob

This comment has been minimized.

Copy link
Member Author

commented Feb 21, 2019

I think that this code could be very useful when incorporated into a soak testing framework, but that it shouldn't be included in our functional test suite.

Probably worth adding some guidance around what is and isn't appropriate for the functional test suite in one of the READMEs.

I'm generally inclined to agree with you, but I think having a comprehensive and easy-to-use framework for adding checks like this is very worthwhile. I'm also inclined to think that packaging such a framework within this repo is probably worthwhile, though there are certainly arguments against that. What do you think about introducing some kind of decorator to denote these sorts of checks on individual test methods and then introducing an --extended-like flag for use with the runner?

@jnewbery

This comment has been minimized.

Copy link
Member

commented Feb 21, 2019

Probably worth adding some guidance around what is and isn't appropriate for the functional test suite in one of the READMEs.

Good idea. I'll add that to my list (or I'm happy to review yours if you want to add it)

I think having a comprehensive and easy-to-use framework for adding checks like this is very worthwhile.

Also agree. The TestNode class is supposed to be reusable, eg for stress or soak testing.

I'm also inclined to think that packaging such a framework within this repo is probably worthwhile, though there are certainly arguments against that. What do you think about introducing some kind of decorator to denote these sorts of checks on individual test methods and then introducing an --extended-like flag for use with the runner?

I think including it in the repo is fine, but my preference would be to separate it somehow from the functional tests, for example having a soak testing framework that imports the TestNode() and then adds the methods it needs. I have a concern that /test/functional will continue to expand to be a test-all-the-things tool, even where other testing techniques are more appropriate.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.