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

Log active peer count and peer list #5575

Merged
merged 5 commits into from
Apr 25, 2019
Merged

Conversation

halfalicious
Copy link
Contributor

@halfalicious halfalicious commented Apr 24, 2019

Fix #5151

Log the active peer count and peer list to the "net" channel every 30 seconds. The peer count is logged with debug verbosity whereas the peer list is logged with trace verbosity.

@halfalicious halfalicious requested review from chfast and gumb0 and removed request for chfast April 24, 2019 04:51
@halfalicious halfalicious force-pushed the log-active-peer-info branch from 17690bf to a270d31 Compare April 24, 2019 04:58
Copy link
Member

@gumb0 gumb0 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you think about logging peer count to INFO verbosity instead?
It would help to show in the default logging that the client is doing something even if sync is not progressing. And during sync it's also interesting to see once in a while how many peers we have at the moment.

Also in case we have 0 peers Looking for peers... could be more user-friendly message than Active peers: 0

@@ -267,6 +267,16 @@ inline std::ostream& operator<<(std::ostream& _strm, NodeID const& _id)
return _strm;
}

inline boost::log::formatting_ostream& operator<<(
boost::log::formatting_ostream& _strm, PeerSessionInfo const& _peerSessionInfo)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Better to add a version for non-const PeerSessionInfo&, too

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Better to add a version for non-const PeerSessionInfo&, too

Why do we need this? I thought that non-const PeerInfo would be converted to const when calling the operator, which is acceptable since we don't need to modify the PeerInfo when logging it?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Apparently generic template<class T> operator<<(formatting_ostream& _strm, T& _value) is a better fit during overload resolution than implicitly converting to const reference

aleth/libdevcore/Log.h

Lines 136 to 138 in f5db298

// Below overloads for both const and non-const references are needed, because without overload for
// non-const reference generic operator<<(formatting_ostream& _strm, T& _value) will be preferred by
// overload resolution.

I found no better solution for this than defining second versions for non-const reference.

Maybe check that this is the case for PeerSessionInfo.

@halfalicious
Copy link
Contributor Author

halfalicious commented Apr 25, 2019

What do you think about logging peer count to INFO verbosity instead?
It would help to show in the default logging that the client is doing something even if sync is not progressing. And during sync it's also interesting to see once in a while how many peers we have at the moment.

Also in case we have 0 peers Looking for peers... could be more user-friendly message than Active peers: 0

I like the idea of logging the peer count with info verbosity. I agree that "looking for peers..." is more user-friendly, but I think that only logging it when there are 0 peers could be confusing since we're looking for peers regardless of whether or not we already have active peers. How about I log both the peer count and "looking for peers"?

@codecov-io
Copy link

codecov-io commented Apr 25, 2019

Codecov Report

Merging #5575 into master will decrease coverage by 0.01%.
The diff coverage is 45.45%.

Impacted file tree graph

@@            Coverage Diff            @@
##           master   #5575      +/-   ##
=========================================
- Coverage   62.11%   62.1%   -0.02%     
=========================================
  Files         347     347              
  Lines       29101   29057      -44     
  Branches     3299    3290       -9     
=========================================
- Hits        18077   18045      -32     
+ Misses       9843    9830      -13     
- Partials     1181    1182       +1

@halfalicious halfalicious force-pushed the log-active-peer-info branch from 8be220c to 3cbbc85 Compare April 25, 2019 04:36
Move logging to separate host function, add "looking for peers" message, and use Host helpers to retrieve peer count and peer session info vector. Also rename Host::peerSessionInfo to Host::peerSessionInfos so it more accurately reflects what the function is returning (vector of peerSessionInfo)

Also use const& when iterating over capabilities and update changelog so that new "changed" entry is grouped with other "changed" entries.
@halfalicious halfalicious force-pushed the log-active-peer-info branch from 3cbbc85 to 2d2d072 Compare April 25, 2019 04:50
libp2p/Host.cpp Outdated
if (m_netConfig.discovery)
LOG(m_infoLogger) << "Looking for peers...";

LOG(m_detailsLogger) << peerSessionInfos();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe prepend with "Peers: ".

@halfalicious
Copy link
Contributor Author

@gumb0 : I looked at the log output for multiple peers and the << overload for vector logs each entry on the same line, which makes the output a little difficult to read:

TRACE 04-25 09:13:41 p2p net [##6332792c…|Parity-Ethereum/v2.3.4-beta-0e95db1-20190220/x86_64-linux-gnu/rustc1.32.0|52.232.243.152|30303|(eth,62)(eth,63)(par,1)(par,2)(par,3)(pip,1), ##865a6325…|Parity-Ethereum/v2.2.9-stable-5d5b372-20190203/x86_64-linux-gnu/rustc1.31.1|52.176.100.77|30303|(eth,62)(eth,63)(par,1)(par,2)(par,3)(pip,1)]

I think it's better to log each peer info on its own line - I think I'll create a private function in Host called something like logPeerInfos which logs each peer info to its own line (and prepends the info with "Peer: "). Any objections?

@gumb0
Copy link
Member

gumb0 commented Apr 25, 2019

@halfalicious If that's necessary, I'd better make it return the string with newline-delimited peer infos, and then with

LOG(m_detailsLogger) << peerSessionInfosString();

we'll make sure we don't do any iteration/locking/copying if filters disable these logs.
It will result in somewhat ugly but acceptable I think output like

TRACE 04-25 09:13:41 p2p net Peers: ##6332792c…|Parity-Ethereum/v2.3.4-beta-0e95db1-20190220/x86_64-linux-gnu/rustc1.32.0|52.232.243.152|30303|(eth,62)(eth,63)(par,1)(par,2)(par,3)(pip,1)
##865a6325…|Parity-Ethereum/v2.2.9-stable-5d5b372-20190203/x86_64-linux-gnu/rustc1.31.1|52.176.100.77|30303|(eth,62)(eth,63)(par,1)(par,2)(par,3)(pip,1)

Another option could be to try to overload operator<< for vector<PeerSessionInfo>, too.

I personally wouldn't bother I think, it's in Trace verbosity - far from the needs of regular user.

@halfalicious halfalicious merged commit 14c3526 into master Apr 25, 2019
@halfalicious halfalicious deleted the log-active-peer-info branch April 25, 2019 19:41
@halfalicious halfalicious mentioned this pull request Apr 26, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Display number of connected peers during sync
3 participants