Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

p2p: Track/log peer uptime and received msg stats #1057

Merged
merged 1 commit into from
Jul 21, 2018

Conversation

gsalgado
Copy link
Collaborator

@gsalgado gsalgado commented Jul 20, 2018

No description provided.

@gsalgado
Copy link
Collaborator Author

I ran a mainnet node with this for a few minutes and saw some bursts of Transaction messages from a few peers that caused the ChainSyncer's msg queue to fill up and cause msgs to be dropped. As shown below, some peers sent us 23k Transaction msgs in less than 10 minutes. Don't know if this is normal, but something to consider when addressing #1052

   DEBUG  07-20 17:07:22        peer  == Peer details ==
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x70b8@118.163.143.32)>: running=True, uptime=0:0:11:57, received_msgs=1727, most_received=Transactions (cmd_id=18)(1477)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xebd1@34.201.141.19)>: running=True, uptime=0:0:11:30, received_msgs=15527, most_received=Transactions (cmd_id=18)(15318)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x94bc@18.233.170.244)>: running=True, uptime=0:0:10:35, received_msgs=8638, most_received=Transactions (cmd_id=18)(8457)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x3a7d@47.104.227.230)>: running=True, uptime=0:0:10:32, received_msgs=13114, most_received=Transactions (cmd_id=18)(12935)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xecf6@202.77.128.12)>: running=True, uptime=0:0:10:31, received_msgs=465, most_received=Transactions (cmd_id=18)(301)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x234b@47.88.230.226)>: running=True, uptime=0:0:10:30, received_msgs=14816, most_received=Transactions (cmd_id=18)(14638)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x4bf0@34.230.45.88)>: running=True, uptime=0:0:10:21, received_msgs=15010, most_received=Transactions (cmd_id=18)(14837)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x768b@54.198.100.133)>: running=True, uptime=0:0:9:54, received_msgs=12211, most_received=Transactions (cmd_id=18)(12052)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x5513@136.243.91.41)>: running=True, uptime=0:0:9:29, received_msgs=23042, most_received=Transactions (cmd_id=18)(22893)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xe8a5@34.239.180.69)>: running=True, uptime=0:0:9:10, received_msgs=2939, most_received=Transactions (cmd_id=18)(2796)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0x5a06@52.59.1.81)>: running=True, uptime=0:0:8:15, received_msgs=8438, most_received=Transactions (cmd_id=18)(8315)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xd4b9@47.75.190.55)>: running=True, uptime=0:0:8:13, received_msgs=12882, most_received=Transactions (cmd_id=18)(12760)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xf60e@188.2.19.54)>: running=True, uptime=0:0:8:7, received_msgs=1787, most_received=Transactions (cmd_id=18)(1709)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xfeda@54.158.81.212)>: running=True, uptime=0:0:8:4, received_msgs=2770, most_received=Transactions (cmd_id=18)(2650)
   DEBUG  07-20 17:07:22        peer  ETHPeer <Node(0xbe2e@34.254.210.116)>: running=True, uptime=0:0:8:1, received_msgs=8129, most_received=Transactions (cmd_id=18)(8008)

p2p/peer.py Outdated
@@ -334,6 +348,8 @@ def is_closing(self) -> bool:
# though, otherwise asyncio's event loop can't run and we can't keep up with other peers.
decoded_msg = cast(Dict[str, Any], cmd.decode(msg))
self.logger.trace("Successfully decoded %s msg: %s", cmd, decoded_msg)
count = self.received_msgs.get(cmd, 0)
self.received_msgs[cmd] = count + 1
Copy link
Member

Choose a reason for hiding this comment

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

If you make received_msgs a collections.defaultdict(int) then you can make this a one-liner as self.received_msgs[cmd] += 1

p2p/peer.py Outdated
def uptime(self) -> str:
delta = datetime.now() - self.start_time
hours, remainder = divmod(delta.seconds, 3600)
minutes, seconds = divmod(remainder, 60)
Copy link
Member

Choose a reason for hiding this comment

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

Strikes me as a good utility function, maybe returning a named tuple of days, hours, minutes, seconds, microseconds

p2p/peer.py Outdated
@property
def uptime(self) -> str:
delta = datetime.now() - self.start_time
hours, remainder = divmod(delta.seconds, 3600)

This comment was marked as resolved.

p2p/peer.py Outdated
@@ -9,6 +9,7 @@
ABC,
abstractmethod
)
from datetime import datetime
Copy link
Member

Choose a reason for hiding this comment

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

p2p/peer.py Outdated
delta = datetime.now() - self.start_time
hours, remainder = divmod(delta.seconds, 3600)
minutes, seconds = divmod(remainder, 60)
return '%d:%02d:%02d:%02d' % (delta.days, hours, minutes, seconds)
Copy link
Contributor

Choose a reason for hiding this comment

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

@pipermerriam days was included down here as delta.days, which is why just delta.seconds works above (it's the remainder of seconds after dividing out the full days). eg~ https://stackoverflow.com/a/10981895/8412986

@gsalgado gsalgado merged commit fd362cb into ethereum:master Jul 21, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants