[3.1] net_plugin improve block latency calculation

[heifner]

Remove the +1 to the block latency calculation otherwise even 0ms latency indicates 1 block latency instead of 0. The +1 makes the comparisons of head and msg.head in the if-else off by 1 when there is no latency.

Added additional logging so that issues like #588 are easier to debug.

Before:

debug 2022-12-21T21:54:29.938 net-3     net_plugin.cpp:1790           recv_handshake       ] ["localhost:9878 - f9bdaf6" - 43 127.0.0.1:52370] Network latency is 0ms, 0 blocks discrepancy by network latency, 1 blocks discrepancy expected once message received

After:

debug 2023-01-31T00:27:27.386 net-0     net_plugin.cpp:1795           recv_handshake       ] ["localhost:9878 - 978ab39" - 1 127.0.0.1:54362] Network latency is 0ms, 0 blocks discrepancy by network latency, 0 blocks discrepancy expected once message received

[greg7mdp]

The PR title doesn't seem quite right to me.

[heifner]

The PR title doesn't seem quite right to me.

How so?

[greg7mdp]

How so?

Sorry if I wasn't clear. I don't find it obvious why the change reduces the amount of handshake messages. From my uninformed viewpoint, it only seem to make the message more accurate.

[heifner]

Sorry if I wasn't clear. I don't find it obvious why the change reduces the amount of handshake messages. From my uninformed viewpoint, it only seem to make the message more accurate.

Ah, good point. I'll try to add some info about how this accomplishes the stated.

[heifner]

Ah, good point. I'll try to add some info about how this accomplishes the stated.

I added some additional info to the PR description. @greg7mdp

[greg7mdp]

I added some additional info to the PR description. @greg7mdp

Thanks a lot @heifner , crystal clear now :-)

[greg7mdp]

Can we factorize these 5 peer_ilog as in:

      auto log_handshake = [&](uint32_t sync) {
         peer_ilog( c, "handshake lib ${lib}, head ${head}, head id ${id}.. sync ${sync}, head ${h}, lib ${l}",
                    ("lib", msg.last_irreversible_block_num)("head", msg.head_num)("id", msg.head_id.str().substr(8,16))
                    ("sync", sync)("h", head)("l", lib_num) );
      };

      if (head_id == msg.head_id) {
         log_handshake(0);
         c->syncing = false;
         notice_message note;
         note.known_blocks.mode = none;
         note.known_trx.mode = catch_up;
         note.known_trx.pending = 0;
         c->enqueue( note );
         return;
      }
      if (head < msg.last_irreversible_block_num) {
         log_handshake(1);
         c->syncing = false;
         if (c->sent_handshake_count > 0) {
            c->send_handshake();
         }
         return;
      }
      if (lib_num > msg.head_num + nblk_combined_latency) {
         log_handshake(2);
         if (msg.generation > 1 || c->protocol_version > proto_base) {
            notice_message note;
            note.known_trx.pending = lib_num;
            note.known_trx.mode = last_irr_catch_up;
            note.known_blocks.mode = last_irr_catch_up;
            note.known_blocks.pending = head;
            c->enqueue( note );
         }
         c->syncing = true;
         return;
      }

      if (head + nblk_combined_latency < msg.head_num ) {
         log_handshake(3);
         c->syncing = false;
         verify_catchup(c, msg.head_num, msg.head_id);
         return;
      } else if(head >= msg.head_num + nblk_combined_latency) {
         log_handshake(4);
         ...

[heifner]

I prefer not to as you lose line #.

[greg7mdp]

fair enough! Although you could replace the lambda with a macro, as in:

#define log_handshake(sync) \
         peer_ilog( c, "handshake lib ${lib}, head ${head}, head id ${id}.. sync ${sync}, head ${h}, lib ${l}",\
                    ("lib", msg.last_irreversible_block_num)("head", msg.head_num)("id", msg.head_id.str().substr(8,16))\
                    ("sync", sync)("h", head)("l", lib_num) );

but maybe we should leave good enough alone :-).