Merge #19509: Per-Peer Message Capture

bff7c66e67aa2f18ef70139338643656a54444fe Add documentation to contrib folder (Troy Giorshev)
381f77be858d7417209b6de0b7cd23cb7eb99261 Add Message Capture Test (Troy Giorshev)
e4f378a505922c0f544b4cfbfdb169e884e02be9 Add capture parser (Troy Giorshev)
4d1a582549bc982d55e24585b0ba06f92f21e9da Call CaptureMessage at appropriate locations (Troy Giorshev)
f2a77ff97bec09dd5fcc043d8659d8ec5dfb87c2 Add CaptureMessage (Troy Giorshev)
dbf779d5deb04f55c6e8493ce4e12ed4628638f3 Clean PushMessage and ProcessMessages (Troy Giorshev)

Pull request description:

  This PR introduces per-peer message capture into Bitcoin Core.  📓

  ## Purpose

  The purpose and scope of this feature is intentionally limited.  It answers a question anyone new to Bitcoin's P2P protocol has had: "Can I see what messages my node is sending and receiving?".

  ## Functionality

  When a new debug-only command line argument `capturemessages` is set, any message that the node receives or sends is captured.  The capture occurs in the MessageHandler thread.  When receiving a message, it is captured as soon as the MessageHandler thread takes the message off of the vProcessMsg queue.  When sending, the message is captured just before the message is pushed onto the vSendMsg queue.

  The message capture is as minimal as possible to reduce the performance impact on the node.  Messages are captured to a new `message_capture` folder in the datadir.  Each node has their own subfolder named with their IP address and port.  Inside, received and sent messages are captured into two binary files, msgs_recv.dat and msgs_sent.dat, like so:

  ```
  message_capture/203.0.113.7:56072/msgs_recv.dat
  message_capture/203.0.113.7:56072/msgs_sent.dat
  ```

  Because the messages are raw binary dumps, included in this PR is a Python parsing tool to convert the binary files into human-readable JSON.  This script has been placed on its own and out of the way in the new `contrib/message-capture` folder.  Its usage is simple and easily discovered by the autogenerated `-h` option.

  ## Future Maintenance

  I sympathize greatly with anyone who says "the best code is no code".

  The future maintenance of this feature will be minimal.  The logic to deserialize the payload of the p2p messages exists in our testing framework.  As long as our testing framework works, so will this tool.

  Additionally, I hope that the simplicity of this tool will mean that it gets used frequently, so that problems will be discovered and solved when they are small.

  ## FAQ

  "Why not just use Wireshark"

  Yes, Wireshark has the ability to filter and decode Bitcoin messages.  However, the purpose of the message capture added in this PR is to assist with debugging, primarily for new developers looking to improve their knowledge of the Bitcoin Protocol.  This drives the design in a different direction than Wireshark, in two different ways.  First, this tool must be convenient and simple to use.  Using an external tool, like Wireshark, requires setup and interpretation of the results.  To a new user who doesn't necessarily know what to expect, this is unnecessary difficulty.  This tool, on the other hand, "just works".  Turn on the command line flag, run your node, run the script, read the JSON.  Second, because this tool is being used for debugging, we want it to be as close to the true behavior of the node as possible.  A lot can happen in the SocketHandler thread that would be missed by Wireshark.

  Additionally, if we are to use Wireshark, we are at the mercy of whoever it maintaining the protocol in Wireshark, both as to it being accurate and recent.  As can be seen by the **many** previous attempts to include Bitcoin in Wireshark (google "bitcoin dissector") this is easier said than done.

  Lastly, I truly believe that this tool will be used significantly more by being included in the codebase.  It's just that much more discoverable.

ACKs for top commit:
  MarcoFalke:
    re-ACK bff7c66e67aa2f18ef70139338643656a54444fe only some minor changes: 👚
  jnewbery:
    utACK bff7c66e67aa2f18ef70139338643656a54444fe
  theStack:
    re-ACK bff7c66e67aa2f18ef70139338643656a54444fe

Tree-SHA512: e59e3160422269221f70f98720b47842775781c247c064071d546c24fa7a35a0e5534e8baa4b4591a750d7eb16de6b4ecf54cbee6d193b261f4f104e28c15f47

2 files changed, 239 insertions, 0 deletions

diff --git a/contrib/message-capture/message-capture-docs.md b/contrib/message-capture/message-capture-docs.md
new file mode 100644
index 0000000000..7301968461
--- /dev/null
+++ b/contrib/message-capture/message-capture-docs.md
@@ -0,0 +1,25 @@
+# Per-Peer Message Capture
+
+## Purpose
+
+This feature allows for message capture on a per-peer basis.  It answers the simple question: "Can I see what messages my node is sending and receiving?"
+
+## Usage and Functionality
+
+* Run `bitcoind` with the `-capturemessages` option.
+* Look in the `message_capture` folder in your datadir.
+  * Typically this will be `~/.bitcoin/message_capture`.
+  * See that there are many folders inside, one for each peer names with its IP address and port.
+  * Inside each peer's folder there are two `.dat` files: one is for received messages (`msgs_recv.dat`) and the other is for sent messages (`msgs_sent.dat`).
+* Run `contrib/message-capture/message-capture-parser.py` with the proper arguments.
+  * See the `-h` option for help.
+  * To see all messages, both sent and received, for all peers use:
+    ```
+    ./contrib/message-capture/message-capture-parser.py -o out.json \
+    ~/.bitcoin/message_capture/**/*.dat
+    ```
+  * Note:  The messages in the given `.dat` files will be interleaved in chronological order.  So, giving both received and sent `.dat` files (as above with `*.dat`) will result in all messages being interleaved in chronological order.
+  * If an output file is not provided (i.e. the `-o` option is not used), then the output prints to `stdout`.
+* View the resulting output.
+  * The output file is `JSON` formatted.
+  * Suggestion: use `jq` to view the output, with `jq . out.json`
diff --git a/contrib/message-capture/message-capture-parser.py b/contrib/message-capture/message-capture-parser.py
new file mode 100755
index 0000000000..9988478f1b
--- /dev/null
+++ b/contrib/message-capture/message-capture-parser.py
@@ -0,0 +1,214 @@
+#!/usr/bin/env python3
+# Copyright (c) 2020 The Bitcoin Core developers
+# Distributed under the MIT software license, see the accompanying
+# file COPYING or http://www.opensource.org/licenses/mit-license.php.
+"""Parse message capture binary files.  To be used in conjunction with -capturemessages."""
+
+import argparse
+import os
+import shutil
+import sys
+from io import BytesIO
+import json
+from pathlib import Path
+from typing import Any, List, Optional
+
+sys.path.append(os.path.join(os.path.dirname(__file__), '../../test/functional'))
+
+from test_framework.messages import ser_uint256     # noqa: E402
+from test_framework.p2p import MESSAGEMAP           # noqa: E402
+
+TIME_SIZE = 8
+LENGTH_SIZE = 4
+MSGTYPE_SIZE = 12
+
+# The test framework classes stores hashes as large ints in many cases.
+# These are variables of type uint256 in core.
+# There isn't a way to distinguish between a large int and a large int that is actually a blob of bytes.
+# As such, they are itemized here.
+# Any variables with these names that are of type int are actually uint256 variables.
+# (These can be easily found by looking for calls to deser_uint256, deser_uint256_vector, and uint256_from_str in messages.py)
+HASH_INTS = [
+    "blockhash",
+    "block_hash",
+    "hash",
+    "hashMerkleRoot",
+    "hashPrevBlock",
+    "hashstop",
+    "prev_header",
+    "sha256",
+    "stop_hash",
+]
+
+HASH_INT_VECTORS = [
+    "hashes",
+    "headers",
+    "vHave",
+    "vHash",
+]
+
+
+class ProgressBar:
+    def __init__(self, total: float):
+        self.total = total
+        self.running = 0
+
+    def set_progress(self, progress: float):
+        cols = shutil.get_terminal_size()[0]
+        if cols <= 12:
+            return
+        max_blocks = cols - 9
+        num_blocks = int(max_blocks * progress)
+        print('\r[ {}{} ] {:3.0f}%'
+              .format('#' * num_blocks,
+                      ' ' * (max_blocks - num_blocks),
+                      progress * 100),
+              end ='')
+
+    def update(self, more: float):
+        self.running += more
+        self.set_progress(self.running / self.total)
+
+
+def to_jsonable(obj: Any) -> Any:
+    if hasattr(obj, "__dict__"):
+        return obj.__dict__
+    elif hasattr(obj, "__slots__"):
+        ret = {}    # type: Any
+        for slot in obj.__slots__:
+            val = getattr(obj, slot, None)
+            if slot in HASH_INTS and isinstance(val, int):
+                ret[slot] = ser_uint256(val).hex()
+            elif slot in HASH_INT_VECTORS and isinstance(val[0], int):
+                ret[slot] = [ser_uint256(a).hex() for a in val]
+            else:
+                ret[slot] = to_jsonable(val)
+        return ret
+    elif isinstance(obj, list):
+        return [to_jsonable(a) for a in obj]
+    elif isinstance(obj, bytes):
+        return obj.hex()
+    else:
+        return obj
+
+
+def process_file(path: str, messages: List[Any], recv: bool, progress_bar: Optional[ProgressBar]) -> None:
+    with open(path, 'rb') as f_in:
+        if progress_bar:
+            bytes_read = 0
+
+        while True:
+            if progress_bar:
+                # Update progress bar
+                diff = f_in.tell() - bytes_read - 1
+                progress_bar.update(diff)
+                bytes_read = f_in.tell() - 1
+
+            # Read the Header
+            tmp_header_raw = f_in.read(TIME_SIZE + LENGTH_SIZE + MSGTYPE_SIZE)
+            if not tmp_header_raw:
+                break
+            tmp_header = BytesIO(tmp_header_raw)
+            time = int.from_bytes(tmp_header.read(TIME_SIZE), "little")      # type: int
+            msgtype = tmp_header.read(MSGTYPE_SIZE).split(b'\x00', 1)[0]     # type: bytes
+            length = int.from_bytes(tmp_header.read(LENGTH_SIZE), "little")  # type: int
+
+            # Start converting the message to a dictionary
+            msg_dict = {}
+            msg_dict["direction"] = "recv" if recv else "sent"
+            msg_dict["time"] = time
+            msg_dict["size"] = length   # "size" is less readable here, but more readable in the output
+
+            msg_ser = BytesIO(f_in.read(length))
+
+            # Determine message type
+            if msgtype not in MESSAGEMAP:
+                # Unrecognized message type
+                try:
+                    msgtype_tmp = msgtype.decode()
+                    if not msgtype_tmp.isprintable():
+                        raise UnicodeDecodeError
+                    msg_dict["msgtype"] = msgtype_tmp
+                except UnicodeDecodeError:
+                    msg_dict["msgtype"] = "UNREADABLE"
+                msg_dict["body"] = msg_ser.read().hex()
+                msg_dict["error"] = "Unrecognized message type."
+                messages.append(msg_dict)
+                print(f"WARNING - Unrecognized message type {msgtype} in {path}", file=sys.stderr)
+                continue
+
+            # Deserialize the message
+            msg = MESSAGEMAP[msgtype]()
+            msg_dict["msgtype"] = msgtype.decode()
+
+            try:
+                msg.deserialize(msg_ser)
+            except KeyboardInterrupt:
+                raise
+            except Exception:
+                # Unable to deserialize message body
+                msg_ser.seek(0, os.SEEK_SET)
+                msg_dict["body"] = msg_ser.read().hex()
+                msg_dict["error"] = "Unable to deserialize message."
+                messages.append(msg_dict)
+                print(f"WARNING - Unable to deserialize message in {path}", file=sys.stderr)
+                continue
+
+            # Convert body of message into a jsonable object
+            if length:
+                msg_dict["body"] = to_jsonable(msg)
+            messages.append(msg_dict)
+
+        if progress_bar:
+            # Update the progress bar to the end of the current file
+            # in case we exited the loop early
+            f_in.seek(0, os.SEEK_END)   # Go to end of file
+            diff = f_in.tell() - bytes_read - 1
+            progress_bar.update(diff)
+
+
+def main():
+    parser = argparse.ArgumentParser(
+        description=__doc__,
+        epilog="EXAMPLE \n\t{0} -o out.json <data-dir>/message_capture/**/*.dat".format(sys.argv[0]),
+        formatter_class=argparse.RawTextHelpFormatter)
+    parser.add_argument(
+        "capturepaths",
+        nargs='+',
+        help="binary message capture files to parse.")
+    parser.add_argument(
+        "-o", "--output",
+        help="output file.  If unset print to stdout")
+    parser.add_argument(
+        "-n", "--no-progress-bar",
+        action='store_true',
+        help="disable the progress bar.  Automatically set if the output is not a terminal")
+    args = parser.parse_args()
+    capturepaths = [Path.cwd() / Path(capturepath) for capturepath in args.capturepaths]
+    output = Path.cwd() / Path(args.output) if args.output else False
+    use_progress_bar = (not args.no_progress_bar) and sys.stdout.isatty()
+
+    messages = []   # type: List[Any]
+    if use_progress_bar:
+        total_size = sum(capture.stat().st_size for capture in capturepaths)
+        progress_bar = ProgressBar(total_size)
+    else:
+        progress_bar = None
+
+    for capture in capturepaths:
+        process_file(str(capture), messages, "recv" in capture.stem, progress_bar)
+
+    messages.sort(key=lambda msg: msg['time'])
+
+    if use_progress_bar:
+        progress_bar.set_progress(1)
+
+    jsonrep = json.dumps(messages)
+    if output:
+        with open(str(output), 'w+', encoding="utf8") as f_out:
+            f_out.write(jsonrep)
+    else:
+        print(jsonrep)
+
+if __name__ == "__main__":
+    main()