bug: Coinbase funds are not spendable in zebra regtest mode.

[idky137]

What happened?

I expected to see this happen:

Funds received from mining rewards should be spendable by the wallet as is the case when using zcashd.

Instead, this happened:

Any transactions containing coinbase funds are rejected by zebra.

The following error is returned in zingolib's (wallet) log :
2024-12-11T23:49:16.858270Z ERROR zingolib::utils::txid: server returned invalid txid Invalid character 'i' at position 2

The following error is returned in zebrad's log:
2024-12-11T23:49:16.857789Z INFO zebra_rpc::server::rpc_call_compatibility: RPC error: Server error: failed to validate tx: WtxId("private"), error: transaction did not pass consensus validation: transaction uses an incorrect consensus branch id in call: method = "sendrawtransaction", params = Array([String("050000800a27a726b4d0d6c2000000008e00000002e81f75bc5edf9c3500b28dd23ac213efd9deb602ed6...

What were you doing when the issue happened?

Order of operations in test:

1. Launch Zebra (regtest mode).
2. Launch Lightwalletd.
3. Launch Zingolib client.
4. Generate 101 blocks.
5. Shield Funds to Orchard.
6. Generate 100 Blocks.
7. Send Shielded Funds.

A test showing this behaviour (lightwalletd_zebrad_basic_send) can be found here: [https://github.com/idky137/zcash-local-net/blob/fcd0298ffb876570224de6dc2acdd44f7d3f205f/tests/integration.rs#L385].

Similar tests using Zcashd and Zaino can be found in the same file for comparison.

Zebra logs

2024-12-11T23:48:20.890119Z  INFO zebrad::components::tracing::component: started tracing component filter="info" TRACING_STATIC_MAX_LEVEL=LevelFilter::INFO LOG_STATIC_MAX_LEVEL=Info
2024-12-11T23:48:20.890129Z  INFO zebrad::components::tracing::component: set 'tracing.progress_bar ="summary"' in zebrad.toml to activate progress bars
2024-12-11T23:48:20.890130Z  INFO zebrad::application: Diagnostic Metadata:
version: 2.1.0+3.g568b25e
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: 568b25e
commit timestamp: 2024-12-11T16:29:44.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-11T23:48:20.890131Z  INFO zebrad::application: loaded zebrad config config_path=Some("/tmp/.tmp3XLNTp/zebrad.toml") config=ZebradConfig { consensus: Config { checkpoint_sync: true }, metrics: Config { endpoint_addr: None }, network: Config { listen_addr: 127.0.0.1:24306, 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/.tmpSoBCc7", 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:20163), indexer_listen_addr: None, parallel_cpu_threads: 0, debug_force_finished_sync: false, cookie_dir: "/tmp/.tmpSoBCc7", 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-11T23:48:20.890169Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::application: initialized rayon thread pool for CPU-bound tasks num_threads=16
2024-12-11T23:48:20.891453Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: Starting zebrad
2024-12-11T23:48:20.891501Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: initializing node state
2024-12-11T23:48:20.891531Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: opening database, this may take a few minutes
2024-12-11T23:48:20.891626Z  WARN zebra_state::service::finalized_state::disk_db: could not canonicalize "/tmp/.tmpSoBCc7/state/v25/regtest": No such file or directory (os error 2)
2024-12-11T23:48:20.891638Z  INFO zebra_state::service::finalized_state::disk_format::upgrade: creating new database with the current format running_version=26.0.0
2024-12-11T23:48:20.891900Z  INFO zebra_state::service::finalized_state::disk_db: the open file limit is high enough for Zebra current_limit=1048576 min_limit=512 ideal_limit=1024
2024-12-11T23:48:20.922525Z  INFO zebra_state::service::finalized_state::disk_db: Opened Zebra state cache at /tmp/.tmpSoBCc7/state/v26/regtest
2024-12-11T23:48:20.922572Z  INFO zebra_state::service::finalized_state: loaded Zebra state cache tip=None
2024-12-11T23:48:20.922627Z  INFO zebra_state::service: starting legacy chain check
2024-12-11T23:48:20.922634Z  INFO zebra_state::service: cached state consensus branch is valid: no legacy chain found
2024-12-11T23:48:20.922681Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: logging database metrics on startup
2024-12-11T23:48:20.922704Z  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-11T23:48:20.922751Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::service::finalized_state::disk_db: the open file limit is high enough for Zebra current_limit=1048576 min_limit=512 ideal_limit=1024
2024-12-11T23:48:20.923494Z  INFO zebra_state::service::finalized_state::disk_format::upgrade: database format is valid running_version=26.0.0 inital_disk_version=None
2024-12-11T23:48:20.923559Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Database Disk Size: 0 B
2024-12-11T23:48:20.923570Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Live Data Disk Size: 0 B
2024-12-11T23:48:20.923573Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::service::finalized_state::disk_db: Total Database Memory Size: 49.2 KB
2024-12-11T23:48:20.923604Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: initializing network
2024-12-11T23:48:20.923640Z  INFO {zebrad="568b25e" net="Regtest"}:open_listener{addr=127.0.0.1:24306}: zebra_network::peer_set::initialize: Trying to open Zcash protocol endpoint at 127.0.0.1:24306...
2024-12-11T23:48:20.923680Z  INFO {zebrad="568b25e" net="Regtest"}:open_listener{addr=127.0.0.1:24306}: zebra_network::peer_set::initialize: Opened Zcash protocol endpoint at 127.0.0.1:24306
2024-12-11T23:48:20.923716Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_network::address_book_updater: starting the address book updater
2024-12-11T23:48:20.923886Z  INFO {zebrad="568b25e" 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-11T23:48:20.923892Z  INFO {zebrad="568b25e" 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-11T23:48:20.923921Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_network::peer_set::initialize: sending initial request for peers active_initial_peer_count=0
2024-12-11T23:48:20.923932Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: initializing verifiers
2024-12-11T23:48:20.923938Z  INFO {zebrad="568b25e" 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-11T23:48:20.923960Z  INFO {zebrad="568b25e" 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-11T23:48:20.924109Z  INFO {zebrad="568b25e" 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-11T23:48:20.924115Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: initializing syncer
2024-12-11T23:48:20.924135Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: initializing mempool
2024-12-11T23:48:20.924143Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: fully initializing inbound peer request handler
2024-12-11T23:48:20.924145Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning RPC server
2024-12-11T23:48:20.924148Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_rpc::server: Trying to open RPC endpoint at 127.0.0.1:20163...
2024-12-11T23:48:20.924190Z  INFO {zebrad="568b25e" 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-11T23:48:20.924194Z  INFO {zebrad="568b25e" 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-11T23:48:20.969673Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_rpc::server: Opened RPC endpoint at 127.0.0.1:20163
2024-12-11T23:48:20.969766Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning block gossip task
2024-12-11T23:48:20.969779Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning mempool queue checker task
2024-12-11T23:48:20.969782Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning mempool transaction gossip task
2024-12-11T23:48:20.969785Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning delete old databases task
2024-12-11T23:48:20.969794Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning progress logging task
2024-12-11T23:48:20.969797Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning end of support checking task
2024-12-11T23:48:20.969796Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::sync::gossip: initializing block gossip task
2024-12-11T23:48:20.969807Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool::queue_checker: initializing mempool queue checker task
2024-12-11T23:48:20.969811Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning mempool crawler task
2024-12-11T23:48:20.969804Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::config: checking for old database versions db_kind="state"
2024-12-11T23:48:20.969815Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawning syncer task
2024-12-11T23:48:20.969824Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool::gossip: initializing transaction gossip task
2024-12-11T23:48:20.969829Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::sync::end_of_support: Starting end of support task
2024-12-11T23:48:20.969833Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool::crawler: initializing mempool crawler task
2024-12-11T23:48:20.969852Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::sync::progress: initial sync is waiting to download the genesis block sync_percent=0.000 % current_height=None
2024-12-11T23:48:20.969893Z  INFO {zebrad="568b25e" net="Regtest"}: zebra_state::config: finished old database version cleanup task
2024-12-11T23:48:20.969946Z  INFO {zebrad="568b25e" net="Regtest"}:checkpoint: zebra_consensus::checkpoint: verified checkpoint range block_count=1 current_range=(Unbounded, Included(Height(0)))
2024-12-11T23:48:20.969954Z  INFO {zebrad="568b25e" net="Regtest"}:checkpoint: zebra_consensus::checkpoint: verified final checkpoint: starting full validation final_checkpoint_height=Height(0)
2024-12-11T23:48:21.028391Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::commands::start: spawned initial Zebra tasks
2024-12-11T23:48:25.971215Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: enabling mempool for debugging best_tip_height=Height(0) enable_at_height=Height(0)
2024-12-11T23:48:25.971232Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: activating mempool: Zebra is close to the tip tip_height=Height(0)
2024-12-11T23:48:30.970630Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::sync::end_of_support: Release always valid in Testnet
2024-12-11T23:48:36.038926Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("6095670f4d9a72fec27443be51da4b330db4a494be5dac413d27e4a412bacae2") block_height="1"
2024-12-11T23:48:40.975585Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: resetting mempool: switched best chain, skipped blocks, or activated network upgrade tip_height=Height(1)
2024-12-11T23:48:40.975613Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: enabling mempool for debugging best_tip_height=Height(1) enable_at_height=Height(0)
2024-12-11T23:48:40.975616Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: activating mempool: Zebra is close to the tip tip_height=Height(1)
2024-12-11T23:48:40.975620Z  INFO {zebrad="568b25e" net="Regtest"}: zebrad::components::mempool: re-verifying mempool transactions after a chain fork transactions=0
2024-12-11T23:48:41.374330Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("437372d8a9bf638b459b59a952fdf35b5f92784dfb98d064403c3c059fb55dff") block_height="2"

...

2024-12-11T23:48:41.493397Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("e71a1ecb1b59f04ebd56bc17d17a27130ab119efb3c50dccd8886bba033a49ba") block_height="101"
2024-12-11T23:49:16.857789Z  INFO zebra_rpc::server::rpc_call_compatibility: RPC error: Server error: failed to validate tx: WtxId("private"), error: transaction did not pass consensus validation: transaction uses an incorrect consensus branch id in call: method = "sendrawtransaction", params = Array([String("050000800a27a726b4d0d6c2000000008e00000002e81f75bc5edf9c3500b28dd23ac213efd9deb602ed6...
2024-12-11T23:49:16.862062Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("fe0cc6e73aac675f18043227db81a989371db0ad3ff1d68adbadd3b1a556dc3f") block_height="102"

...

2024-12-11T23:49:16.995450Z  INFO zebra_rpc::methods::get_block_template_rpcs: submit block accepted block_hash=block::Hash("34ce6b843cdce4624ae16ab2f78fc0f37e9077ce03f1bab8df45b71b44c0d48a") block_height="201"

Thank you for running a regtest zebrad 2.1.0+3.g568b25e node!
You're helping to strengthen the network and contributing to a social good :)

Zebra Version

zebrad 2.1.0

Which operating systems does the issue happen on?

• Linux
• macOS
• Windows
• Other OS

OS details

Linux works 6.1.0-28-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.119-1 (2024-11-22) x86_64 GNU/Linux

Additional information

Before [https://github.com//pull/9063] merged a different error was being hit where any block containing transactions spending coinbase funds were rejected. This is no longer the case but the transaction withing the blocks still are.

*NOTE: When the same test is run with Zaino instead of Lightwalletd the Following Error is returned by Zaino:
called Result::unwrap()on anErrvalue: CompleteAndBroadcast(Broadcast(Broadcast("Send Error: status: Internal, message: \"Error: JsonRPC Client Error: Error: Serialization/Deserialization Error: missing fieldresult at line 1 column 202\", details: [], metadata: MetadataMap { headers: {\"content-type\": \"application/grpc\", \"date\": \"Fri, 06 Dec 2024 15:36:08 GMT\", \"content-length\": \"0\"} }")))

[mpguerra]

Thank you for reporting! I think this may be the same as #8478 which is on our current Sprint and @arya2 has been working on already.

Once @arya2 confirms we can close one of the issues as a duplicate

[arya2]

Transparent outputs in transactions spending coinbase inputs is now allowed on Regtest in #9085, but the logs in this issue indicate that the rejected transactions are using the wrong consensus branch id. Switching from NU6 to NU5 or NU5 to NU6 could be a quick fix.

[idky137]

Thanks for looking into this. One of our wallet devs will have a look at this this week.

Its interesting that this works for zcashd but not zebrad though, but maybe there are stronger tx acceptance rules in zebrad?

[idky137]

Hey,

I think we may have solved this, I'm not sure 100% what it was exactly but there was a part of zcash-local-net that had not been updated for NU6. Im still running tests but so far everything is looking good.

I'm sorry if you have wasted time looking into this for us.

I think it has possibly highlighted some bugs in other codebases though.

We have run this test using lwd-zcashd, lwd-zebrad, zaino-zcashd and zaino-zebrad and found the following behaviour:

• zcashd accepts the tx where zebrad does not.
• lwd does not pick up on the rejected tx from zebra, but it returns an incorrect txid which the wallet then discards.
• zaino picks up the rejected tx but returns the underlying server error instead of converting it to a tonic status.

I will post this in the discord as it seams less to do with zebra, and will be adding a fix for zaino's bad behaviour.