search

teamnsrg / ethereum-p2p

Official Go implementation of the Ethereum protocol
https://geth.ethereum.org
GNU Lesser General Public License v3.0
17 stars 9 forks source link

Zzma/add rlpx devp2p loggin #1

Closed zzma closed 6 years ago

zzma commented 6 years ago

@SimonSK @sid1602

RLPx (PING, PONG, FINDNODE, NEIGHBORS) and DEVP2P (HELLO, DISCONNECT, PING, PONG) logging.

In order to selectively log these protocol messages, I created a log method called Proto that logs at the CRITICAL (i.e. --verbosity=0) level.

Still need to add Ethereum Subprotocol stuff in the next PR

zzma commented 6 years ago

This should be ready to go. Has logging of all network messages, and peer addition/removal logging. One thing that it does not do is log the peer_id of the sender / receiver, beyond what can be inferred from message contents.

Here's the sample output for each message type. 

CRIT [12-07|22:39:17|p2p/discover/udp.go:548] <<PING/v4|addr="24.224.46.225:30303"|size=127|err=<nil>|obj={"Version":4,"From":{"IP":"24.224.46.225","UDP":30303,"TCP":30303},"To":{"IP":"76.191.16.13","UDP":59375,"TCP":0},"Expiration":1512707980,"Rest":[]} 
CRIT [12-07|22:39:17|p2p/discover/udp.go:548] <<PONG/v4|addr="139.199.203.145:30303"|size=149|err=<nil>|obj={"To":{"IP":"76.191.16.14","UDP":37909,"TCP":30303},"ReplyTok":"owenEBSJIaIV+4Ril1IDLlZkaBsXDYpY9M2zpwYy2sc=","Expiration":1512707977,"Rest":[]} 
CRIT [12-07|22:39:18|p2p/discover/udp.go:493] >>FINDNODE/v4|size=171|err=<nil>|obj={"Target":"32efd14301831aea5ec30adb28107003056a5b11df8ef4d49eccb8f3d3bb46aab5fd872081591118cabd52c7643136eba457c3d17baf0353053001f30d1d1933","Expiration":1512707978,"Rest":null} 
CRIT [12-07|22:39:10|p2p/discover/udp.go:548] <<NEIGHBORS/v4|addr="52.16.188.185:30303"|size=425|err=<nil>|obj={"Nodes":[{"IP":"73.140.22.146","UDP":61881,"TCP":30303,"ID":"44f2f0a03c230b697abe833fa70df70be02feb5b983bb01e2cf812609868587a798643966c6be7bb98f4873e4114bca36cf6296482b77551a3fa1589df5d06bc"},{"IP":"101.71.216.87","UDP":15513,"TCP":30399,"ID":"ca0daa2d697275bf4c4a243d949572861fcee4841c7ea885200f3be2eb3c438544de2298e9d239e51301b18f65c126a9991d316a62ac7ebe8d603f95ac24ddc3"},{"IP":"97.89.56.18","UDP":30303,"TCP":30303,"ID":"297d69d14ffe0fe10fdd416ad2f0ff163444f4576cc438c400d12cea364b8d30af3ae28f0cf225c3bc4f80f857565d42d2a7f66e2124e22497a01c06acd9e85d"},{"IP":"68.47.237.57","UDP":30303,"TCP":30303,"ID":"bf966972c58d7ef86610a53efd7161298c8e4e4043dcb7fde5ca7ce5c8043b32caff629063c37b4659e46f51e89c1e1f3edfca2b831a339996ff5d521ac59dd0"}],"Expiration":1512707979,"Rest":[]} 
CRIT [12-07|22:39:23|p2p/message.go:133]      >>DEVP2P_HELLO|obj={"Version":5,"Name":"Geth/v1.7.3-stable-9368f779/darwin-amd64/go1.7","Caps":[{"Name":"eth","Version":63}],"ListenPort":0,"ID":"3d261c0d7cc073228519ded144650cc561902e150b6b0db5a767dd994b069bcd8400bf2e82c366cbcdc262ee07bb6979ceda657d543020c772dfda3f5cf8db06","Rest":null}|size=124 
CRIT [12-07|22:39:23|p2p/rlpx.go:158]         <<DEVP2P_DISC|obj="too many peers"|size=0x2 
CRIT [12-08|01:15:08|p2p/message.go:136]      >>DEVP2P_PING|obj=[]interface {}(nil)|size=0x1 
CRIT [12-08|01:15:09|p2p/message.go:136]      >>DEVP2P_PONG|obj=[]interface {}(nil)|size=0x1 
CRIT [12-07|22:39:41|p2p/message.go:121]      >>ETH_STATUS|obj={"ProtocolVersion":63,"NetworkId":1,"TD":17179869184,"CurrentBlock":"0xd4e56740f876aef8c010b86a40d5f56745a118d0906a34e69aec8c0db1cb8fa3","GenesisBlock":"0xd4e56740f876aef8c010b86a40d5f56745a118d0906a34e69aec8c0db1cb8fa3"}|size=76 
CRIT [12-07|22:51:48|p2p/message.go:121]      >>ETH_GET_BLOCK_HEADERS|obj={"Origin":{"Hash":"0x7470bcf1202f73135681fe9f24f270fbd4c9a79f59012f2d526dfa0cb3b07a25","Number":0},"Amount":1,"Skip":0,"Reverse":false}|size=37 
CRIT [12-08|01:14:52|eth/handler.go:419]      <<ETH_BLOCK_HEADERS|obj=[]*types.Header{{"parentHash":"0xa218e2c611f21232d857e3c8cecdcdf1f65f25a4477f98f6f47e4063807f2308","sha3Uncles":"0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347","miner":"0xbcdfc35b86bedf72f0cda046a3c16829a2ef41d1","stateRoot":"0xc5e389416116e3696cce82ec4533cce33efccb24ce245ae9546a4b8f0d5e9a75","transactionsRoot":"0x7701df8e07169452554d14aadd7bfa256d4a1d0355c1d174ab373e3e2d0a3743","receiptsRoot":"0x26cf9d9422e9dd95aedc7914db690b92bab6902f5221d62694a2fa5d065f534b","logsBloom":"0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000","difficulty":"0x38c3bf2616aa","number":"0x1d4c00","gasLimit":"0x47e7c0","gasUsed":"0x14820","timestamp":"0x578f7aa8","extraData":"0x64616f2d686172642d666f726b","mixHash":"0x5b5acbf4bf305f948bd7be176047b20623e1417f75597341a059729165b92397","nonce":"0xbede87201de42426","hash":"0x4985f5ca3d2afbec36529aa96f74de3cc10a2a4a6c44f2157a57d2c6059a11bb"}}|size=0x213 
CRIT [12-08|01:15:03|p2p/message.go:121]      >>ETH_GET_BLOCK_BODIES|obj=[]common.Hash{[22 183 176 25 46 17 185 1 222 143 213 27 108 219 217 241 166 32 151 238 154 245 40 154 4 179 34 162 52 236 171 92], [47 185 50 99 184 167 225 118 131 65 218 128 57 223 209 236 125 172 109 186 86 117 174 108 187 247 18 72 109 138 82 222]}|size=68 
CRIT [12-08|01:15:04|eth/handler.go:505]      <<ETH_BLOCK_BODIES|obj="<OMITTED>"|size=0x299 
CRIT [12-07|22:51:52|eth/handler.go:630]      <<ETH_NEW_BLOCK_HASHES|obj=eth.newBlockHashesData{struct { Hash common.Hash; Number uint64 }{Hash:[85 222 44 128 100 151 196 178 117 189 134 186 42 58 102 210 105 171 3 222 235 216 19 103 215 2 255 45 92 104 24 78], Number:0x47a326}}|size=0x27 
CRIT [12-07|22:51:52|p2p/message.go:121]      >>ETH_GET_NODE_DATA|obj=[]common.Hash{[218 139 98 251 43 76 238 127 139 27 161 200 101 222 220 150 76 36 242 28 109 145 25 185 180 81 78 104 59 243 83 228]}|size=34 
CRIT [12-08|01:15:02|eth/handler.go:564]      <<ETH_NODE_DATA|obj="<OMITTED>"|size=0x21a 
CRIT [12-07|22:51:54|p2p/message.go:121]      >>ETH_GET_RECEIPTS|obj=[]common.Hash{[15 204 199 234 153 143 23 32 194 5 184 48 48 143 230 68 195 221 252 239 19 31 86 28 15 193 179 185 196 246 231 77], [244 79 227 26 113 227 130 153 55 120 79 64 161 235 200 149 65 193 64 92 229 186 100 79 47 125 19 173 112 233 103 35]}|size=68 
CRIT [12-07|22:51:54|eth/handler.go:617]      <<ETH_RECEIPTS|obj="<OMITTED>"|size=0xbbb
zzma commented 6 years ago

Also - it's not passing tests currently, but that has more to do with master not passing tests. I will fix the tests in a separate PR and rebase all the branches on that.

zzma commented 6 years ago

@SimonSK - any concerns? Or you okay with this?

sid1602 commented 6 years ago

This looks good to me.

Siddharth Murali Graduate Student | Computer Engineering University of Illinois at Urbana Champaign | Class of 2018

On Fri, Dec 8, 2017 at 11:57 AM, Zane Ma notifications@github.com wrote:

@SimonSK https://github.com/simonsk - any concerns? Or you okay with this?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/teamnsrg/go-ethereum/pull/1#issuecomment-350329461, or mute the thread https://github.com/notifications/unsubscribe-auth/AJGwfI-ezakFqja9fabvMbp5X8pZ_Lt5ks5s-XiigaJpZM4Q4uyt .

zzma commented 6 years ago

I changed my mind and added peer nodeIDs to all messages. I also added a from IP address for incoming RLPx packets. All other parts of the messages are the same.

zzma commented 6 years ago

Oh btw, in case it wasn't clear from the code, this PR also includes Ethereum subprotocol messages as well.