Skip to content

Commit 5288dc3

Browse files
mtrippledmtrippled
committed
Log outbound peer connection preparation.
Log lifecycle of peer connections in a single entry at beginning, and then when it ends. Log outbound connection attempts. Log peer connection when logging autoconnect preparation. Count total peers when checking autoconnect. Log untrusted validator lists.
1 parent 2216e5a commit 5288dc3

File tree

11 files changed

+208
-50
lines changed

11 files changed

+208
-50
lines changed

‎src/xrpld/app/misc/Manifest.h‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -353,7 +353,9 @@ class ManifestCache
353353
May be called concurrently
354354
*/
355355
ManifestDisposition
356-
applyManifest(Manifest m);
356+
applyManifest(
357+
Manifest m,
358+
std::unique_ptr<std::stringstream> const& ss = {});
357359

358360
/** Populate manifest cache with manifests in database and config.
359361

‎src/xrpld/app/misc/ValidatorList.h‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -424,7 +424,8 @@ class ValidatorList
424424
uint256 const& hash,
425425
Overlay& overlay,
426426
HashRouter& hashRouter,
427-
NetworkOPs& networkOPs);
427+
NetworkOPs& networkOPs,
428+
std::unique_ptr<std::stringstream> const& ss = {});
428429

429430
/** Apply multiple published lists of public keys.
430431
@@ -452,7 +453,8 @@ class ValidatorList
452453
std::uint32_t version,
453454
std::vector<ValidatorBlobInfo> const& blobs,
454455
std::string siteUri,
455-
std::optional<uint256> const& hash = {});
456+
std::optional<uint256> const& hash = {},
457+
std::unique_ptr<std::stringstream> const& ss = {});
456458

457459
/* Attempt to read previously stored list files. Expected to only be
458460
called when loading from URL fails.
@@ -786,7 +788,8 @@ class ValidatorList
786788
std::uint32_t version,
787789
std::string siteUri,
788790
std::optional<uint256> const& hash,
789-
lock_guard const&);
791+
lock_guard const&,
792+
std::unique_ptr<std::stringstream> const& ss = {});
790793

791794
// This function updates the keyListings_ counts for all the trusted
792795
// master keys
@@ -879,7 +882,8 @@ class ValidatorList
879882
Json::Value& list,
880883
std::string const& manifest,
881884
std::string const& blob,
882-
std::string const& signature);
885+
std::string const& signature,
886+
std::unique_ptr<std::stringstream> const& ss = {});
883887

884888
/** Stop trusting publisher's list of keys.
885889

‎src/xrpld/app/misc/detail/Manifest.cpp‎

Lines changed: 16 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -379,7 +379,9 @@ ManifestCache::revoked(PublicKey const& pk) const
379379
}
380380

381381
ManifestDisposition
382-
ManifestCache::applyManifest(Manifest m)
382+
ManifestCache::applyManifest(
383+
Manifest m,
384+
std::unique_ptr<std::stringstream> const& ss)
383385
{
384386
// Check the manifest against the conditions that do not require a
385387
// `unique_lock` (write lock) on the `mutex_`. Since the signature can be
@@ -388,7 +390,7 @@ ManifestCache::applyManifest(Manifest m)
388390
// comment below), `checkSignature` only needs to be set to true on the
389391
// first run.
390392
auto prewriteCheck =
391-
[this, &m](auto const& iter, bool checkSignature, auto const& lock)
393+
[this, &m, &ss](auto const& iter, bool checkSignature, auto const& lock)
392394
-> std::optional<ManifestDisposition> {
393395
XRPL_ASSERT(
394396
lock.owns_lock(),
@@ -415,6 +417,11 @@ ManifestCache::applyManifest(Manifest m)
415417
{
416418
if (auto stream = j_.warn())
417419
logMftAct(stream, "Invalid", m.masterKey, m.sequence);
420+
if (ss)
421+
{
422+
*ss << to_string(m)
423+
<< ": not verified. Hence, the manifest is invalid";
424+
}
418425
return ManifestDisposition::invalid;
419426
}
420427

@@ -450,6 +457,13 @@ ManifestCache::applyManifest(Manifest m)
450457
<< ": is not revoked and the manifest has no "
451458
"signing key. Hence, the manifest is "
452459
"invalid";
460+
if (ss)
461+
{
462+
*ss << to_string(m)
463+
<< ": is not revoked and the manifest has no "
464+
"signing key. Hence, the manifest is "
465+
"invalid";
466+
}
453467
return ManifestDisposition::invalid;
454468
}
455469

‎src/xrpld/app/misc/detail/ValidatorList.cpp‎

Lines changed: 43 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@
3636
#include <cmath>
3737
#include <numeric>
3838
#include <shared_mutex>
39+
#include <sstream>
3940

4041
namespace ripple {
4142

@@ -943,10 +944,11 @@ ValidatorList::applyListsAndBroadcast(
943944
uint256 const& hash,
944945
Overlay& overlay,
945946
HashRouter& hashRouter,
946-
NetworkOPs& networkOPs)
947+
NetworkOPs& networkOPs,
948+
std::unique_ptr<std::stringstream> const& ss)
947949
{
948950
auto const result =
949-
applyLists(manifest, version, blobs, std::move(siteUri), hash);
951+
applyLists(manifest, version, blobs, std::move(siteUri), hash, ss);
950952
auto const disposition = result.bestDisposition();
951953

952954
if (disposition == ListDisposition::accepted)
@@ -998,7 +1000,8 @@ ValidatorList::applyLists(
9981000
std::uint32_t version,
9991001
std::vector<ValidatorBlobInfo> const& blobs,
10001002
std::string siteUri,
1001-
std::optional<uint256> const& hash /* = {} */)
1003+
std::optional<uint256> const& hash /* = {} */,
1004+
std::unique_ptr<std::stringstream> const& ss)
10021005
{
10031006
if (std::count(
10041007
std::begin(supportedListVersions),
@@ -1019,7 +1022,8 @@ ValidatorList::applyLists(
10191022
version,
10201023
siteUri,
10211024
hash,
1022-
lock);
1025+
lock,
1026+
ss);
10231027

10241028
if (stats.bestDisposition() < result.bestDisposition() ||
10251029
(stats.bestDisposition() == result.bestDisposition() &&
@@ -1141,13 +1145,15 @@ ValidatorList::applyList(
11411145
std::uint32_t version,
11421146
std::string siteUri,
11431147
std::optional<uint256> const& hash,
1144-
ValidatorList::lock_guard const& lock)
1148+
ValidatorList::lock_guard const& lock,
1149+
std::unique_ptr<std::stringstream> const& ss)
11451150
{
11461151
using namespace std::string_literals;
11471152

11481153
Json::Value list;
11491154
auto const& manifest = localManifest ? *localManifest : globalManifest;
1150-
auto [result, pubKeyOpt] = verify(lock, list, manifest, blob, signature);
1155+
auto [result, pubKeyOpt] =
1156+
verify(lock, list, manifest, blob, signature, ss);
11511157

11521158
if (!pubKeyOpt)
11531159
{
@@ -1356,17 +1362,34 @@ ValidatorList::verify(
13561362
Json::Value& list,
13571363
std::string const& manifest,
13581364
std::string const& blob,
1359-
std::string const& signature)
1365+
std::string const& signature,
1366+
std::unique_ptr<std::stringstream> const& ss)
13601367
{
13611368
auto m = deserializeManifest(base64_decode(manifest));
13621369

13631370
if (!m || !publisherLists_.count(m->masterKey))
1371+
{
1372+
JLOG(j_.debug()) << "problem verifying manifest: deserialize "
1373+
<< (m ? "success" : "failure") << ", master key "
1374+
<< (publisherLists_.count(m->masterKey) ? "" : "not")
1375+
<< " in publisherLists_";
1376+
if (ss)
1377+
{
1378+
*ss << "setting ListDisposition::untrusted. problem verifying "
1379+
"manifest: deserialize "
1380+
<< (m ? "success" : "failure") << ", master key "
1381+
<< (publisherLists_.count(m->masterKey) ? "" : "not")
1382+
<< " in publisherLists_. ";
1383+
}
13641384
return {ListDisposition::untrusted, {}};
1385+
}
13651386

13661387
PublicKey masterPubKey = m->masterKey;
13671388
auto const revoked = m->revoked();
13681389

1369-
auto const result = publisherManifests_.applyManifest(std::move(*m));
1390+
auto applySs = std::make_unique<std::stringstream>();
1391+
auto const result =
1392+
publisherManifests_.applyManifest(std::move(*m), applySs);
13701393

13711394
if (revoked && result == ManifestDisposition::accepted)
13721395
{
@@ -1378,7 +1401,19 @@ ValidatorList::verify(
13781401
auto const signingKey = publisherManifests_.getSigningKey(masterPubKey);
13791402

13801403
if (revoked || !signingKey || result == ManifestDisposition::invalid)
1404+
{
1405+
if (ss)
1406+
{
1407+
*ss << "setting ListDisposition::untrusted. "
1408+
<< (revoked ? " revoked " : " not revoked ")
1409+
<< (signingKey ? "" : " bad signing key ")
1410+
<< (result == ManifestDisposition::invalid ? " invalid result. "
1411+
: "");
1412+
if (!applySs->str().empty())
1413+
*ss << " reason: " << applySs->str() << ". ";
1414+
}
13811415
return {ListDisposition::untrusted, masterPubKey};
1416+
}
13821417

13831418
auto const sig = strUnHex(signature);
13841419
auto const data = base64_decode(blob);

‎src/xrpld/overlay/detail/ConnectAttempt.cpp‎

Lines changed: 31 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -51,14 +51,20 @@ ConnectAttempt::ConnectAttempt(
5151
, stream_(*stream_ptr_)
5252
, slot_(slot)
5353
{
54-
JLOG(journal_.debug()) << "Connect " << remote_endpoint;
54+
log << "CONNECTATTEMPT start "
55+
<< to_string(std::chrono::system_clock::now())
56+
<< ". remote ip: " << remote_endpoint_ << ". id: " << id_;
57+
JLOG(journal_.debug()) << "connecting " << log.str();
5558
}
5659

5760
ConnectAttempt::~ConnectAttempt()
5861
{
5962
if (slot_ != nullptr)
6063
overlay_.peerFinder().on_closed(slot_);
6164
JLOG(journal_.trace()) << "~ConnectAttempt";
65+
JLOG(journal_.debug()) << log.str() << ". end reason: "
66+
<< (close_reason.str().empty() ? "unknown"
67+
: close_reason.str());
6268
}
6369

6470
void
@@ -71,7 +77,7 @@ ConnectAttempt::stop()
7177
{
7278
JLOG(journal_.debug()) << "Stop";
7379
}
74-
close();
80+
close("stop");
7581
}
7682

7783
void
@@ -88,7 +94,7 @@ ConnectAttempt::run()
8894
//------------------------------------------------------------------------------
8995

9096
void
91-
ConnectAttempt::close()
97+
ConnectAttempt::close(const char* reason)
9298
{
9399
XRPL_ASSERT(
94100
strand_.running_in_this_thread(),
@@ -99,21 +105,25 @@ ConnectAttempt::close()
99105
timer_.cancel(ec);
100106
socket_.close(ec);
101107
JLOG(journal_.debug()) << "Closed";
108+
log << "close ";
109+
close_reason << reason;
102110
}
103111
}
104112

105113
void
106114
ConnectAttempt::fail(std::string const& reason)
107115
{
108116
JLOG(journal_.debug()) << reason;
109-
close();
117+
close(reason.c_str());
110118
}
111119

112120
void
113121
ConnectAttempt::fail(std::string const& name, error_code ec)
114122
{
123+
std::stringstream ss;
124+
ss << name << ", error: " << ec.message();
115125
JLOG(journal_.debug()) << name << ": " << ec.message();
116-
close();
126+
close(ss.str().c_str());
117127
}
118128

119129
void
@@ -149,7 +159,9 @@ ConnectAttempt::onTimer(error_code ec)
149159
{
150160
// This should never happen
151161
JLOG(journal_.error()) << "onTimer: " << ec.message();
152-
return close();
162+
std::stringstream ss;
163+
ss << "onTimer, error: " << ec.message();
164+
return close(ss.str().c_str());
153165
}
154166
fail("Timeout");
155167
}
@@ -201,7 +213,7 @@ ConnectAttempt::onHandshake(error_code ec)
201213

202214
auto const sharedValue = makeSharedValue(*stream_ptr_, journal_);
203215
if (!sharedValue)
204-
return close(); // makeSharedValue logs
216+
return close("onHandshake no sharedValue"); // makeSharedValue logs
205217

206218
req_ = makeRequest(
207219
!overlay_.peerFinder().config().peerPrivate,
@@ -278,11 +290,11 @@ ConnectAttempt::onShutdown(error_code ec)
278290
if (!ec)
279291
{
280292
JLOG(journal_.error()) << "onShutdown: expected error condition";
281-
return close();
293+
return close("onShutdown: expected error condition");
282294
}
283295
if (ec != boost::asio::error::eof)
284296
return fail("onShutdown", ec);
285-
close();
297+
close("onShutdown eof");
286298
}
287299

288300
//--------------------------------------------------------------------------
@@ -331,7 +343,10 @@ ConnectAttempt::processResponse()
331343
JLOG(journal_.info())
332344
<< "Unable to upgrade to peer protocol: " << response_.result()
333345
<< " (" << response_.reason() << ")";
334-
return close();
346+
std::stringstream ss;
347+
ss << "unable to upgrade peer protocol: " << response_.result() << " ("
348+
<< response_.reason() << ")";
349+
return close(ss.str().c_str());
335350
}
336351

337352
// Just because our peer selected a particular protocol version doesn't
@@ -351,7 +366,7 @@ ConnectAttempt::processResponse()
351366

352367
auto const sharedValue = makeSharedValue(*stream_ptr_, journal_);
353368
if (!sharedValue)
354-
return close(); // makeSharedValue logs
369+
return close("processResponse no sharedValue"); // makeSharedValue logs
355370

356371
try
357372
{
@@ -365,14 +380,17 @@ ConnectAttempt::processResponse()
365380

366381
JLOG(journal_.info())
367382
<< "Public Key: " << toBase58(TokenType::NodePublic, publicKey);
383+
log << "public key: " << toBase58(TokenType::NodePublic, publicKey);
368384

369385
JLOG(journal_.debug())
370386
<< "Protocol: " << to_string(*negotiatedProtocol);
387+
log << " protocol: " << to_string(*negotiatedProtocol);
371388

372389
auto const member = app_.cluster().member(publicKey);
373390
if (member)
374391
{
375392
JLOG(journal_.info()) << "Cluster name: " << *member;
393+
log << "cluster name: " << *member;
376394
}
377395

378396
auto const result = overlay_.peerFinder().activate(
@@ -391,13 +409,15 @@ ConnectAttempt::processResponse()
391409
*negotiatedProtocol,
392410
id_,
393411
overlay_);
412+
peer->log << "outbound ( " << log.str() << "). ";
394413

395414
overlay_.add_active(peer);
396415
}
397416
catch (std::exception const& e)
398417
{
399418
return fail(std::string("Handshake failure (") + e.what() + ")");
400419
}
420+
close_reason << "successful connection";
401421
}
402422

403423
} // namespace ripple

‎src/xrpld/overlay/detail/ConnectAttempt.h‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@
2222

2323
#include <xrpld/overlay/detail/OverlayImpl.h>
2424
#include <xrpld/overlay/detail/Tuning.h>
25+
#include <sstream>
2526

2627
namespace ripple {
2728

@@ -62,6 +63,9 @@ class ConnectAttempt : public OverlayImpl::Child,
6263
request_type req_;
6364

6465
public:
66+
std::stringstream log;
67+
std::stringstream close_reason;
68+
6569
ConnectAttempt(
6670
Application& app,
6771
boost::asio::io_service& io_service,
@@ -83,7 +87,7 @@ class ConnectAttempt : public OverlayImpl::Child,
8387

8488
private:
8589
void
86-
close();
90+
close(const char* reason);
8791
void
8892
fail(std::string const& reason);
8993
void

0 commit comments

Comments
 (0)