fix(hang): Stop blocking some Zebra futures for up to a minute using a CPU busy-loop, Credit: Ziggurat Team (#6763), james_katz (#7000)

[teor2345]

Motivation

Since PR #6235 was merged in March 2023, Zebra's progress logging future has been busy-waiting in a loop for at least 55 seconds out of every minute.

Since this loop doesn't call into the tokio executor, it never yields, so it blocks all other futures running on that thread.

This is a likely cause for these bugs:
Close #6763
Close #7000

It might also possibly be causing these bugs, or making them worse:

• RPC connection closed by Zebra during sending_transactions_using_lightwalletd test #6867
• Fix repeated block timeouts during initial sync #5709
• Use correct tx modifications in transaction::tests::v4_with_modified_joinsplit_is_rejected #6922
• Process abort in state tests on some macOS versions with Rust 1.70 #6812

Specifications

https://docs.rs/tokio/latest/tokio/#cpu-bound-tasks-and-blocking-code

Complex Code or Requirements

tokio uses cooperative multitasking with internal yields, but only tokio APIs can yield to tokio:
https://docs.rs/tokio/latest/tokio/task/index.html#cooperative-scheduling

Solution

Sleep before continuing the loop.
Use monotonic Instant times, so that changing the computer's clock doesn't cause progress updates to stop.

Review

This seems like it might be a release blocker, given the number of bugs it impacts.

Reviewer Checklist

• Will the PR name make sense to users?
  • Does it need extra CHANGELOG info? (new features, breaking changes, large changes)
• Are the PR labels correct?
• Does the code do what the ticket and PR says?
  • Does it change concurrent code, unsafe code, or consensus rules?
• How do you know it works? Does it have tests?

Follow Up Work

We should ask users to re-test and see if any of these bugs are still happening.

[teor2345]

@mpguerra is it ok if we get this merged before the release?

It would finish off all our current network bugs, and get Zebra ready for re-testing.

[codecov]

Codecov Report

Merging #7103 (45dbb42) into main (455779c) will decrease coverage by 0.03%.
The diff coverage is 0.00%.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #7103      +/-   ##
==========================================
- Coverage   77.38%   77.35%   -0.03%     
==========================================
  Files         310      310              
  Lines       41795    41796       +1     
==========================================
- Hits        32343    32332      -11     
- Misses       9452     9464      +12     

[conradoplg]

Good catch! I monitored CPU usage before & after and I think it shows the difference, before there was a core at 100% most of the time

[teor2345]

Good catch! I monitored CPU usage before & after and I think it shows the difference, before there was a core at 100% most of the time

Thanks, I was going to check this!

[teor2345]

I got the elapsed time calculation wrong, the tests should be fixed now.

[teor2345]

I can confirm, the only CPU heavy threads left on my machine are my zcashd testnet miner. All my Zebra instances are at 50% CPU or less.