Log outbound connection attempts.

Log peer connection when logging autoconnect preparation.

Author: mtrippled

src/xrpld/overlay/detail/ConnectAttempt.cpp

@@ -51,14 +51,18 @@ ConnectAttempt::ConnectAttempt(
     , stream_(*stream_ptr_)
     , slot_(slot)
 {
-    JLOG(journal_.debug()) << "Connect " << remote_endpoint;
+    log << "CONNECTATTEMPT start " << to_string(std::chrono::system_clock::now())
+        << ". remote ip: " << remote_endpoint_ << ". id: " << id_;
+    JLOG(journal_.debug()) << "connecting " << log.str();
 }
 
 ConnectAttempt::~ConnectAttempt()
 {
     if (slot_ != nullptr)
         overlay_.peerFinder().on_closed(slot_);
     JLOG(journal_.trace()) << "~ConnectAttempt";
+    JLOG(journal_.debug()) << log.str() << ". end reason: "
+        << (close_reason.str().empty() ? "unknown" : close_reason.str());
 }
 
 void
@@ -71,7 +75,7 @@ ConnectAttempt::stop()
     {
         JLOG(journal_.debug()) << "Stop";
     }
-    close();
+    close("stop");
 }
 
 void
@@ -88,7 +92,7 @@ ConnectAttempt::run()
 //------------------------------------------------------------------------------
 
 void
-ConnectAttempt::close()
+ConnectAttempt::close(const char* reason)
 {
     XRPL_ASSERT(
         strand_.running_in_this_thread(),
@@ -99,21 +103,25 @@ ConnectAttempt::close()
         timer_.cancel(ec);
         socket_.close(ec);
         JLOG(journal_.debug()) << "Closed";
+        log << "close ";
+        close_reason << reason;
     }
 }
 
 void
 ConnectAttempt::fail(std::string const& reason)
 {
     JLOG(journal_.debug()) << reason;
-    close();
+    close(reason.c_str());
 }
 
 void
 ConnectAttempt::fail(std::string const& name, error_code ec)
 {
+    std::stringstream ss;
+    ss << name << ", error: " << ec.message();
     JLOG(journal_.debug()) << name << ": " << ec.message();
-    close();
+    close(ss.str().c_str());
 }
 
 void
@@ -149,7 +157,9 @@ ConnectAttempt::onTimer(error_code ec)
     {
         // This should never happen
         JLOG(journal_.error()) << "onTimer: " << ec.message();
-        return close();
+        std::stringstream ss;
+        ss << "onTimer, error: " << ec.message();
+        return close(ss.str().c_str());
     }
     fail("Timeout");
 }
@@ -201,7 +211,7 @@ ConnectAttempt::onHandshake(error_code ec)
 
     auto const sharedValue = makeSharedValue(*stream_ptr_, journal_);
     if (!sharedValue)
-        return close();  // makeSharedValue logs
+        return close("onHandshake no sharedValue");  // makeSharedValue logs
 
     req_ = makeRequest(
         !overlay_.peerFinder().config().peerPrivate,
@@ -278,11 +288,11 @@ ConnectAttempt::onShutdown(error_code ec)
     if (!ec)
     {
         JLOG(journal_.error()) << "onShutdown: expected error condition";
-        return close();
+        return close("onShutdown: expected error condition");
     }
     if (ec != boost::asio::error::eof)
         return fail("onShutdown", ec);
-    close();
+    close("onShutdown eof");
 }
 
 //--------------------------------------------------------------------------
@@ -331,7 +341,10 @@ ConnectAttempt::processResponse()
         JLOG(journal_.info())
             << "Unable to upgrade to peer protocol: " << response_.result()
             << " (" << response_.reason() << ")";
-        return close();
+        std::stringstream ss;
+        ss << "unable to upgrade peer protocol: " << response_.result()
+            << " (" << response_.reason() << ")";
+        return close(ss.str().c_str());
     }
 
     // Just because our peer selected a particular protocol version doesn't
@@ -351,7 +364,7 @@ ConnectAttempt::processResponse()
 
     auto const sharedValue = makeSharedValue(*stream_ptr_, journal_);
     if (!sharedValue)
-        return close();  // makeSharedValue logs
+        return close("processResponse no sharedValue");  // makeSharedValue logs
 
     try
     {
@@ -365,14 +378,17 @@ ConnectAttempt::processResponse()
 
         JLOG(journal_.info())
             << "Public Key: " << toBase58(TokenType::NodePublic, publicKey);
+        log << "public key: " << toBase58(TokenType::NodePublic, publicKey);
 
         JLOG(journal_.debug())
             << "Protocol: " << to_string(*negotiatedProtocol);
+        log << " protocol: " << to_string(*negotiatedProtocol);
 
         auto const member = app_.cluster().member(publicKey);
         if (member)
         {
             JLOG(journal_.info()) << "Cluster name: " << *member;
+            log << "cluster name: " << *member;
         }
 
         auto const result = overlay_.peerFinder().activate(
@@ -391,14 +407,15 @@ ConnectAttempt::processResponse()
             *negotiatedProtocol,
             id_,
             overlay_);
-        peer->log << "outbound. ";
+        peer->log << "outbound ( " << log.str()  << "). ";
 
         overlay_.add_active(peer);
     }
     catch (std::exception const& e)
     {
         return fail(std::string("Handshake failure (") + e.what() + ")");
     }
+    close_reason << "successful connection";
 }
 
 }  // namespace ripple

src/xrpld/overlay/detail/ConnectAttempt.h

@@ -22,6 +22,7 @@
 
 #include <xrpld/overlay/detail/OverlayImpl.h>
 #include <xrpld/overlay/detail/Tuning.h>
+#include <sstream>
 
 namespace ripple {
 
@@ -62,6 +63,9 @@ class ConnectAttempt : public OverlayImpl::Child,
     request_type req_;
 
 public:
+    std::stringstream log;
+    std::stringstream close_reason;
+
     ConnectAttempt(
         Application& app,
         boost::asio::io_service& io_service,
@@ -83,7 +87,7 @@ class ConnectAttempt : public OverlayImpl::Child,
 
 private:
     void
-    close();
+    close(const char* reason);
     void
     fail(std::string const& reason);
     void

src/xrpld/overlay/detail/PeerImp.cpp

@@ -130,7 +130,7 @@ PeerImp::PeerImp(
                           << txReduceRelayEnabled_ << " on " << remote_address_
                           << " " << id_;
 
-    log << "ctor2";
+    log << "ctor2 ";
     initLog();
 }
 

src/xrpld/peerfinder/detail/Counts.h

@@ -249,6 +249,25 @@ class Counts
         return ss.str();
     }
 
+    std::string
+    stats() const {
+        std::stringstream ss;
+        ss << "peer stats, "
+            << "outbound attempts: " << m_attempts
+            << " active connections: " << m_active
+            << " inbound slots: " << m_in_max
+            << " active inbound slots: " << m_in_active
+            << " outbound slots: " << m_out_max
+            << " active outbound slots: " << m_out_active
+            << " fixed: " << m_fixed
+            << " active fixed: " << m_fixed_active
+            << " reserved: " << m_reserved
+            << " inbound not active or closing: " << m_acceptCount
+            << " closing: " << m_closingCount
+            << ". ";
+        return ss.str();
+    }
+
     //--------------------------------------------------------------------------
 private:
     // Adjusts counts based on the specified slot, in the direction indicated.

src/xrpld/peerfinder/detail/Logic.h

@@ -494,7 +494,7 @@ class Logic
     autoconnect()
     {
         std::stringstream ss;
-        ss << "AUTOCONNECT ";
+        ss << "AUTOCONNECT " << counts_.stats();
         std::vector<beast::IP::Endpoint> const none;
 
         std::lock_guard _(lock_);