log bytes recv/sent per command

[jonasschnelli]

Not sure if we want to have this is master.

This adds a sent/recv byte counter per command to each CNode.
It is a waste product of some statistics gathering during finding a strategy for throttling nodes without affecting the overall quality of the network.

I think throttling the block response to a node with a height < self.height - 288 (TBD) would be a good approach. Nodes in initial sync might need longer to catch up if they are connected to throttled nodes only. Initial sync is a one time process and is therefore (maybe) be not very time critical.

Example:

    "bytessent_per_cmd": {
      "addr": 30003,
      "block": 28981980,
      "getheaders": 9682,
      "headers": 82,
      "inv": 30843,
      "ping": 48,
      "pong": 40,
      "tx": 97400,
      "verack": 0,
      "version": 103
    },
    "bytesrecv_per_cmd": {
      "getaddr": 0,
      "getdata": 11935,
      "getheaders": 997,
      "headers": 1458027,
      "ping": 40,
      "pong": 40,
      "reject": 230,
      "verack": 0,
      "version": 102
    }

[sipa]

Any reason not to use const std::string& ?

[jonasschnelli]

CNode::BeginMessage() also uses const char* (https://github.com/bitcoin/bitcoin/blob/master/src/net.h#L499). EndMessage() is always called over PushMessage(const char* pszCommand, const T1& a1, ...). Not sure if it would make sense to cast/transform to a std::string.

[sipa]

ok

[laanwj]

Right, I agree with @sipa that I prefer std::string, but yes for that to have any effect whatsoever that'd require switching that entire call chain to std::string and that is out of the scope of this pull.

[paveljanik]

On the other hand, we are already changing EndMessage() here, so it could be done in one step, together.

[jonasschnelli]

I think it's to invasive for a little logging feature. It would basically require to change all PushMessage(...) then BeginMessage() and EndMessage() function. An either conversion of CMessageHeader (that it accepts std::string) or some conversions to c-strings in the mentioned functions.
IMO, it's not worth changing this.

[paveljanik]

Agreed.

[sipa]

Concept ACK, I think this is useful.

[jonasschnelli]

Thanks @sipa for reviewing!
Fixed nits. Added bytessent_per_cmd and bytesrecv_per_cmd to getpeersinfo help.

[sipa]

I haven't checked the code for this, but we should make sure this only accounts for incoming messages of a known type. Otherwise you introduce a memory DoS attack by allowing the sender to construct an arbitrarily-sized map.

[jonasschnelli]

@sipa: good point! Will address it soon.

[theuni]

These maps will need locking

Edit: I take that back. It looks like the cs_vNodes in CopyNodeStats is enough. Might want to make CNode::mapSendBytesPerCmd / CNode::mapRecvBytesPerCmd private though, so nobody's tempted to use them directly.

[jonasschnelli]

@theuni: Right. I was aware of the locking and did come to the conclusion that both new maps are protected by cs_vSend and cs_vRecvMsg.

Moved the maps to the private section.

[jonasschnelli]

Added memory DOS prevention by filtering valid commands.

[sdaftuar]

Since this is a map lookup, can we just initialize the map once with entries for each valid string, and then do a find() here?

[jonasschnelli]

Yes. Would be possible. I somehow searched for a solution that doesn't require initialization. Do you think the map.find() would be faster or just less code?

[sdaftuar]

Mostly I was thinking less code/easier to read (though it would be faster too, since we have to do a find() anyway).

[laanwj]

C++11 to the rescue:

const static std::set<std::string> logAllowIncommingCmds = {
    "version", "verack", "addr", "inv", "getdata",
    "getblocks", "getheaders", "tx", "headers", "block",
    "getaddr", "mempool", "ping", "pong", "alert",
    "filterload", "filteradd", "filterclear", "reject"
};

    if (logAllowIncomingCmds.count(command))
        mapRecvBytesPerCmd[command] += msg.hdr.nMessageSize;

[jgarzik]

ut ACK - this actually recreates a change I wrote a long time ago (first version of getpeerinfo did this)

[dcousens]

concept ACK

edit: is it worth persisting this to storage?

[jonasschnelli]

IMO
for (unsigned int i = 0; i < sizeof(logAllowIncommingCmds)/sizeof(logAllowIncommingCmds[0]); i++) is fine until we switch over to C++11.

@dcousens: not sure if disk persistence would make sense here. I'd like to extend this up to the GUI layer to have a better network/bandwidth graph that could also generate and show data when it's not opened, though, this PR does not include time based data logging.

[jonasschnelli]

Passed Travis now.
Would be nice if someone can test this.

[laanwj]

Going to test this

[laanwj]

I've thought of - what I think is an even better solution - as it doesn't require recourse to anything besides the map itself: prepopulate the mapRecvBytesPerCmd. At initialization:

    for (unsigned int i = 0; i < sizeof(logAllowIncomingCmds)/sizeof(logAllowIncomingCmds[0]); i++)
        mapRecvBytesPerCmd[logAllowIncomingCmds[i]] = 0;

Then only increase if the item exists, e.g.

    mapCmdSize_t::iterator i = mapRecvBytesPerCmd.find(msg.hdr.pchCommand);
    if (i != mapRecvBytesPerCmd.end())
        i->second += msg.hdr.nMessageSize;

[jonasschnelli]

@laanwj: I like your map.find approach.
Implemented (squash-me commit) and renamed POSIX reserved *_t type.

[laanwj]

If we want we could hide the entries with i.second==0 here.

[jonasschnelli]

I also though about that, but I think the null entries are better instead of hiding. It result in more controllable parsing.

[laanwj]

Why would this result in more controllable parsing? The zeros don't mean anything. The only reason those entries are there in the first place is our 'ignore unknown command' implementation detail.

[laanwj]

Otherwise, to be consistent, if you really want an overview of all possible messages, we want zero entries for mapSendBytesPerCmd too (this will require an array of all messages we can potentially send).

[jonasschnelli]

I though if someone writes a statistics fronted that uses the RPC as data-source it would complicate things (a little bit) because you don't have a full list of available commands at the beginning. But no strong opinion. I think the drawback right now is a relatively big response.

[laanwj]

OK i agree. If you want to know eg. the set of commands that is not considered *other*. OK I don't care deeply about this, fine to leave it as-is, but I expect more people to comment on this. Empty rows just look unnecessary, and it's repeated for every peer.

[laanwj]

Minimally-tested ACK, I like this functionality a lot

[laanwj]

Speaking of which, why is verack accounted for 0 bytes? I guess we don't include the message header in the size? I think it should.

    "bytessent_per_cmd": {
      "addr": 31,
      "getheaders": 997,
      "inv": 9043,
      "ping": 16,
      "verack": 0,
      "version": 115
    },

[jonasschnelli]

Correct. Right now only the message size counts... so your right. This needs to be fixed, otherwise we are not really counting net bytes. Working on it.

[GIJensen]

ACK

[GIJensen]

nit: I believe these should read "BOOST_FOREACH(const mapMsgSize..." (No space between "(" and "const")

[jonasschnelli]

Fixed minor code style issues (three unnecessary spaces).

[laanwj]

Will merge after squash and travis OK

[jonasschnelli]

Squashed.

[rebroad]

why not put ssSend.size() into a variable and use that?

[rebroad]

Is anyone using this functionality? If so, can uses be documented somewhere?

[maflcko]

@rebroad I think the goal was to find out what msg consumes the most bytes.