Non-Finalised State not returned by Zebra's ReadStateService in Regtest mode.

[idky137]

$ cargo nextest run state_service_get_blockchain_info_no_cache --no-capture
    Finished `test` profile [unoptimized + debuginfo] target(s) in 0.22s
    Starting 1 test across 9 binaries (71 skipped)
       START             zaino-state state::tests::state_service_get_blockchain_info_no_cache

running 1 test
Connected to node using IPv4 at address http://127.0.0.1:20507/.
Fetch Service Chain Height: 2
State Service Chain Height: 0
2024-12-27T17:03:55.555954Z  INFO zebrad::components::tracing::component: started tracing component filter="info" TRACING_STATIC_MAX_LEVEL=LevelFilter::INFO LOG_STATIC_MAX_LEVEL=Info
2024-12-27T17:03:55.555970Z  INFO zebrad::components::tracing::component: set 'tracing.progress_bar ="summary"' in zebrad.toml to activate progress bars
2024-12-27T17:03:55.555972Z  INFO zebrad::application: Diagnostic Metadata:
version: 2.1.0+9.g0fe47bb
Zcash network: Regtest
running state version: 26.0.0
initial disk state version: creating.new.database
features: default,getblocktemplate_rpcs,howudoin,indicatif,progress_bar,release_max_level_info
branch: main
git commit: 0fe47bb
commit timestamp: 2024-12-21T02:29:16.000000000Z
target triple: x86_64-unknown-linux-gnu
rust compiler: 1.82.0
rust release date: 2024-10-15
optimization level: 3
debug checks: false
2024-12-27T17:03:55.555973Z  INFO zebrad::application: loaded zebrad config config_path=Some("/tmp/.tmp0O0JhF/zebrad.toml") config=ZebradConfig { consensus: Config { checkpoint_sync: true }, metrics: Config { endpoint_addr: None }, network: Config { listen_addr: 127.0.0.1:15417, external_addr: None, network: Regtest { activation_heights: {Height(0): Genesis, Height(1): Nu6} }, initial_mainnet_peers: {"dnsseed.z.cash:8233", "dnsseed.str4d.xyz:8233", "mainnet.seeder.zfnd.org:8233", "mainnet.is.yolo.money:8233"}, initial_testnet_peers: {"dnsseed.testnet.z.cash:18233", "testnet.seeder.zfnd.org:18233", "testnet.is.yolo.money:18233"}, cache_dir: IsEnabled(false), peerset_initial_target_size: 25, crawl_new_peer_interval: 61s, max_connections_per_ip: 1 }, state: Config { cache_dir: "/tmp/.tmpg4VWtW", ephemeral: false, delete_old_database: true, debug_stop_at_height: None, debug_validity_check_interval: None }, tracing: Config { inner: InnerConfig { use_color: true, force_use_color: false, filter: None, buffer_limit: 128000, endpoint_addr: None, flamegraph: None, progress_bar: None, log_file: None, use_journald: false } }, sync: Config { download_concurrency_limit: 50, checkpoint_verify_concurrency_limit: 1000, full_verify_concurrency_limit: 20, parallel_cpu_threads: 0 }, mempool: Config { tx_cost_limit: 80000000, eviction_memory_time: 3600s, debug_enable_at_height: None }, rpc: Config { listen_addr: Some(127.0.0.1:20507), indexer_listen_addr: None, parallel_cpu_threads: 0, debug_force_finished_sync: false, cookie_dir: "/tmp/.tmpg4VWtW", enable_cookie_auth: false }, mining: Config { miner_address: Some(TransparentAddress { network_kind: Testnet, pub_key_hash: "17a95184b6b158dcb8d576fc182d9b7f14377d04" }), extra_coinbase_data: None, debug_like_zcashd: true } }
2024-12-27T17:03:55.556003Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::application: initialized rayon thread pool for CPU-bound tasks num_threads=16
2024-12-27T17:03:55.557172Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: Starting zebrad
2024-12-27T17:03:55.557240Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: initializing node state
2024-12-27T17:03:55.557277Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: opening database, this may take a few minutes
2024-12-27T17:03:55.557371Z  WARN zebra_state::service::finalized_state::disk_db: could not canonicalize "/tmp/.tmpg4VWtW/state/v25/regtest": No such file or directory (os error 2)
2024-12-27T17:03:55.557379Z  INFO zebra_state::service::finalized_state::disk_format::upgrade: creating new database with the current format running_version=26.0.0
2024-12-27T17:03:55.557578Z  INFO zebra_state::service::finalized_state::disk_db: the open file limit is high enough for Zebra current_limit=1024 min_limit=512 ideal_limit=1024
2024-12-27T17:03:55.592516Z  INFO zebra_state::service::finalized_state::disk_db: Opened Zebra state cache at /tmp/.tmpg4VWtW/state/v26/regtest
2024-12-27T17:03:55.592553Z  INFO zebra_state::service::finalized_state: loaded Zebra state cache tip=None
2024-12-27T17:03:55.592613Z  INFO zebra_state::service: starting legacy chain check
2024-12-27T17:03:55.592619Z  INFO zebra_state::service: cached state consensus branch is valid: no legacy chain found
2024-12-27T17:03:55.592668Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: logging database metrics on startup
2024-12-27T17:03:55.592701Z  INFO zebra_state::service::finalized_state::disk_format::upgrade: marked database format as newly created running_version=26.0.0 disk_version=26.0.0
2024-12-27T17:03:55.592747Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::service::finalized_state::disk_db: the open file limit is high enough for Zebra current_limit=1024 min_limit=512 ideal_limit=1024
2024-12-27T17:03:55.593384Z  INFO zebra_state::service::finalized_state::disk_format::upgrade: database format is valid running_version=26.0.0 inital_disk_version=None
2024-12-27T17:03:55.593435Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Database Disk Size: 0 B
2024-12-27T17:03:55.593443Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Live Data Disk Size: 0 B
2024-12-27T17:03:55.593446Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Database Memory Size: 49.2 KB
2024-12-27T17:03:55.593483Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: initializing network
2024-12-27T17:03:55.593501Z  INFO {zebrad="0fe47bb" net="Regtest"}:open_listener{addr=127.0.0.1:15417}: zebra_network::peer_set::initialize: Trying to open Zcash protocol endpoint at 127.0.0.1:15417...
2024-12-27T17:03:55.593542Z  INFO {zebrad="0fe47bb" net="Regtest"}:open_listener{addr=127.0.0.1:15417}: zebra_network::peer_set::initialize: Opened Zcash protocol endpoint at 127.0.0.1:15417
2024-12-27T17:03:55.593573Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_network::address_book_updater: starting the address book updater
2024-12-27T17:03:55.593757Z  INFO {zebrad="0fe47bb" net="Regtest"}:add_initial_peers: zebra_network::peer_set::initialize: connecting to initial peer set ipv4_peer_count=0 ipv6_peer_count=0
2024-12-27T17:03:55.593767Z  INFO {zebrad="0fe47bb" net="Regtest"}:add_initial_peers: zebra_network::peer_set::initialize: finished connecting to initial seed and disk cache peers handshake_success_total=0 handshake_error_total=0 outbound_connections=0
2024-12-27T17:03:55.593824Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_network::peer_set::initialize: sending initial request for peers active_initial_peer_count=0
2024-12-27T17:03:55.593850Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: initializing verifiers
2024-12-27T17:03:55.593861Z  INFO {zebrad="0fe47bb" net="Regtest"}:crawl_and_dial{new_peer_interval=61s}: zebra_network::peer_set::initialize: starting the peer address crawler crawl_new_peer_interval=61s outbound_connections=0
2024-12-27T17:03:55.593895Z  INFO {zebrad="0fe47bb" net="Regtest"}:init{config=Config { checkpoint_sync: true } network=Regtest { activation_heights: {Height(0): Genesis, Height(1): Nu6} }}: zebra_consensus::router: starting state checkpoint validation
2024-12-27T17:03:55.594174Z  INFO {zebrad="0fe47bb" net="Regtest"}:init{config=Config { checkpoint_sync: true } network=Regtest { activation_heights: {Height(0): Genesis, Height(1): Nu6} }}: zebra_consensus::router: initializing block verifier router tip=None max_checkpoint_height=Height(0)
2024-12-27T17:03:55.594193Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: initializing syncer
2024-12-27T17:03:55.594211Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: initializing mempool
2024-12-27T17:03:55.594214Z  INFO {zebrad="0fe47bb" net="Regtest"}:init{config=Config { checkpoint_sync: true } network=Regtest { activation_heights: {Height(0): Genesis, Height(1): Nu6} }}: zebra_consensus::router: state is not fully synced yet, remaining checkpoints will be verified during syncing
2024-12-27T17:03:55.594216Z  INFO {zebrad="0fe47bb" net="Regtest"}:init{config=Config { checkpoint_sync: true } network=Regtest { activation_heights: {Height(0): Genesis, Height(1): Nu6} }}: zebra_consensus::router: finished state checkpoint validation
2024-12-27T17:03:55.594219Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: fully initializing inbound peer request handler
2024-12-27T17:03:55.594221Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning RPC server
2024-12-27T17:03:55.594222Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: Trying to open RPC endpoint at 127.0.0.1:20507...
2024-12-27T17:03:55.594276Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_rpc::server: Opened RPC endpoint at 127.0.0.1:20507
2024-12-27T17:03:55.594291Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning block gossip task
2024-12-27T17:03:55.594295Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning mempool queue checker task
2024-12-27T17:03:55.594296Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning mempool transaction gossip task
2024-12-27T17:03:55.594298Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning delete old databases task
2024-12-27T17:03:55.594300Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning progress logging task
2024-12-27T17:03:55.594301Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning end of support checking task
2024-12-27T17:03:55.594303Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning mempool crawler task
2024-12-27T17:03:55.594302Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::sync::gossip: initializing block gossip task
2024-12-27T17:03:55.594304Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool::gossip: initializing transaction gossip task
2024-12-27T17:03:55.594303Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool::queue_checker: initializing mempool queue checker task
2024-12-27T17:03:55.594307Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawning syncer task
2024-12-27T17:03:55.594307Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::config: checking for old database versions db_kind="state"
2024-12-27T17:03:55.594313Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool::crawler: initializing mempool crawler task
2024-12-27T17:03:55.594317Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::sync::progress: initial sync is waiting to download the genesis block sync_percent=0.000 % current_height=None
2024-12-27T17:03:55.594318Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::sync::end_of_support: Starting end of support task
2024-12-27T17:03:55.594351Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebra_state::config: finished old database version cleanup task
2024-12-27T17:03:55.594367Z  INFO {zebrad="0fe47bb" net="Regtest"}:checkpoint: zebra_consensus::checkpoint: verified checkpoint range block_count=1 current_range=(Unbounded, Included(Height(0)))
2024-12-27T17:03:55.594371Z  INFO {zebrad="0fe47bb" net="Regtest"}:checkpoint: zebra_consensus::checkpoint: verified final checkpoint: starting full validation final_checkpoint_height=Height(0)
2024-12-27T17:03:55.650065Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::commands::start: spawned initial Zebra tasks
2024-12-27T17:04:00.596055Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: enabling mempool for debugging best_tip_height=Height(0) enable_at_height=Height(0)
2024-12-27T17:04:00.596079Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: activating mempool: Zebra is close to the tip tip_height=Height(0)
2024-12-27T17:04:05.595314Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::sync::end_of_support: Release always valid in Testnet
2024-12-27T17:04:10.690330Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("6095670f4d9a72fec27443be51da4b330db4a494be5dac413d27e4a412bacae2") block_height="1"
2024-12-27T17:04:15.602414Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: resetting mempool: switched best chain, skipped blocks, or activated network upgrade tip_height=Height(1)
2024-12-27T17:04:15.602443Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: enabling mempool for debugging best_tip_height=Height(1) enable_at_height=Height(0)
2024-12-27T17:04:15.602446Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: activating mempool: Zebra is close to the tip tip_height=Height(1)
2024-12-27T17:04:15.602449Z  INFO {zebrad="0fe47bb" net="Regtest"}: zebrad::components::mempool: re-verifying mempool transactions after a chain fork transactions=0
2024-12-27T17:04:15.696757Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("437372d8a9bf638b459b59a952fdf35b5f92784dfb98d064403c3c059fb55dff") block_height="2"

thread 'state::tests::state_service_get_blockchain_info_no_cache' panicked at zaino-state/src/state.rs:879:9:
assertion `left == right` failed
  left: ("test", Height(0), block::Hash("029f11d80ef9765602235e1bc9727e3eb6ba20839319f761fee920d63401e327"), Height(5848405), {ConsensusBranchIdHex(ConsensusBranchId(1537743641)): NetworkUpgradeInfo { name: Overwinter, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(1991772603)): NetworkUpgradeInfo { name: Sapling, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(733220448)): NetworkUpgradeInfo { name: Blossom, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(4122551051)): NetworkUpgradeInfo { name: Heartwood, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(3925833126)): NetworkUpgradeInfo { name: Canopy, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(3268858036)): NetworkUpgradeInfo { name: Nu5, activation_height: Height(1), status: Pending }, ConsensusBranchIdHex(ConsensusBranchId(3370586197)): NetworkUpgradeInfo { name: Nu6, activation_height: Height(1), status: Pending }}, TipConsensusBranch { chain_tip: ConsensusBranchIdHex(ConsensusBranchId(0)), next_block: ConsensusBranchIdHex(ConsensusBranchId(3370586197)) })
 right: ("test", Height(2), block::Hash("437372d8a9bf638b459b59a952fdf35b5f92784dfb98d064403c3c059fb55dff"), Height(5848264), {ConsensusBranchIdHex(ConsensusBranchId(1537743641)): NetworkUpgradeInfo { name: Overwinter, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(1991772603)): NetworkUpgradeInfo { name: Sapling, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(733220448)): NetworkUpgradeInfo { name: Blossom, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(4122551051)): NetworkUpgradeInfo { name: Heartwood, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(3925833126)): NetworkUpgradeInfo { name: Canopy, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(3268858036)): NetworkUpgradeInfo { name: Nu5, activation_height: Height(1), status: Active }, ConsensusBranchIdHex(ConsensusBranchId(3370586197)): NetworkUpgradeInfo { name: Nu6, activation_height: Height(1), status: Active }}, TipConsensusBranch { chain_tip: ConsensusBranchIdHex(ConsensusBranchId(3370586197)), next_block: ConsensusBranchIdHex(ConsensusBranchId(3370586197)) })

[idky137]

• Relevant tests is in Read state service #140