Addressed PR feedback

Changed public functions of Session to use thread-safe logger since they can potentially be called from any thread. Also demote some network error messages from error to debug and make minor modifications to some log messages.
ethereum · May 24, 2019 · 4fbfa0c · 4fbfa0c
1 parent e7dc0b0
commit 4fbfa0c
Show file tree

Hide file tree

Showing 6 changed files with 27 additions and 24 deletions.
diff --git a/libethereum/EthereumCapability.h b/libethereum/EthereumCapability.h
@@ -190,7 +190,6 @@ class EthereumCapability : public p2p::CapabilityFace
 
     Logger m_logger{createLogger(VerbosityDebug, "ethcap")};
     Logger m_loggerDetail{createLogger(VerbosityTrace, "ethcap")};
-    Logger m_loggerError{createLogger(VerbosityError, "ethcap")};
     Logger m_loggerWarn{createLogger(VerbosityWarning, "ethcap")};
     /// Logger for messages about impolite behaivour of peers.
     Logger m_loggerImpolite{createLogger(VerbosityDebug, "impolite")};

diff --git a/libethereum/EthereumPeer.h b/libethereum/EthereumPeer.h
@@ -22,7 +22,8 @@ class EthereumPeer
         u256 const& /*_capabilityVersion*/)
       : m_host(std::move(_host)), m_id(_peerID)
     {
-        m_logger.add_attribute("Suffix", boost::log::attributes::constant<std::string>{m_id.hex()});
+        m_logger.add_attribute(
+            "Suffix", boost::log::attributes::constant<std::string>{m_id.abridged()});
     }
 
     bool statusReceived() const { return m_protocolVersion != 0; }

diff --git a/libethereum/WarpCapability.cpp b/libethereum/WarpCapability.cpp
@@ -123,10 +123,9 @@ class WarpPeerObserver : public WarpPeerObserverFace
                 data.toBytesConstRef());
 
             LOG(m_logger) << "Saved chunk " << hash << " Chunks left: " << m_neededChunks.size()
-                          << " Requested chunks: " << m_requestedChunks.size()
                           << " (peer: " << _peerID << ")";
             if (m_neededChunks.empty() && m_requestedChunks.empty())
-                LOG(m_logger) << "Snapshot download complete from " << _peerID;
+                LOG(m_logger) << "Snapshot download complete";
         }
         else
             m_neededChunks.push_back(askedHash);
@@ -457,13 +456,13 @@ bool WarpCapability::interpretCapabilityPacket(NodeID const& _peerID, unsigned _
     }
     catch (Exception const&)
     {
-        LOG(m_loggerError) << "Warp Peer " << _peerID << " causing an exception: "
-                           << boost::current_exception_diagnostic_information() << " " << _r;
+        LOG(m_loggerWarn) << "Warp Peer " << _peerID << " causing an exception: "
+                          << boost::current_exception_diagnostic_information() << " " << _r;
     }
     catch (std::exception const& _e)
     {
-        LOG(m_loggerError) << "Warp Peer " << _peerID << " causing an exception: " << _e.what()
-                           << " " << _r;
+        LOG(m_loggerWarn) << "Warp Peer " << _peerID << " causing an exception: " << _e.what()
+                          << " " << _r;
     }
 
     return true;

diff --git a/libethereum/WarpCapability.h b/libethereum/WarpCapability.h
@@ -131,7 +131,7 @@ class WarpCapability : public p2p::CapabilityFace
     std::unordered_map<NodeID, WarpPeerStatus> m_peers;
 
     Logger m_logger{createLogger(VerbosityDebug, "warpcap")};
-    Logger m_loggerError{createLogger(VerbosityError, "warpcap")};
+    Logger m_loggerWarn{createLogger(VerbosityWarning, "warpcap")};
 };
 
 }  // namespace eth

diff --git a/libp2p/Session.cpp b/libp2p/Session.cpp
@@ -27,6 +27,8 @@ Session::Session(Host* _h, unique_ptr<RLPXFrameCoder>&& _io, std::shared_ptr<RLP
     stringstream remoteInfoStream;
     remoteInfoStream << "(" << m_info.id << "@" << m_socket->remoteEndpoint() << ")";
 
+    m_logSuffix = remoteInfoStream.str();
+
     auto const attr = boost::log::attributes::constant<std::string>{remoteInfoStream.str()};
     m_netLogger.add_attribute("Suffix", attr);
     m_netLoggerDetail.add_attribute("Suffix", attr);
@@ -41,7 +43,8 @@ Session::Session(Host* _h, unique_ptr<RLPXFrameCoder>&& _io, std::shared_ptr<RLP
 
 Session::~Session()
 {
-    LOG(m_netLogger) << "Closing peer session";
+    cnetlog << "Closing peer session with " << m_logSuffix;
+
     m_peer->m_lastConnected = m_peer->m_lastAttempted - chrono::seconds(1);
 
     // Read-chain finished for one reason or another.
@@ -100,7 +103,7 @@ bool Session::readPacket(uint16_t _capId, unsigned _packetType, RLP const& _r)
         // v4 frame headers are useless, offset packet type used
         // v5 protocol type is in header, packet type not offset
         if (_capId == 0 && _packetType < UserPacket)
-            return interpretCapabilityPacket(static_cast<P2pPacketType>(_packetType), _r);
+            return interpretP2pPacket(static_cast<P2pPacketType>(_packetType), _r);
 
         for (auto const& cap : m_capabilities)
         {
@@ -131,7 +134,7 @@ bool Session::readPacket(uint16_t _capId, unsigned _packetType, RLP const& _r)
     return true;
 }
 
-bool Session::interpretCapabilityPacket(P2pPacketType _t, RLP const& _r)
+bool Session::interpretP2pPacket(P2pPacketType _t, RLP const& _r)
 {
     LOG(m_capLoggerDetail) << p2pPacketTypeToString(_t) << " from";
     switch (_t)
@@ -174,7 +177,7 @@ bool Session::interpretCapabilityPacket(P2pPacketType _t, RLP const& _r)
 
 void Session::ping()
 {
-    LOG(m_capLoggerDetail) << "Ping to";
+    clog(VerbosityTrace, "p2pcap") << "Ping to " << m_logSuffix;
     RLPStream s;
     sealAndSend(prep(s, PingPacket));
     m_ping = std::chrono::steady_clock::now();
@@ -295,7 +298,7 @@ void Session::drop(DisconnectReason _reason)
 
 void Session::disconnect(DisconnectReason _reason)
 {
-    LOG(m_netLoggerDetail) << "Disconnecting (our reason: " << reasonOf(_reason) << ") from";
+    cnetdetails << "Disconnecting (our reason: " << reasonOf(_reason) << ") from " << m_logSuffix;
 
     if (m_socket->ref().is_open())
     {
@@ -343,8 +346,8 @@ void Session::doRead()
             }
             catch (std::exception const& _e)
             {
-                LOG(m_netLoggerError) << "Exception decoding frame header RLP: " << _e.what() << " "
-                                      << bytesConstRef(m_data.data(), h128::size).cropped(3);
+                LOG(m_netLogger) << "Exception decoding frame header RLP: " << _e.what() << " "
+                                 << bytesConstRef(m_data.data(), h128::size).cropped(3);
                 drop(BadProtocol);
                 return;
             }
@@ -360,16 +363,16 @@ void Session::doRead()
                         return;
                     else if (!m_io->authAndDecryptFrame(bytesRef(m_data.data(), tlen)))
                     {
-                        LOG(m_netLoggerError) << "Frame decrypt failed";
+                        LOG(m_netLogger) << "Frame decrypt failed";
                         drop(BadProtocol);  // todo: better error
                         return;
                     }
 
                     bytesConstRef frame(m_data.data(), hLength);
                     if (!checkPacket(frame))
                     {
-                        LOG(m_netLoggerError) << "Received invalid message. Size: " << frame.size()
-                                              << " bytes, message: " << toHex(frame) << endl;
+                        LOG(m_netLogger) << "Received invalid message. Size: " << frame.size()
+                                         << " bytes, message: " << toHex(frame) << endl;
                         disconnect(BadProtocol);
                         return;
                     }
@@ -379,7 +382,7 @@ void Session::doRead()
                         RLP r(frame.cropped(1));
                         bool ok = readPacket(hProtocolId, packetType, r);
                         if (!ok)
-                            LOG(m_netLoggerError)
+                            LOG(m_netLogger)
                                 << "Couldn't interpret " << p2pPacketTypeToString(packetType)
                                 << " (" << packetType << "). RLP: " << RLP(r);
                     }
@@ -392,7 +395,7 @@ bool Session::checkRead(std::size_t _expected, boost::system::error_code _ec, st
 {
     if (_ec && _ec.category() != boost::asio::error::get_misc_category() && _ec.value() != boost::asio::error::eof)
     {
-        LOG(m_netLoggerDetail) << "Error reading: " << _ec.message();
+        LOG(m_netLogger) << "Error reading: " << _ec.message();
         drop(TCPError);
         return false;
     }
@@ -437,8 +440,7 @@ bool Session::canHandle(
 
 void Session::disableCapability(std::string const& _capabilityName, std::string const& _problem)
 {
-    LOG(m_netLoggerDetail) << "DISABLE: Disabling capability '" << _capabilityName
-                           << "'. Reason: " << _problem;
+    cnetlog << "Disabling capability '" << _capabilityName << "'. Reason: " << _problem << m_logSuffix;
     m_disabledCapabilities.insert(_capabilityName);
 }
 

diff --git a/libp2p/Session.h b/libp2p/Session.h
@@ -135,7 +135,7 @@ class Session: public SessionFace, public std::enable_shared_from_this<SessionFa
     bool readPacket(uint16_t _capId, unsigned _t, RLP const& _r);
 
     /// Interpret an incoming Session packet.
-    bool interpretCapabilityPacket(P2pPacketType _t, RLP const& _r);
+    bool interpretP2pPacket(P2pPacketType _t, RLP const& _r);
 
     /// @returns true iff the _msg forms a valid message for sending or receiving on the network.
     static bool checkPacket(bytesConstRef _msg);
@@ -177,6 +177,8 @@ class Session: public SessionFace, public std::enable_shared_from_this<SessionFa
 
     std::set<std::string> m_disabledCapabilities;
 
+    std::string m_logSuffix;
+
     Logger m_netLogger{createLogger(VerbosityDebug, "net")};
     Logger m_netLoggerDetail{createLogger(VerbosityTrace, "net")};
     Logger m_netLoggerError{createLogger(VerbosityError, "net")};