Skip to content
This repository was archived by the owner on Oct 28, 2021. It is now read-only.

Minor network logging updates #5574

Merged
halfalicious merged 3 commits into from
Apr 26, 2019
Merged

Minor network logging updates #5574

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
5eadfb7
Log egress/ingress via boost log attribute
halfalicious Apr 23, 2019
2a6f7dd
Log expected/actual abridged genesis hashes
halfalicious Apr 23, 2019
2d27205
Reuse RLPxHandshake ctor
halfalicious Apr 25, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Next Next commit
Log egress/ingress via boost log attribute
  • Loading branch information
@halfalicious
halfalicious committed Apr 23, 2019
commit 5eadfb76a29a66cdcc144b96195b53f32662cce1
100 changes: 57 additions & 43 deletions libp2p/RLPxHandshake.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,38 @@ constexpr size_t c_ackCipherSizeBytes = 210;
constexpr size_t c_authCipherSizeBytes = 307;
}

RLPXHandshake::RLPXHandshake(Host* _host, std::shared_ptr<RLPXSocket> const& _socket)
: m_host(_host),
m_originated(false),
m_socket(_socket),
m_idleTimer(m_socket->ref().get_io_service())
{
m_logger.add_attribute(
"Context", boost::log::attributes::constant<std::string>(connectionDirectionString()));
m_errorLogger.add_attribute(
"Context", boost::log::attributes::constant<std::string>(connectionDirectionString()));
crypto::Nonce::get().ref().copyTo(m_nonce.ref());
}

RLPXHandshake::RLPXHandshake(
Host* _host, std::shared_ptr<RLPXSocket> const& _socket, NodeID _remote)
: m_host(_host),
m_remote(_remote),
m_originated(true),
m_socket(_socket),
m_idleTimer(m_socket->ref().get_io_service())
{
m_logger.add_attribute(
"Context", boost::log::attributes::constant<std::string>(connectionDirectionString()));
m_errorLogger.add_attribute(
"Context", boost::log::attributes::constant<std::string>(connectionDirectionString()));
crypto::Nonce::get().ref().copyTo(m_nonce.ref());
}


void RLPXHandshake::writeAuth()
{
LOG(m_logger) << connectionDirectionString() << "auth to " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "auth to " << m_remote << "@" << m_socket->remoteEndpoint();
m_auth.resize(Signature::size + h256::size + Public::size + h256::size + 1);
bytesRef sig(&m_auth[0], Signature::size);
bytesRef hepubk(&m_auth[Signature::size], h256::size);
Expand All @@ -49,8 +77,7 @@ void RLPXHandshake::writeAuth()

void RLPXHandshake::writeAck()
{
LOG(m_logger) << connectionDirectionString() << "ack to " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "ack to " << m_remote << "@" << m_socket->remoteEndpoint();
m_ack.resize(Public::size + h256::size + 1);
bytesRef epubk(&m_ack[0], Public::size);
bytesRef nonce(&m_ack[Public::size], h256::size);
Expand All @@ -68,8 +95,7 @@ void RLPXHandshake::writeAck()

void RLPXHandshake::writeAckEIP8()
{
LOG(m_logger) << connectionDirectionString() << "EIP-8 ack to " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "EIP-8 ack to " << m_remote << "@" << m_socket->remoteEndpoint();
RLPStream rlp;
rlp.appendList(3)
<< m_ecdheLocal.pub()
Expand Down Expand Up @@ -103,8 +129,7 @@ void RLPXHandshake::setAuthValues(Signature const& _sig, Public const& _remotePu

void RLPXHandshake::readAuth()
{
LOG(m_logger) << connectionDirectionString() << "auth from " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "auth from " << m_remote << "@" << m_socket->remoteEndpoint();
m_authCipher.resize(c_authCipherSizeBytes);
auto self(shared_from_this());
ba::async_read(m_socket->ref(), ba::buffer(m_authCipher, c_authCipherSizeBytes),
Expand All @@ -129,8 +154,8 @@ void RLPXHandshake::readAuthEIP8()
{
assert(m_authCipher.size() == c_authCipherSizeBytes);
uint16_t size(m_authCipher[0]<<8 | m_authCipher[1]);
LOG(m_logger) << connectionDirectionString() << size << " bytes EIP-8 auth from " << m_remote
<< "@" << m_socket->remoteEndpoint();
LOG(m_logger) << size << " bytes EIP-8 auth from " << m_remote << "@"
<< m_socket->remoteEndpoint();
m_authCipher.resize((size_t)size + 2);
auto rest = ba::buffer(ba::buffer(m_authCipher) + c_authCipherSizeBytes);
auto self(shared_from_this());
Expand All @@ -153,8 +178,8 @@ void RLPXHandshake::readAuthEIP8()
}
else
{
LOG(m_logger) << connectionDirectionString() << "auth decrypt failed for " << m_remote
<< "@" << m_socket->remoteEndpoint();
LOG(m_logger) << "auth decrypt failed for " << m_remote << "@"
<< m_socket->remoteEndpoint();
m_nextState = Error;
transition();
}
Expand All @@ -163,8 +188,7 @@ void RLPXHandshake::readAuthEIP8()

void RLPXHandshake::readAck()
{
LOG(m_logger) << connectionDirectionString() << "ack from " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "ack from " << m_remote << "@" << m_socket->remoteEndpoint();
m_ackCipher.resize(c_ackCipherSizeBytes);
auto self(shared_from_this());
ba::async_read(m_socket->ref(), ba::buffer(m_ackCipher, c_ackCipherSizeBytes),
Expand All @@ -187,8 +211,8 @@ void RLPXHandshake::readAckEIP8()
{
assert(m_ackCipher.size() == c_ackCipherSizeBytes);
uint16_t size(m_ackCipher[0]<<8 | m_ackCipher[1]);
LOG(m_logger) << connectionDirectionString() << size << " bytes EIP-8 ack from " << m_remote
<< "@" << m_socket->remoteEndpoint();
LOG(m_logger) << size << " bytes EIP-8 ack from " << m_remote << "@"
<< m_socket->remoteEndpoint();
m_ackCipher.resize((size_t)size + 2);
auto rest = ba::buffer(ba::buffer(m_ackCipher) + c_ackCipherSizeBytes);
auto self(shared_from_this());
Expand All @@ -207,8 +231,8 @@ void RLPXHandshake::readAckEIP8()
}
else
{
LOG(m_logger) << connectionDirectionString() << "ack decrypt failed for " << m_remote
<< "@" << m_socket->remoteEndpoint();
LOG(m_logger) << "ack decrypt failed for " << m_remote << "@"
<< m_socket->remoteEndpoint();
m_nextState = Error;
transition();
}
Expand All @@ -226,11 +250,10 @@ void RLPXHandshake::cancel()
void RLPXHandshake::error()
{
if (remoteSocketConnected())
LOG(m_logger) << connectionDirectionString() << "Disconnecting " << m_remote << "@"
<< m_socket->remoteEndpoint() << " (Handshake Failed)";
LOG(m_logger) << "Disconnecting " << m_remote << "@" << m_socket->remoteEndpoint()
<< " (Handshake Failed)";
else
LOG(m_logger) << connectionDirectionString()
<< "Handshake Failed (Connection reset by peer " << m_remote << ")";
LOG(m_logger) << "Handshake Failed (Connection reset by peer " << m_remote << ")";

cancel();
}
Expand All @@ -243,7 +266,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
if (_ech || m_nextState == Error || m_cancel)
{
stringstream errorStream;
errorStream << connectionDirectionString() << "Handshake Failed ";
errorStream << "Handshake Failed ";
if (_ech)
errorStream << "(I/O Error: " << _ech.message() << ") ";
errorStream << "(" << m_remote;
Expand All @@ -262,7 +285,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
if (!_ec)
{
std::stringstream errorStream;
errorStream << connectionDirectionString() << "Disconnecting " << m_remote;
errorStream << "Disconnecting " << m_remote;
if (remoteSocketConnected())
errorStream << "@" << m_socket->remoteEndpoint();
errorStream << " (Handshake Timeout)";
Expand Down Expand Up @@ -298,8 +321,8 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
else if (m_nextState == WriteHello)
{
// Send the p2p capability Hello frame
LOG(m_logger) << connectionDirectionString() << packetTypeToString(HelloPacket) << " to "
<< m_remote << "@" << m_socket->remoteEndpoint();
LOG(m_logger) << packetTypeToString(HelloPacket) << " to " << m_remote << "@"
<< m_socket->remoteEndpoint();

m_nextState = ReadHello;

Expand All @@ -325,8 +348,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
}
else if (m_nextState == ReadHello)
{
LOG(m_logger) << connectionDirectionString() << "Frame header from " << m_remote << "@"
<< m_socket->remoteEndpoint();
LOG(m_logger) << "Frame header from " << m_remote << "@" << m_socket->remoteEndpoint();

// Authenticate and decrypt initial hello frame with initial RLPXFrameCoder
// and request m_host to start session.
Expand All @@ -345,7 +367,6 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
if (!m_io)
{
LOG(m_errorLogger)
<< connectionDirectionString()
<< "Internal error in handshake: RLPXFrameCoder disappeared ("
<< m_remote << ")";
m_nextState = Error;
Expand All @@ -362,8 +383,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
return;
}

LOG(m_logger) << connectionDirectionString()
<< "Successfully decrypted frame header from " << m_remote << "@"
LOG(m_logger) << "Successfully decrypted frame header from " << m_remote << "@"
<< m_socket->remoteEndpoint() << ". Validating contents...";

/// check frame size
Expand All @@ -375,7 +395,6 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
{
// all future frames: 16777216
LOG(m_logger)
<< connectionDirectionString()
<< "Frame is too large! Expected size: " << expectedFrameSizeBytes
<< " bytes, actual size: " << frameSize << " bytes (" << m_remote << "@"
<< m_socket->remoteEndpoint() << ")";
Expand All @@ -390,8 +409,8 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
bytesConstRef(&header).cropped(3).copyTo(&headerRLP);

/// read padded frame and mac
LOG(m_logger) << connectionDirectionString() << "Frame body from " << m_remote
<< "@" << m_socket->remoteEndpoint();
LOG(m_logger) << "Frame body from " << m_remote << "@"
<< m_socket->remoteEndpoint();

constexpr size_t byteBoundary = 16;
m_handshakeInBuffer.resize(
Expand All @@ -408,8 +427,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
{
if (!m_io)
{
LOG(m_errorLogger) << connectionDirectionString()
<< "Internal error in handshake: "
LOG(m_errorLogger) << "Internal error in handshake: "
"RLPXFrameCoder disappeared ("
<< m_remote << ")";
m_nextState = Error;
Expand All @@ -420,8 +438,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
bytesRef frame(&m_handshakeInBuffer);
if (!m_io->authAndDecryptFrame(frame))
{
LOG(m_logger) << connectionDirectionString()
<< "Frame body decrypt failed (" << m_remote
LOG(m_logger) << "Frame body decrypt failed (" << m_remote
<< "@" << m_socket->remoteEndpoint() << ")";
m_nextState = Error;
transition();
Expand All @@ -433,7 +450,6 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
if (packetType != HelloPacket)
{
LOG(m_logger)
<< connectionDirectionString()
<< "Invalid packet type. Expected: "
<< packetTypeToString(HelloPacket)
<< ", received: " << packetTypeToString(packetType) << " ("
Expand All @@ -443,8 +459,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
return;
}

LOG(m_logger) << connectionDirectionString()
<< packetTypeToString(HelloPacket)
LOG(m_logger) << packetTypeToString(HelloPacket)
<< " verified. Starting session with " << m_remote
<< "@" << m_socket->remoteEndpoint();
try
Expand All @@ -456,8 +471,7 @@ void RLPXHandshake::transition(boost::system::error_code _ech)
catch (std::exception const& _e)
{
stringstream errorStream;
errorStream << connectionDirectionString() << "Handshake with "
<< m_remote;
errorStream << "Handshake with " << m_remote;
if (remoteSocketConnected())
errorStream << "@" << m_socket->remoteEndpoint();
errorStream << " causing an exception: " << _e.what();
Expand Down
6 changes: 3 additions & 3 deletions libp2p/RLPxHandshake.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,10 +33,10 @@ class RLPXHandshake: public std::enable_shared_from_this<RLPXHandshake>

public:
/// Setup incoming connection.
RLPXHandshake(Host* _host, std::shared_ptr<RLPXSocket> const& _socket): m_host(_host), m_originated(false), m_socket(_socket), m_idleTimer(m_socket->ref().get_io_service()) { crypto::Nonce::get().ref().copyTo(m_nonce.ref()); }
RLPXHandshake(Host* _host, std::shared_ptr<RLPXSocket> const& _socket);

/// Setup outbound connection.
RLPXHandshake(Host* _host, std::shared_ptr<RLPXSocket> const& _socket, NodeID _remote): m_host(_host), m_remote(_remote), m_originated(true), m_socket(_socket), m_idleTimer(m_socket->ref().get_io_service()) { crypto::Nonce::get().ref().copyTo(m_nonce.ref()); }
RLPXHandshake(Host* _host, std::shared_ptr<RLPXSocket> const& _socket, NodeID _remote);

virtual ~RLPXHandshake() = default;

Expand Down