From 5eadfb76a29a66cdcc144b96195b53f32662cce1 Mon Sep 17 00:00:00 2001 From: Nils-Erik Frantzell Date: Mon, 22 Apr 2019 21:37:14 -0700 Subject: [PATCH 1/3] Log egress/ingress via boost log attribute --- libp2p/RLPxHandshake.cpp | 100 ++++++++++++++++++++++----------------- libp2p/RLPxHandshake.h | 6 +-- 2 files changed, 60 insertions(+), 46 deletions(-) diff --git a/libp2p/RLPxHandshake.cpp b/libp2p/RLPxHandshake.cpp index 10e97ec6a72..f927e885c67 100644 --- a/libp2p/RLPxHandshake.cpp +++ b/libp2p/RLPxHandshake.cpp @@ -20,10 +20,38 @@ constexpr size_t c_ackCipherSizeBytes = 210; constexpr size_t c_authCipherSizeBytes = 307; } +RLPXHandshake::RLPXHandshake(Host* _host, std::shared_ptr 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(connectionDirectionString())); + m_errorLogger.add_attribute( + "Context", boost::log::attributes::constant(connectionDirectionString())); + crypto::Nonce::get().ref().copyTo(m_nonce.ref()); +} + +RLPXHandshake::RLPXHandshake( + Host* _host, std::shared_ptr 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(connectionDirectionString())); + m_errorLogger.add_attribute( + "Context", boost::log::attributes::constant(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); @@ -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); @@ -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() @@ -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), @@ -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()); @@ -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(); } @@ -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), @@ -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()); @@ -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(); } @@ -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(); } @@ -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; @@ -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)"; @@ -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; @@ -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. @@ -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; @@ -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 @@ -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() << ")"; @@ -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( @@ -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; @@ -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(); @@ -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) << " (" @@ -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 @@ -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(); diff --git a/libp2p/RLPxHandshake.h b/libp2p/RLPxHandshake.h index be695e71e41..a54dd447ac4 100644 --- a/libp2p/RLPxHandshake.h +++ b/libp2p/RLPxHandshake.h @@ -33,10 +33,10 @@ class RLPXHandshake: public std::enable_shared_from_this public: /// Setup incoming connection. - RLPXHandshake(Host* _host, std::shared_ptr 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 const& _socket); + /// Setup outbound connection. - RLPXHandshake(Host* _host, std::shared_ptr 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 const& _socket, NodeID _remote); virtual ~RLPXHandshake() = default; From 2a6f7dda7431b4a5b569b8af4bd1caea84a67d74 Mon Sep 17 00:00:00 2001 From: Nils-Erik Frantzell Date: Mon, 22 Apr 2019 21:37:36 -0700 Subject: [PATCH 2/3] Log expected/actual abridged genesis hashes --- libethereum/EthereumPeer.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/libethereum/EthereumPeer.cpp b/libethereum/EthereumPeer.cpp index 51f14e2ae4d..34b1d3b7850 100644 --- a/libethereum/EthereumPeer.cpp +++ b/libethereum/EthereumPeer.cpp @@ -62,8 +62,8 @@ std::string EthereumPeer::validate( error << "Protocol version mismatch. Host protocol version: " << _hostProtocolVersion << ", peer protocol version: " << m_protocolVersion; else if (m_genesisHash != _hostGenesisHash) - error << "Genesis hash mismatch. Host genesis hash: " << _hostGenesisHash - << ", peer genesis hash: " << m_genesisHash; + error << "Genesis hash mismatch. Host genesis hash: " << _hostGenesisHash.abridged() + << ", peer genesis hash: " << m_genesisHash.abridged(); else if (m_asking != Asking::State && m_asking != Asking::Nothing) error << "Peer banned for unexpected status message."; From 2d2720517968f127fb55abf49570cd47bfc050c9 Mon Sep 17 00:00:00 2001 From: Nils-Erik Frantzell Date: Wed, 24 Apr 2019 21:45:58 -0700 Subject: [PATCH 3/3] Reuse RLPxHandshake ctor --- libp2p/RLPxHandshake.cpp | 15 +++------------ 1 file changed, 3 insertions(+), 12 deletions(-) diff --git a/libp2p/RLPxHandshake.cpp b/libp2p/RLPxHandshake.cpp index f927e885c67..e9656a270e3 100644 --- a/libp2p/RLPxHandshake.cpp +++ b/libp2p/RLPxHandshake.cpp @@ -21,23 +21,14 @@ constexpr size_t c_authCipherSizeBytes = 307; } RLPXHandshake::RLPXHandshake(Host* _host, std::shared_ptr 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(connectionDirectionString())); - m_errorLogger.add_attribute( - "Context", boost::log::attributes::constant(connectionDirectionString())); - crypto::Nonce::get().ref().copyTo(m_nonce.ref()); -} + : RLPXHandshake(_host, _socket, {}) +{} RLPXHandshake::RLPXHandshake( Host* _host, std::shared_ptr const& _socket, NodeID _remote) : m_host(_host), m_remote(_remote), - m_originated(true), + m_originated(_remote), m_socket(_socket), m_idleTimer(m_socket->ref().get_io_service()) {