Skip to content

Commit

Permalink
Merge bitcoin#19509: Per-Peer Message Capture
Browse files Browse the repository at this point in the history
bff7c66 Add documentation to contrib folder (Troy Giorshev)
381f77b Add Message Capture Test (Troy Giorshev)
e4f378a Add capture parser (Troy Giorshev)
4d1a582 Call CaptureMessage at appropriate locations (Troy Giorshev)
f2a77ff Add CaptureMessage (Troy Giorshev)
dbf779d 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 bff7c66 only some minor changes: 👚
  jnewbery:
    utACK bff7c66
  theStack:
    re-ACK bff7c66

Tree-SHA512: e59e3160422269221f70f98720b47842775781c247c064071d546c24fa7a35a0e5534e8baa4b4591a750d7eb16de6b4ecf54cbee6d193b261f4f104e28c15f47
  • Loading branch information
MarcoFalke authored and vijaydasmp committed Dec 4, 2023
1 parent eb3f601 commit 4cad90b
Show file tree
Hide file tree
Showing 9 changed files with 371 additions and 15 deletions.
25 changes: 25 additions & 0 deletions 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`
214 changes: 214 additions & 0 deletions 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()
9 changes: 5 additions & 4 deletions src/init.cpp
Expand Up @@ -706,7 +706,7 @@ void SetupServerArgs(NodeContext& node)
argsman.AddArg("-stopatheight", strprintf("Stop running after reaching the given height in the main chain (default: %u)", DEFAULT_STOPATHEIGHT), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST);
argsman.AddArg("-watchquorums=<n>", strprintf("Watch and validate quorum communication (default: %u)", llmq::DEFAULT_WATCH_QUORUMS), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST);
argsman.AddArg("-addrmantest", "Allows to test address relay on localhost", ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST);

argsman.AddArg("-capturemessages", "Capture all P2P messages to disk", ArgsManager::ALLOW_BOOL | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST);
argsman.AddArg("-debug=<category>", "Output debugging information (default: -nodebug, supplying <category> is optional). "
"If <category> is not supplied or if <category> = 1, output all debugging information. <category> can be: " + LogInstance().LogCategoriesString() + ".", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
argsman.AddArg("-debugexclude=<category>", strprintf("Exclude debugging information for a category. Can be used in conjunction with -debug=1 to output debug logs for all categories except one or more specified categories."), ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST);
Expand Down Expand Up @@ -1238,16 +1238,17 @@ bool AppInitParameterInteraction(const ArgsManager& args)

// Trim requested connection counts, to fit into system limitations
// <int> in std::min<int>(...) to work around FreeBSD compilation issue described in #2695
nFD = RaiseFileDescriptorLimit(nMaxConnections + MIN_CORE_FILEDESCRIPTORS + MAX_ADDNODE_CONNECTIONS + nBind);
nFD = RaiseFileDescriptorLimit(nMaxConnections + MIN_CORE_FILEDESCRIPTORS + MAX_ADDNODE_CONNECTIONS + nBind + NUM_FDS_MESSAGE_CAPTURE);

#ifdef USE_POLL
int fd_max = nFD;
#else
int fd_max = FD_SETSIZE;
#endif
nMaxConnections = std::max(std::min<int>(nMaxConnections, fd_max - nBind - MIN_CORE_FILEDESCRIPTORS - MAX_ADDNODE_CONNECTIONS), 0);
nMaxConnections = std::max(std::min<int>(nMaxConnections, fd_max - nBind - MIN_CORE_FILEDESCRIPTORS - MAX_ADDNODE_CONNECTIONS - NUM_FDS_MESSAGE_CAPTURE), 0);
if (nFD < MIN_CORE_FILEDESCRIPTORS)
return InitError(_("Not enough file descriptors available."));
nMaxConnections = std::min(nFD - MIN_CORE_FILEDESCRIPTORS - MAX_ADDNODE_CONNECTIONS, nMaxConnections);
nMaxConnections = std::min(nFD - MIN_CORE_FILEDESCRIPTORS - MAX_ADDNODE_CONNECTIONS - NUM_FDS_MESSAGE_CAPTURE, nMaxConnections);

if (nMaxConnections < nUserMaxConnections)
InitWarning(strprintf(_("Reducing -maxconnections from %d to %d, because of system limitations."), nUserMaxConnections, nMaxConnections));
Expand Down
38 changes: 32 additions & 6 deletions src/net.cpp
Expand Up @@ -3946,6 +3946,9 @@ void CConnman::PushMessage(CNode* pnode, CSerializedNetMsg&& msg)
{
size_t nMessageSize = msg.data.size();
LogPrint(BCLog::NET, "sending %s (%d bytes) peer=%d\n", SanitizeString(msg.command), nMessageSize, pnode->GetId());
if (gArgs.GetBoolArg("-capturemessages", false)) {
CaptureMessage(pnode->addr, msg.m_type, msg.data, /* incoming */ false);
}

// make sure we use the appropriate network transport format
std::vector<unsigned char> serializedHeader;
Expand All @@ -3964,11 +3967,9 @@ void CConnman::PushMessage(CNode* pnode, CSerializedNetMsg&& msg)
pnode->mapSendBytesPerMsgCmd[msg.command] += nTotalSize;
pnode->nSendSize += nTotalSize;

if (pnode->nSendSize > nSendBufferMaxSize)
pnode->fPauseSend = true;
if (pnode->nSendSize > nSendBufferMaxSize) pnode->fPauseSend = true;
pnode->vSendMsg.push_back(std::move(serializedHeader));
if (nMessageSize)
pnode->vSendMsg.push_back(std::move(msg.data));
if (nMessageSize) pnode->vSendMsg.push_back(std::move(msg.data));
pnode->nSendMsgSize = pnode->vSendMsg.size();

{
Expand All @@ -3986,8 +3987,7 @@ void CConnman::PushMessage(CNode* pnode, CSerializedNetMsg&& msg)
if (!hasPendingData && wakeupSelectNeeded)
WakeSelect();
}
if (nBytesSent)
RecordBytesSent(nBytesSent);
if (nBytesSent) RecordBytesSent(nBytesSent);
}

bool CConnman::ForNode(const CService& addr, std::function<bool(const CNode* pnode)> cond, std::function<bool(CNode* pnode)> func)
Expand Down Expand Up @@ -4157,4 +4157,30 @@ void CConnman::UnregisterEvents(CNode *pnode)
epollfd, EPOLL_CTL_DEL, pnode->hSocket, NetworkErrorString(WSAGetLastError()));
}
#endif
void CaptureMessage(const CAddress& addr, const std::string& msg_type, const Span<const unsigned char>& data, bool is_incoming)
{
// Note: This function captures the message at the time of processing,
// not at socket receive/send time.
// This ensures that the messages are always in order from an application
// layer (processing) perspective.
auto now = GetTime<std::chrono::microseconds>();

// Windows folder names can not include a colon
std::string clean_addr = addr.ToString();
std::replace(clean_addr.begin(), clean_addr.end(), ':', '_');

fs::path base_path = GetDataDir() / "message_capture" / clean_addr;
fs::create_directories(base_path);

fs::path path = base_path / (is_incoming ? "msgs_recv.dat" : "msgs_sent.dat");
CAutoFile f(fsbridge::fopen(path, "ab"), SER_DISK, CLIENT_VERSION);

ser_writedata64(f, now.count());
f.write(msg_type.data(), msg_type.length());
for (auto i = msg_type.length(); i < CMessageHeader::COMMAND_SIZE; ++i) {
f << '\0';
}
uint32_t size = data.size();
ser_writedata32(f, size);
f.write((const char*)data.data(), data.size());
}
6 changes: 6 additions & 0 deletions src/net.h
Expand Up @@ -22,6 +22,7 @@
#include <protocol.h>
#include <random.h>
#include <saltedhasher.h>
#include <span.h>
#include <streams.h>
#include <sync.h>
#include <threadinterrupt.h>
Expand Down Expand Up @@ -91,6 +92,8 @@ static constexpr uint64_t DEFAULT_MAX_UPLOAD_TARGET = 0;
static const bool DEFAULT_BLOCKSONLY = false;
/** -peertimeout default */
static const int64_t DEFAULT_PEER_CONNECT_TIMEOUT = 60;
/** Number of file descriptors required for message capture **/
static const int NUM_FDS_MESSAGE_CAPTURE = 1;

static const bool DEFAULT_FORCEDNSSEED = false;
static const size_t DEFAULT_MAXRECEIVEBUFFER = 5 * 1000;
Expand Down Expand Up @@ -1470,4 +1473,7 @@ inline std::chrono::microseconds PoissonNextSend(std::chrono::microseconds now,
return std::chrono::microseconds{PoissonNextSend(now.count(), average_interval.count())};
}

/** Dump binary message to file, with timestamp */
void CaptureMessage(const CAddress& addr, const std::string& msg_type, const Span<const unsigned char>& data, bool is_incoming);

#endif // BITCOIN_NET_H
11 changes: 7 additions & 4 deletions src/net_processing.cpp
Expand Up @@ -4429,14 +4429,12 @@ bool PeerManagerImpl::ProcessMessages(CNode* pfrom, std::atomic<bool>& interrupt
}

// Don't bother if send buffer is too full to respond anyway
if (pfrom->fPauseSend)
return false;
if (pfrom->fPauseSend) return false;

std::list<CNetMessage> msgs;
{
LOCK(pfrom->cs_vProcessMsg);
if (pfrom->vProcessMsg.empty())
return false;
if (pfrom->vProcessMsg.empty()) return false;
// Just take one message
msgs.splice(msgs.begin(), pfrom->vProcessMsg, pfrom->vProcessMsg.begin());
pfrom->nProcessQueueSize -= msgs.front().m_raw_message_size;
Expand All @@ -4446,6 +4444,11 @@ bool PeerManagerImpl::ProcessMessages(CNode* pfrom, std::atomic<bool>& interrupt
CNetMessage& msg(msgs.front());

msg.SetVersion(pfrom->GetRecvVersion());
if (gArgs.GetBoolArg("-capturemessages", false)) {
CaptureMessage(pfrom->addr, msg.m_command, MakeUCharSpan(msg.m_recv), /* incoming */ true);
}

msg.SetVersion(pfrom->GetCommonVersion());
const std::string& msg_type = msg.m_command;

// Message size
Expand Down

0 comments on commit 4cad90b

Please sign in to comment.