Skip to content

test: rpc: add last block announcement time to getpeerinfo result#27052

Open
LarryRuane wants to merge 5 commits into
bitcoin:masterfrom
LarryRuane:2023-02-getpeerinfo
Open

test: rpc: add last block announcement time to getpeerinfo result#27052
LarryRuane wants to merge 5 commits into
bitcoin:masterfrom
LarryRuane:2023-02-getpeerinfo

Conversation

@LarryRuane

@LarryRuane LarryRuane commented Feb 6, 2023

Copy link
Copy Markdown
Contributor

This PR adds last_block_announcement to the per-peer getpeerinfo RPC result. This is the most recent time that this peer was the first to notify our node of a new block (one that we didn't already know about), or zero if this peer has never been the first to notify us of a new block. This timestamp already exists internally and is used for stale-tip eviction logic; this PR exposes it at the RPC layer.

This PR started out as a suggestion for additional test coverage, see #26172 (comment). It turned out that the easiest way to test (already-merged) #26172 is to add this field to getpeerinfo and have a functional test verify its value. But it may also be useful to have this result in its own right, similar to that RPC's existing last_block field -- it indicates something about the quality of our peers. It allows one to predict which peer will be evicted when the stale tip logic activates. (I'm not sure if that would be useful, but it may be.)

The functional test added here fails without #26172, which is the main goal.

This PR does not test the actual stale-tip eviction logic; that's difficult to do with a functional test. But it does test the correctness of the timestamp that the eviction logic depends on. #23352 is an attempt to test the eviction logic using a unit test, it's not ready to be merged yet. I think having both kinds of tests would be beneficial.

@DrahtBot

DrahtBot commented Feb 6, 2023

Copy link
Copy Markdown
Contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/27052.

Reviews

See the guideline for information on the review process.

Type Reviewers
Concept ACK satsie, kristapsk, naiyoma
Stale ACK rkrux

If your review is incorrectly listed, please copy-paste <!--meta-tag:bot-skip--> into the comment that the bot should ignore.

Conflicts

Reviewers, this pull request conflicts with the following ones:

  • #35315 (refactor: Use NodeClock::time_point in more places by maflcko)
  • #34565 (refactor: extract BlockDownloadManager from PeerManagerImpl by w0xlt)
  • #19461 (multiprocess: Add bitcoin-gui -ipcconnect option by ryanofsky)
  • #19460 (multiprocess: Add bitcoin-wallet -ipcconnect option by ryanofsky)
  • #10102 (Multiprocess bitcoin by ryanofsky)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

LLM Linter (✨ experimental)

Possible typos and grammar issues:

  • the the earlier height 2 block -> the earlier height 2 block [duplicate word; the intended meaning is clear once corrected]

2026-06-07 15:53:08

@LarryRuane

Copy link
Copy Markdown
Contributor Author

Force pushed to fix CI failure

@satsie

satsie commented Feb 7, 2023

Copy link
Copy Markdown
Contributor

Concept ACK. I spent quite a bit of time trying to test #26172 (my findings are documented here) and can confirm the difficulty of testing it with the current state of the test framework.

I also support the suggestion to add last_block_announcement to getpeerinfo not only because it seems to be the easiest way to test 26172, but I agree it can be useful information to have when trying to learn more about one's peers, especially when this timestamp is already available internally.

Comment thread src/net.h Outdated
Comment thread src/net.h Outdated
@LarryRuane

Copy link
Copy Markdown
Contributor Author

Force pushed from becf38061b2625bcc629293fec0dce7c27292e14 to

  • efc2e70f1763c6bf3f6b246202adb9d5f1f798ee diff -- needed rebase
  • 16d2903b8a9e6e980e24e04ab2d86c7e778f5764 diff -- make the suggested review changes
  • 2e80e3bdcd9cac7878c0d14956ba9c57626da855 diff -- fix CI failure
  • 6c564aafb3d5f61fffa0d6311ad688c47b14014a diff -- add release notes, and small improvement to functional test

I'll take this out of draft now since I think it's ready for review.

@sedited

sedited commented Mar 11, 2026

Copy link
Copy Markdown
Contributor

@rkrux @naiyoma can you take another look here?

@rkrux

rkrux commented Mar 12, 2026

Copy link
Copy Markdown
Contributor

can you take another look here?

Will get around to it soon.

@dergoegge

Copy link
Copy Markdown
Member

I think the commit messages for the last two commits should be more detailed

@danielabrozzoni danielabrozzoni left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Code Review d46a3a5

I still haven't tested, I only looked at the code for now. The code looks ok, but there are some style improvements that I think should be picked up:

  • I would like to see #27052 (comment), I think it would make the code more consistent and easier to understand
  • In the first commit (e3ea536), it would be nice to have some more context in the commit message on why you're converting m_last_block_announcement to NodeSeconds. Something as easy as "preparatory for next commit" is fine, it's just to have some history in git as well
  • The PR description is good and gives a lot of insight as of why the PR is useful, but this context should be in the commit messages as well. I would add it to the commit message of the third commit (34b9122)
  • The first three commits should have the prefixes rpc: or net: in the commit message.

Comment thread test/functional/p2p_block_times.py Outdated
Comment thread test/functional/p2p_block_times.py Outdated
Comment thread src/net_processing.cpp Outdated
Comment thread test/functional/p2p_block_times.py Outdated
Comment thread test/functional/p2p_block_times.py Outdated

@naiyoma naiyoma left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

TestedACK d46a3a5

Tested without the fix from PR #26172 by flipping the null check condition.
The test fails as expected, catching last_block_announcement not being updated
when a peer announces a new block.

assert peerinfo['last_block_announcement'] == cur_time
AssertionError

I have not been able to observe any eviction logs, but I could see the last_block_announcement being set for my peers
Every 5.0s: bitcoin-cli getpeerinfo | grep last_block_announcement ubuntu: Fri Mar 20 12:46:28 2026

"last_block_announcement": 1773995600,
"last_block_announcement": 0,
"last_block_announcement": 0,
"last_block_announcement": 1773999976,
"last_block_announcement": 1773999593,
"last_block_announcement": 0,
"last_block_announcement": 1773997866,
"last_block_announcement": 0,

micro nits: you can address this if you have to make another push

Consider adding a test case for when a peer sends a header that is new to us but has less chain work than our tip last_block_announcement.

@LarryRuane

Copy link
Copy Markdown
Contributor Author

I think I've addressed (and accepted) all suggestions, thanks!

@naiyoma

naiyoma commented Apr 2, 2026

Copy link
Copy Markdown
Contributor

I think I've addressed (and accepted) all suggestions, thanks!

will re-review

I haven't been able to reproduce the test failing

458/458 - p2p_block_times.py failed, Duration: 2401 s

I think this is where the timeout is happening -> https://github.com/bitcoin/bitcoin/blob/master/test/functional/test_framework/p2p.py#L917

@sedited

sedited commented Apr 20, 2026

Copy link
Copy Markdown
Contributor

@LarryRuane can you fix the CI failures here?

@LarryRuane

Copy link
Copy Markdown
Contributor Author

@naiyoma

Consider adding a test case for when a peer sends a header that is new to us but has less chain work than our tip last_block_announcement.

I added this to the test, but could not get it to work (CI fails intermittently). I don't think it's very important, so I reverted it (force-pushed 136eed4). In this very rare situation, if the timestamp gets updated (I don't think it will, but if it does), it's not much of a problem; it isn't critical that this timestamp is correct. If you know how to add this to the test, please explain; otherwise, I think this is okay to merge.

@naiyoma

naiyoma commented Apr 27, 2026

Copy link
Copy Markdown
Contributor

I added this to the test, but could not get it to work (CI fails intermittently). I don't think it's very important, so I reverted it (force-pushed 136eed4).

Yeah, this is not important. I just thought it would be a good addition to the test, but it shouldn’t block this PR from moving forward.
I did find the CI failure a bit odd. I’ll look into it. If I figure it out, I’ll share it here and likely add it as a follow-up.

@luke-jr

luke-jr commented Apr 27, 2026

Copy link
Copy Markdown
Member

In this very rare situation, if the timestamp gets updated (I don't think it will, but if it does), it's not much of a problem; it isn't critical that this timestamp is correct.

If it isn't important, then why expose it to RPC at all?

@naiyoma

naiyoma commented Apr 29, 2026

Copy link
Copy Markdown
Contributor

@naiyoma

Consider adding a test case for when a peer sends a header that is new to us but has less chain work than our tip last_block_announcement.

I added this to the test, but could not get it to work (CI fails intermittently). I don't think it's very important, so I reverted it (force-pushed 136eed4). In this very rare situation, if the timestamp gets updated (I don't think it will, but if it does), it's not much of a problem; it isn't critical that this timestamp is correct. If you know how to add this to the test, please explain; otherwise, I think this is okay to merge.

I think I've been able to reproduce the CI failure.
The intermittent timeout depends on how fast the test runs.

When the test runs quickly, the first and second blocks are identical because
both are created within the same second and get the same timestamp. So
blocks[-1].hash_hex == node.getbestblockhash() is immediately True and
send_blocks_and_test(success=True) resolves instantly.

When there is a slight delay between the two create_block calls,
the blocks get different timestamps and are therefore different.
block.hash_hex != block.hash_hex, so wait_until keeps polling for
60 seconds waiting for the tip to change. This results in
a timeout.

A second issue is that the test was not correclty checking the edge case i suggested.
it was passing because received_new_header=0
we already had the block. The chainwork condition was never
tested.

My suggestion is to create a genuinely different block with an explicit timestamp:

block2 = create_block(tip, create_coinbase(2), block.nTime + 1)
block2.solve()
headers_message2 = msg_headers()
headers_message2.headers = [CBlockHeader(block2)]
peer.send_and_ping(headers_message2)

This ensures received_new_header=1 never seen this header
but the condition still evaluates to false because nChainWork is equal not
greater:

if (received_new_header && last_header.nChainWork > m_chainman.ActiveChain().Tip()->nChainWork)
// True && (0006 > 0006) == False

I did generate mutants for this condition

if (received_new_header && last_header.nChainWork > m_chainman.ActiveChain().Tip()->nChainWork) {
        nodestate->m_last_block_announcement = Now<NodeSeconds>();
    }

<     if (received_new_header && last_header.nChainWork < m_chainman.ActiveChain().Tip()->nChainWork) {
---
>     if (received_new_header && last_header.nChainWork >= m_chainman.ActiveChain().Tip()->nChainWork) {
2899c2899
<     if (received_new_header && last_header.nChainWork <= m_chainman.ActiveChain().Tip()->nChainWork) {
---
>     if (received_new_header && last_header.nChainWork >= m_chainman.ActiveChain().Tip()->nChainWork) {
2899c2899
<     if (received_new_header || last_header.nChainWork > m_chainman.ActiveChain().Tip()->nChainWork) {
---
>     if (received_new_header && last_header.nChainWork >= m_chainman.ActiveChain().Tip()->nChainWork) {

Testing this edge case does kill these two surviving mutants (> -> >= and && -> ||). In my opinion, this is worth testing, so maybe it can be included here or in a follow-up.

@sedited

sedited commented May 22, 2026

Copy link
Copy Markdown
Contributor

@LarryRuane do you plan to update your approach here with @naiyoma's suggestions?

@LarryRuane

Copy link
Copy Markdown
Contributor Author

@naiyoma - thanks for the review and mutation testing!

@naiyoma naiyoma left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

re-ACK e422fc5

new test case added, test stylistic changes addressed, and commit messages prefixed, except for the first one, which could be net:

LarryRuane and others added 5 commits June 7, 2026 09:52
This non-functional change makes it clear that this variable is a
time_point (point-in-time) rather than a duration. (An int64_t can be
either). This variable's use is modified in the following commits, so
we may as well moderize its type. This type is also mockable, which a
later test commit takes advantage of.
Copy its value from CNodeState. Unused until the next commit.
This is the most recent time that this peer was the first to notify our
node of a new block (one that we didn't already know about), or zero if
this peer has never been the first to notify us of a new block. This can
be used to evaluate the quality (performance) of this peer, similar to
the existing `last_block` field.

This timestamp already exists internally and is used for stale-tip
eviction logic; this PR exposes it at the RPC layer. This will also be
used (in a later commit) to increase stale-tip test coverage.
Co-authored-by: naiyoma <lankas.aurelia@gmail.com>
The `getpeerinfo` RPC now returns `last_block_announcement`.
@LarryRuane

Copy link
Copy Markdown
Contributor Author

... except for the first one, which could be net:

Thanks for catching that, force-pushed to fix that (just the commit message, no other changes).

@@ -200,7 +199,7 @@ BOOST_FIXTURE_TEST_CASE(stale_tip_peer_management, OutboundTest)

// Update the last announced block time for the last
// peer, and check that the next newest node gets evicted.
peerLogic->UpdateLastBlockAnnounceTime(vNodes.back()->GetId(), GetTime());
peerLogic->UpdateLastBlockAnnounceTime(vNodes.back()->GetId(), Now<NodeSeconds>());

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

nit in the first commit: This is not worse, but I don't think NodeSeconds is the right type here.

It seems more consistent to use the native clock type (and resolution), that is NodeClock::time_point.

I've pushed a commit that does this to fa67c65 (https://github.com/bitcoin/bitcoin/pull/35315/commits)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.