diff options
author | MarcoFalke <falke.marco@gmail.com> | 2019-02-05 17:40:11 -0500 |
---|---|---|
committer | MarcoFalke <falke.marco@gmail.com> | 2019-02-05 17:40:16 -0500 |
commit | 5029e94f855c73bad2e0ea6dc0378f33787ae131 (patch) | |
tree | 99544c3e6d4b5bb037fdc1e41cc79d75e81482e9 /doc | |
parent | baf125b31d0b4d37fc54123bc2563dac9ffde024 (diff) | |
parent | 13782b8ba84c5033a59a5234410a763393eafb8d (diff) |
Merge #14519: tests: add utility to easily profile node performance with perf
13782b8ba8 docs: add perf section to developer docs (James O'Beirne)
58180b5fd4 tests: add utility to easily profile node performance with perf (James O'Beirne)
Pull request description:
Adds a context manager to easily (and selectively) profile node performance during functional test execution using `perf`.
While writing some tests, I encountered some odd bitcoind slowness. I wrote up a utility (`TestNode.profile_with_perf`) that generates performance diagnostics for a node by running `perf` during the execution of a particular region of test code.
`perf` usage is detailed in the excellent (and sadly unmerged) https://github.com/bitcoin/bitcoin/pull/12649; all due props to @eklitzke.
### Example
```python
with node.profile_with_perf("large-msgs"):
for i in range(200):
node.p2p.send_message(some_large_msg)
node.p2p.sync_with_ping()
```
This generates a perf data file in the test node's datadir (`/tmp/testtxmpod0y/node0/node-0-TestName-large-msgs.perf.data`).
Running `perf report` generates nice output about where the node spent most of its time while running that part of the test:
```bash
$ perf report -i /tmp/testtxmpod0y/node0/node-0-TestName-large-msgs.perf.data --stdio \
| c++filt \
| less
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 135 of event 'cycles:pp'
# Event count (approx.): 1458205679493582
#
# Children Self Command Shared Object Symbol
# ........ ........ ............... ................... ........................................................................................................................................................................................................................................................................
#
70.14% 0.00% bitcoin-net bitcoind [.] CNode::ReceiveMsgBytes(char const*, unsigned int, bool&)
|
---CNode::ReceiveMsgBytes(char const*, unsigned int, bool&)
70.14% 0.00% bitcoin-net bitcoind [.] CNetMessage::readData(char const*, unsigned int)
|
---CNetMessage::readData(char const*, unsigned int)
CNode::ReceiveMsgBytes(char const*, unsigned int, bool&)
35.52% 0.00% bitcoin-net bitcoind [.] std::vector<char, zero_after_free_allocator<char> >::_M_fill_insert(__gnu_cxx::__normal_iterator<char*, std::vector<char, zero_after_free_allocator<char> > >, unsigned long, char const&)
|
---std::vector<char, zero_after_free_allocator<char> >::_M_fill_insert(__gnu_cxx::__normal_iterator<char*, std::vector<char, zero_after_free_allocator<char> > >, unsigned long, char const&)
CNetMessage::readData(char const*, unsigned int)
CNode::ReceiveMsgBytes(char const*, unsigned int, bool&)
...
```
Tree-SHA512: 9ac4ceaa88818d5eca00994e8e3c8ad42ae019550d6583972a0a4f7b0c4f61032e3d0c476b4ae58756bc5eb8f8015a19a7fc26c095bd588f31d49a37ed0c6b3e
Diffstat (limited to 'doc')
-rw-r--r-- | doc/developer-notes.md | 46 |
1 files changed, 46 insertions, 0 deletions
diff --git a/doc/developer-notes.md b/doc/developer-notes.md index ec29310ffe..1deb5d791a 100644 --- a/doc/developer-notes.md +++ b/doc/developer-notes.md @@ -17,6 +17,7 @@ Developer Notes - [DEBUG_LOCKORDER](#debug_lockorder) - [Valgrind suppressions file](#valgrind-suppressions-file) - [Compiling for test coverage](#compiling-for-test-coverage) + - [Performance profiling with perf](#performance-profiling-with-perf) - [Locking/mutex usage notes](#lockingmutex-usage-notes) - [Threads](#threads) - [Ignoring IDE/editor files](#ignoring-ideeditor-files) @@ -265,6 +266,51 @@ make cov # A coverage report will now be accessible at `./test_bitcoin.coverage/index.html`. ``` +### Performance profiling with perf + +Profiling is a good way to get a precise idea of where time is being spent in +code. One tool for doing profiling on Linux platforms is called +[`perf`](http://www.brendangregg.com/perf.html), and has been integrated into +the functional test framework. Perf can observe a running process and sample +(at some frequency) where its execution is. + +Perf installation is contingent on which kernel version you're running; see +[this StackExchange +thread](https://askubuntu.com/questions/50145/how-to-install-perf-monitoring-tool) +for specific instructions. + +Certain kernel parameters may need to be set for perf to be able to inspect the +running process' stack. + +```sh +$ sudo sysctl -w kernel.perf_event_paranoid=-1 +$ sudo sysctl -w kernel.kptr_restrict=0 +``` + +Make sure you [understand the security +trade-offs](https://lwn.net/Articles/420403/) of setting these kernel +parameters. + +To profile a running bitcoind process for 60 seconds, you could use an +invocation of `perf record` like this: + +```sh +$ perf record \ + -g --call-graph dwarf --per-thread -F 140 \ + -p `pgrep bitcoind` -- sleep 60 +``` + +You could then analyze the results by running + +```sh +perf report --stdio | c++filt | less +``` + +or using a graphical tool like [Hotspot](https://github.com/KDAB/hotspot). + +See the functional test documentation for how to invoke perf within tests. + + **Sanitizers** Bitcoin Core can be compiled with various "sanitizers" enabled, which add |