WIP: Log block height and size when received #8983

rebroad commented at 1:23 PM on October 20, 2016: contributor

Displays block height and size in debug.log when a block is received.

Various people have expressed a desire for this to be logged in previous PRs.

I'm not sure if the way I've passed the blocksize to ProcessNewBlock is the most ideal way. Very open to feedback on better ways.

Tested with "make check" now that I know about this! (Still not quite sure how to debug when tests fail quite yet though!)

The LogPrint also puts the debug message to "block" rather than "net" as part of an attempt to separate net debugs into more specific debugs. This pull does not include an update to init.cpp yet as I suspect this will want to be done as part of a later pull, once more things are using "block"? Apologies that I am unsure of the order in which this would be migrated.

Log height of block messages, if known, when received 05e0b74025

Log size of blocks received b475a41368

rebroad force-pushed on Oct 20, 2016

rebroad renamed this:
~~Show block height and size when received~~
Log block height and size when received
on Oct 20, 2016

in src/main.cpp:None in b475a41368

3752 | @@ -3753,9 +3753,14 @@ bool ProcessNewBlock(CValidationState& state, const CChainParams& chainparams, C
3753 |          CBlockIndex *pindex = NULL;
3754 |          bool fNewBlock = false;
3755 |          bool ret = AcceptBlock(*pblock, state, chainparams, &pindex, fRequested, dbp, &fNewBlock);
3756 | -        if (pindex && pfrom) {
3757 | -            mapBlockSource[pindex->GetBlockHash()] = pfrom->GetId();
3758 | -            if (fNewBlock) pfrom->nLastBlockTime = GetTime();
3759 | +        if (pfrom) {
3760 | +            if (pindex) {
3761 | +                LogPrint("block", "recv block %s (%d) size=%d peer=%d\n", pblock->GetHash().ToString(), pindex->nHeight,

sipa commented at 9:52 PM on October 20, 2016:

Why do you duplicate this line?

in src/main.cpp:None in b475a41368

6023 | @@ -6019,10 +6024,9 @@ bool static ProcessMessage(CNode* pfrom, string strCommand, CDataStream& vRecv,
6024 |      else if (strCommand == NetMsgType::BLOCK && !fImporting && !fReindex) // Ignore blocks received while importing
6025 |      {
6026 |          CBlock block;
6027 | +        pfrom->nBlockSize = vRecv.size(); // Used by ProcessNewBlock() debug

sipa commented at 9:54 PM on October 20, 2016:

That's not needed, and it's a layer violation, as this is the serialized size, not the block size.

rebroad commented at 9:16 AM on October 22, 2016:

@sipa thanks. ok, so I need to add the size of the header to get the block size, or subtract it? Do you say it's not needed as there is the function GetSerializeSize()? Happy to call that instead, but I somehow felt I was saving resources by not needing to.

sipa commented at 6:00 PM on October 24, 2016:

My question is more what do you want to log? How many bytes are being transferred, or the consensus-critical block size?

Assuming compact blocks and other better relay mechanisms take off, the size on the wire will be less and less relevant.

in src/main.cpp:None in b475a41368

3761 | +                LogPrint("block", "recv block %s (%d) size=%d peer=%d\n", pblock->GetHash().ToString(), pindex->nHeight,
3762 | +                    pfrom->nBlockSize, pfrom->id);
3763 | +                mapBlockSource[pindex->GetBlockHash()] = pfrom->GetId();
3764 | +                if (fNewBlock) pfrom->nLastBlockTime = GetTime();
3765 | +            } else
3766 | +                LogPrint("block", "recv block %s size=%d peer=%d\n", pblock->GetHash().ToString(), pfrom->nBlockSize, pfrom->id);

sipa commented at 9:56 PM on October 20, 2016:

You can use ::GetSerializeSize(*pblock, SER_DISK, CLIENT_VERSION) to obtain the total block size, or GetBlockWeight(*pblock) to get the weight (the limited resource after segwit, which may be more useful longer term).

rebroad commented at 9:18 AM on October 22, 2016:

Which is more useful to report? the height or the weight? (I am not actually sure what the weight even is!)

Shall I close this PR until I've made the changes or is it preferable to leave it open? Or shall I change the title to include WIP since it's still WIP?

sipa commented at 6:15 PM on October 24, 2016:

Weight is (4 * size_without_witness + 1 * size_of_witness). In segwit, weight is limited to 4000000.

fanquake added the label Docs and Output on Oct 21, 2016

MarcoFalke renamed this:
~~Log block height and size when received~~
WIP: Log block height and size when received
on Oct 22, 2016

gmaxwell commented at 4:53 PM on October 24, 2016: contributor

What does this gain over the logging in UpdateTip that we already do?

rebroad commented at 1:37 AM on October 25, 2016: contributor

@gmaxwell The thinking behind this was more along the lines of logging the serialized size of messages received with a view to adding more logging later, perhaps with a command line option to turn this on/off. Blocks, being the largest messages sent/recved, I felt to be particularly notable.

TODO - still needs changing so that ProcessNewBlock detects whether it's called from receiving a block or a compact block, as I don't want it to log "recv block" when it's actually a compact block that was received and a block constructed from that.

fanquake commented at 7:42 AM on November 13, 2016: member

What's the status of this? If it's still a WIP, can you close the PR for now, and re-open it when it's been finished & rebased?

fanquake commented at 8:33 AM on November 25, 2016: member

Closing for now, see comment above.

fanquake closed this on Nov 25, 2016

MarcoFalke locked this on Sep 8, 2021