1. add(ci): Add a Zebra cached state update test, fix lightwalletd tests (#4813)

* Fix clippy::let_and_return

* Increase lightwalletd test timeouts for zebrad slowness

* Add a `zebrad_update_sync()` test, that update syncs Zebra without lightwalletd

* Run the zebrad-update-sync test in CI

* Add extra zebrad time to workaround lightwalletd bugs

.github/workflows/continous-integration-docker.patch.yml

@@ -63,6 +63,12 @@ jobs:
     steps:
       - run: 'echo "No build required"'
 
+  test-update-sync:
+    name: Zebra tip update / Run update-to-tip test
+    runs-on: ubuntu-latest
+    steps:
+      - run: 'echo "No build required"'
+
   lightwalletd-rpc-test:
     name: Zebra tip JSON-RPC / Run fully-synced-rpc test
     runs-on: ubuntu-latest

.github/workflows/continous-integration-docker.yml

@@ -309,6 +309,33 @@ jobs:
       disk_suffix: tip
       height_grep_text: 'current_height.*=.*Height'
 
+  # Test that Zebra can sync to the chain tip, using a cached Zebra tip state,
+  # without launching `lightwalletd`.
+  #
+  # Runs:
+  # - after every PR is merged to `main`
+  # - on every PR update
+  #
+  # If the state version has changed, waits for the new cached state to be created.
+  # Otherwise, if the state rebuild was skipped, runs immediately after the build job.
+  test-update-sync:
+    name: Zebra tip update
+    needs: test-full-sync
+    uses: ./.github/workflows/deploy-gcp-tests.yml
+    if: ${{ !cancelled() && !failure() && github.event.inputs.regenerate-disks != 'true' && github.event.inputs.run-full-sync != 'true' }}
+    with:
+      app_name: zebrad
+      test_id: update-to-tip
+      test_description: Test syncing to tip with a Zebra tip state
+      test_variables: '-e TEST_UPDATE_SYNC=1 -e ZEBRA_FORCE_USE_COLOR=1 -e ZEBRA_CACHED_STATE_DIR=/var/cache/zebrad-cache'
+      needs_zebra_state: true
+      # TODO: do we want to update the disk on every PR, to increase CI speed?
+      saves_to_disk: false
+      disk_suffix: tip
+      root_state_path: '/var/cache'
+      # TODO: do we also want to test the `zebrad` part of the `lwd-cache`? (But not update it.)
+      zebra_state_dir: 'zebrad-cache'
+
   # Test that Zebra can answer a synthetic RPC call, using a cached Zebra tip state
   #
   # Runs:
@@ -410,6 +437,7 @@ jobs:
       test_variables: '-e TEST_LWD_UPDATE_SYNC=1 -e ZEBRA_TEST_LIGHTWALLETD=1 -e ZEBRA_FORCE_USE_COLOR=1 -e ZEBRA_CACHED_STATE_DIR=/var/cache/zebrad-cache -e LIGHTWALLETD_DATA_DIR=/var/cache/lwd-cache'
       needs_zebra_state: true
       needs_lwd_state: true
+      # TODO: do we want to update the disk on every PR, to increase CI speed?
       saves_to_disk: false
       disk_prefix: lwd-cache
       disk_suffix: tip

docker/entrypoint.sh

@@ -38,6 +38,12 @@ case "$1" in
             cargo test --locked --release --features "test_sync_to_mandatory_checkpoint_${NETWORK,,},lightwalletd-grpc-tests" --package zebrad --test acceptance -- --nocapture --include-ignored "sync_to_mandatory_checkpoint_${NETWORK,,}"
             # TODO: replace with $ZEBRA_CACHED_STATE_DIR in Rust and workflows
             ls -lh "/zebrad-cache"/*/* || (echo "No /zebrad-cache/*/*"; ls -lhR "/zebrad-cache" | head -50 || echo "No /zebrad-cache directory")
+        elif [[ "$TEST_UPDATE_SYNC" -eq "1" ]]; then
+            # Run a Zebra sync starting at the cached tip, and syncing to the latest tip.
+            #
+            # List directory used by test
+            ls -lh "$ZEBRA_CACHED_STATE_DIR"/*/* || (echo "No $ZEBRA_CACHED_STATE_DIR/*/*"; ls -lhR  "$ZEBRA_CACHED_STATE_DIR" | head -50 || echo "No $ZEBRA_CACHED_STATE_DIR directory")
+            cargo test --locked --release --features lightwalletd-grpc-tests --package zebrad --test acceptance -- --nocapture --include-ignored zebrad_update_sync
         elif [[ "$TEST_CHECKPOINT_SYNC" -eq "1" ]]; then
             # Run a Zebra sync starting at the cached mandatory checkpoint, and syncing past it.
             #

zebra-network/src/peer/handshake.rs

@@ -1137,7 +1137,7 @@ async fn send_periodic_heartbeats_with_shutdown_handle(
     // slow rate, and shutdown is a oneshot. If both futures
     // are ready, we want the shutdown to take priority over
     // sending a useless heartbeat.
-    let result = match future::select(shutdown_rx, heartbeat_run_loop).await {
+    match future::select(shutdown_rx, heartbeat_run_loop).await {
         Either::Left((Ok(CancelHeartbeatTask), _unused_run_loop)) => {
             tracing::trace!("shutting down because Client requested shut down");
             handle_heartbeat_shutdown(
@@ -1164,9 +1164,7 @@ async fn send_periodic_heartbeats_with_shutdown_handle(
 
             result
         }
-    };
+    }
-
-    result
 }
 
 /// Send periodical heartbeats to `server_tx`, and update the peer status through

zebrad/tests/acceptance.rs

@@ -1199,10 +1199,17 @@ fn lightwalletd_integration() -> Result<()> {
     lightwalletd_integration_test(LaunchWithEmptyState)
 }
 
-/// Make sure `lightwalletd` can sync from Zebra, in update sync mode.
+/// Make sure `zebrad` can sync from peers, but don't actually launch `lightwalletd`.
 ///
-/// If `LIGHTWALLETD_DATA_DIR` is set, runs a quick sync, then a full sync.
+/// This test only runs when the `ZEBRA_CACHED_STATE_DIR` env var is set.
-/// If `LIGHTWALLETD_DATA_DIR` is not set, just runs a full sync.
+///
+/// This test might work on Windows.
+#[test]
+fn zebrad_update_sync() -> Result<()> {
+    lightwalletd_integration_test(UpdateZebraCachedStateNoRpc)
+}
+
+/// Make sure `lightwalletd` can sync from Zebra, in update sync mode.
 ///
 /// This test only runs when the `ZEBRA_TEST_LIGHTWALLETD`,
 /// `ZEBRA_CACHED_STATE_DIR`, and `LIGHTWALLETD_DATA_DIR` env vars are set.
@@ -1249,6 +1256,9 @@ fn lightwalletd_full_sync() -> Result<()> {
 async fn lightwalletd_test_suite() -> Result<()> {
     lightwalletd_integration_test(LaunchWithEmptyState)?;
 
+    // Only runs when ZEBRA_CACHED_STATE_DIR is set.
+    lightwalletd_integration_test(UpdateZebraCachedStateNoRpc)?;
+
     // Only runs when ZEBRA_CACHED_STATE_DIR is set.
     // When manually running the test suite, allow cached state in the full sync test.
     lightwalletd_integration_test(FullSyncFromGenesis {
@@ -1271,26 +1281,29 @@ async fn lightwalletd_test_suite() -> Result<()> {
 
 /// Run a lightwalletd integration test with a configuration for `test_type`.
 ///
-/// Set `allow_cached_state_for_full_sync` to speed up manual full sync tests.
+/// Set `FullSyncFromGenesis { allow_lightwalletd_cached_state: true }` to speed up manual full sync tests.
 ///
 /// The random ports in this test can cause [rare port conflicts.](#Note on port conflict)
-#[cfg(not(target_os = "windows"))]
 fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()> {
     zebra_test::init();
 
     // Skip the test unless the user specifically asked for it
-    if zebra_skip_lightwalletd_tests() {
+    //
+    // TODO: pass test_type to zebra_skip_lightwalletd_tests() and check for lightwalletd launch in there
+    if test_type.launches_lightwalletd() && zebra_skip_lightwalletd_tests() {
         return Ok(());
     }
 
-    // Get the zebrad and lightwalletd configs
+    // TODO: split the zebrad and lightwalletd launches and checks into separate functions?
+
+    // Get the zebrad config
 
     // Handle the Zebra state directory based on the test type:
     // - LaunchWithEmptyState: ignore the state directory
-    // - FullSyncFromGenesis & UpdateCachedState:
+    // - FullSyncFromGenesis, UpdateCachedState, UpdateZebraCachedStateNoRpc:
     //   skip the test if it is not available, timeout if it is not populated
 
-    // Write a configuration that has RPC listen_addr set.
+    // Write a configuration that has RPC listen_addr set (if needed).
     // If the state path env var is set, use it in the config.
     let config = if let Some(config) =
         test_type.zebrad_config("lightwalletd_integration_test".to_string())
@@ -1301,7 +1314,7 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
     };
 
     // Handle the lightwalletd state directory based on the test type:
-    // - LaunchWithEmptyState: ignore the state directory
+    // - LaunchWithEmptyState, UpdateZebraCachedStateNoRpc: ignore the state directory
     // - FullSyncFromGenesis: use it if available, timeout if it is already populated
     // - UpdateCachedState: skip the test if it is not available, timeout if it is not populated
     let lightwalletd_state_path =
@@ -1321,9 +1334,6 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
     // Get the lists of process failure logs
     let (zebrad_failure_messages, zebrad_ignore_messages) = test_type.zebrad_failure_messages();
 
-    let (lightwalletd_failure_messages, lightwalletd_ignore_messages) =
-        test_type.lightwalletd_failure_messages();
-
     // Launch zebrad
     let zdir = testdir()?.with_exact_config(&config)?;
     let mut zebrad = zdir
@@ -1339,17 +1349,20 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
         zebrad.expect_stdout_line_matches("loaded Zebra state cache .*tip.*=.*None")?;
     }
 
+    // Launch lightwalletd, if needed
+    let mut lightwalletd = if test_type.launches_lightwalletd() {
         // Wait until `zebrad` has opened the RPC endpoint
         zebrad.expect_stdout_line_matches(regex::escape(
             format!("Opened RPC endpoint at {}", config.rpc.listen_addr.unwrap()).as_str(),
         ))?;
 
-    // Launch lightwalletd
-
         // Write a fake zcashd configuration that has the rpcbind and rpcport options set
         let ldir = testdir()?;
         let ldir = ldir.with_lightwalletd_config(config.rpc.listen_addr.unwrap())?;
 
+        let (lightwalletd_failure_messages, lightwalletd_ignore_messages) =
+            test_type.lightwalletd_failure_messages();
+
         // Launch the lightwalletd process
         let lightwalletd = if test_type == LaunchWithEmptyState {
             ldir.spawn_lightwalletd_child(None, args![])?
@@ -1404,8 +1417,9 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
         // lightwalletd will keep retrying getblock.
         if !test_type.allow_lightwalletd_cached_state() {
             if test_type.needs_zebra_cached_state() {
-            lightwalletd
+                lightwalletd.expect_stdout_line_matches(
-                .expect_stdout_line_matches("([Aa]dding block to cache)|([Ww]aiting for block)")?;
+                    "([Aa]dding block to cache)|([Ww]aiting for block)",
+                )?;
             } else {
                 lightwalletd.expect_stdout_line_matches(regex::escape(
                     "Waiting for zcashd height to reach Sapling activation height (419200)",
@@ -1413,11 +1427,17 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
             }
         }
 
-    if matches!(test_type, UpdateCachedState | FullSyncFromGenesis { .. }) {
+        Some(lightwalletd)
+    } else {
+        None
+    };
+
+    if test_type.needs_zebra_cached_state() {
         // Wait for Zebra to sync its cached state to the chain tip
         zebrad.expect_stdout_line_matches(SYNC_FINISHED_REGEX)?;
 
         // Wait for lightwalletd to sync some blocks
+        if let Some(ref mut lightwalletd) = lightwalletd {
             lightwalletd
                 .expect_stdout_line_matches("([Aa]dding block to cache)|([Ww]aiting for block)")?;
 
@@ -1438,12 +1458,14 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
                     "([Aa]dding block to cache 1[7-9][0-9]{5})|([Ww]aiting for block)",
                 );
                 if log_result.is_err() {
+                    // This error takes up about 100 lines, and looks like a panic message
                     tracing::warn!(
-                    ?log_result,
+                        multi_line_error = ?log_result,
                         "ignoring a lightwalletd test failure, to work around a lightwalletd hang bug",
                     );
                 }
             }
+        }
 
         // Check Zebra is still at the tip (also clears and prints Zebra's logs)
         zebrad.expect_stdout_line_matches(SYNC_FINISHED_REGEX)?;
@@ -1455,28 +1477,36 @@ fn lightwalletd_integration_test(test_type: LightwalletdTestType) -> Result<()>
         //
         // TODO: re-enable this code when lightwalletd hangs are fixed
         if cfg!(lightwalletd_hang_fix) {
+            if let Some(ref mut lightwalletd) = lightwalletd {
                 lightwalletd.expect_stdout_line_matches(regex::escape(
                     "Block hash changed, clearing mempool clients",
                 ))?;
-            lightwalletd.expect_stdout_line_matches(regex::escape("Adding new mempool txid"))?;
+                lightwalletd
+                    .expect_stdout_line_matches(regex::escape("Adding new mempool txid"))?;
+            }
         }
     }
 
     // Cleanup both processes
-    lightwalletd.kill()?;
+    //
-    zebrad.kill()?;
-
-    let lightwalletd_output = lightwalletd.wait_with_output()?.assert_failure()?;
-    let zebrad_output = zebrad.wait_with_output()?.assert_failure()?;
-
     // If the test fails here, see the [note on port conflict](#Note on port conflict)
     //
     // zcash/lightwalletd exits by itself, but
     // adityapk00/lightwalletd keeps on going, so it gets killed by the test harness.
+    zebrad.kill()?;
+
+    if let Some(mut lightwalletd) = lightwalletd {
+        lightwalletd.kill()?;
+
+        let lightwalletd_output = lightwalletd.wait_with_output()?.assert_failure()?;
 
         lightwalletd_output
             .assert_was_killed()
             .wrap_err("Possible port conflict. Are there other acceptance tests running?")?;
+    }
+
+    let zebrad_output = zebrad.wait_with_output()?.assert_failure()?;
+
     zebrad_output
         .assert_was_killed()
         .wrap_err("Possible port conflict. Are there other acceptance tests running?")?;

zebrad/tests/common/launch.rs

@@ -45,7 +45,11 @@ pub const BETWEEN_NODES_DELAY: Duration = Duration::from_secs(2);
 /// The amount of time we wait for lightwalletd to update to the tip.
 ///
 /// The cached tip can be a few days old, and Zebra needs time to activate its mempool.
-pub const LIGHTWALLETD_UPDATE_TIP_DELAY: Duration = Duration::from_secs(20 * 60);
+///
+/// Currently, `zebrad` syncs are slower than `lightwalletd` syncs, so we re-use its timeout.
+///
+/// TODO: reduce to 20 minutes when `zebrad` sync performance improves
+pub const LIGHTWALLETD_UPDATE_TIP_DELAY: Duration = LIGHTWALLETD_FULL_SYNC_TIP_DELAY;
 
 /// The amount of time we wait for lightwalletd to do a full sync to the tip.
 ///
@@ -53,6 +57,14 @@ pub const LIGHTWALLETD_UPDATE_TIP_DELAY: Duration = Duration::from_secs(20 * 60)
 /// and Zebra needs time to activate its mempool.
 pub const LIGHTWALLETD_FULL_SYNC_TIP_DELAY: Duration = Duration::from_secs(90 * 60);
 
+/// The amount of extra time we wait for Zebra to sync to the tip,
+/// after we ignore a lightwalletd failure.
+///
+/// Zebra logs a status entry every minute, so there should be at least 4 in this interval.
+///
+/// TODO: remove this extra time when lightwalletd hangs are fixed
+pub const ZEBRAD_EXTRA_DELAY_FOR_LIGHTWALLETD_WORKAROUND: Duration = Duration::from_secs(5 * 60);
+
 /// Extension trait for methods on `tempfile::TempDir` for using it as a test
 /// directory for `zebrad`.
 pub trait ZebradTestDirExt

zebrad/tests/common/lightwalletd.rs

@@ -28,7 +28,7 @@ use super::{
     },
     launch::{
         ZebradTestDirExt, LIGHTWALLETD_DELAY, LIGHTWALLETD_FULL_SYNC_TIP_DELAY,
-        LIGHTWALLETD_UPDATE_TIP_DELAY,
+        LIGHTWALLETD_UPDATE_TIP_DELAY, ZEBRAD_EXTRA_DELAY_FOR_LIGHTWALLETD_WORKAROUND,
     },
 };
 
@@ -67,7 +67,7 @@ pub fn zebra_skip_lightwalletd_tests() -> bool {
     // TODO: check if the lightwalletd binary is in the PATH?
     //       (this doesn't seem to be implemented in the standard library)
     //
-    // See is_command_available in zebra-test/tests/command.rs for one way to do this.
+    // See is_command_available() in zebra-test/src/tests/command.rs for one way to do this.
 
     if env::var_os(ZEBRA_TEST_LIGHTWALLETD).is_none() {
         // This message is captured by the test runner, use
@@ -236,6 +236,14 @@ pub enum LightwalletdTestType {
     ///
     /// This test requires a cached Zebra and lightwalletd state.
     UpdateCachedState,
+
+    /// Launch `zebrad` and sync it to the tip, but don't launch `lightwalletd`.
+    ///
+    /// If this test fails, the failure is in `zebrad` without RPCs or `lightwalletd`.
+    /// If it succeeds, but the RPC tests fail, the problem is caused by RPCs or `lightwalletd`.
+    ///
+    /// This test requires a cached Zebra state.
+    UpdateZebraCachedStateNoRpc,
 }
 
 impl LightwalletdTestType {
@@ -243,26 +251,36 @@ impl LightwalletdTestType {
     pub fn needs_zebra_cached_state(&self) -> bool {
         match self {
             LaunchWithEmptyState => false,
-            FullSyncFromGenesis { .. } | UpdateCachedState => true,
+            FullSyncFromGenesis { .. } | UpdateCachedState | UpdateZebraCachedStateNoRpc => true,
         }
     }
 
-    /// Does this test need a lightwalletd cached state?
+    /// Does this test launch `lightwalletd`?
+    pub fn launches_lightwalletd(&self) -> bool {
+        match self {
+            UpdateZebraCachedStateNoRpc => false,
+            LaunchWithEmptyState | FullSyncFromGenesis { .. } | UpdateCachedState => true,
+        }
+    }
+
+    /// Does this test need a `lightwalletd` cached state?
     pub fn needs_lightwalletd_cached_state(&self) -> bool {
         match self {
-            LaunchWithEmptyState | FullSyncFromGenesis { .. } => false,
+            LaunchWithEmptyState | FullSyncFromGenesis { .. } | UpdateZebraCachedStateNoRpc => {
+                false
+            }
             UpdateCachedState => true,
         }
     }
 
-    /// Does this test allow a lightwalletd cached state, even if it is not required?
+    /// Does this test allow a `lightwalletd` cached state, even if it is not required?
     pub fn allow_lightwalletd_cached_state(&self) -> bool {
         match self {
             LaunchWithEmptyState => false,
             FullSyncFromGenesis {
                 allow_lightwalletd_cached_state,
             } => *allow_lightwalletd_cached_state,
-            UpdateCachedState => true,
+            UpdateCachedState | UpdateZebraCachedStateNoRpc => true,
         }
     }
 
@@ -287,13 +305,19 @@ impl LightwalletdTestType {
     /// Returns `None` if the test should be skipped,
     /// and `Some(Err(_))` if the config could not be created.
     pub fn zebrad_config(&self, test_name: String) -> Option<Result<ZebradConfig>> {
+        let config = if self.launches_lightwalletd() {
+            random_known_rpc_port_config()
+        } else {
+            default_test_config()
+        };
+
         if !self.needs_zebra_cached_state() {
-            return Some(random_known_rpc_port_config());
+            return Some(config);
         }
 
         let zebra_state_path = self.zebrad_state_path(test_name)?;
 
-        let mut config = match random_known_rpc_port_config() {
+        let mut config = match config {
             Ok(config) => config,
             Err(error) => return Some(Err(error)),
         };
@@ -307,8 +331,17 @@ impl LightwalletdTestType {
         Some(Ok(config))
     }
 
-    /// Returns the lightwalletd state path for this test, if set.
+    /// Returns the `lightwalletd` state path for this test, if set, and if allowed for this test.
     pub fn lightwalletd_state_path(&self, test_name: String) -> Option<PathBuf> {
+        if !self.launches_lightwalletd() {
+            tracing::info!(
+                "running {test_name:?} {self:?} lightwalletd test, \
+                 ignoring any cached state in the {LIGHTWALLETD_DATA_DIR:?} environment variable",
+            );
+
+            return None;
+        }
+
         match env::var_os(LIGHTWALLETD_DATA_DIR) {
             Some(path) => Some(path.into()),
             None => {
@@ -331,21 +364,29 @@ impl LightwalletdTestType {
 
     /// Returns the `zebrad` timeout for this test type.
     pub fn zebrad_timeout(&self) -> Duration {
-        // We use the same timeouts as lightwalletd,
+        let base_timeout = match self {
+            LaunchWithEmptyState => LIGHTWALLETD_DELAY,
+            FullSyncFromGenesis { .. } => LIGHTWALLETD_FULL_SYNC_TIP_DELAY,
+            UpdateCachedState | UpdateZebraCachedStateNoRpc => LIGHTWALLETD_UPDATE_TIP_DELAY,
+        };
+
+        // If lightwalletd hangs and times out, Zebra needs a bit of extra time to finish
+        base_timeout + ZEBRAD_EXTRA_DELAY_FOR_LIGHTWALLETD_WORKAROUND
+    }
+
+    /// Returns the `lightwalletd` timeout for this test type.
+    #[track_caller]
+    pub fn lightwalletd_timeout(&self) -> Duration {
+        if !self.launches_lightwalletd() {
+            panic!("lightwalletd must not be launched in the {self:?} test");
+        }
+
+        // We use the same timeouts for zebrad and lightwalletd,
         // because the tests swap between checking zebrad and lightwalletd.
         match self {
             LaunchWithEmptyState => LIGHTWALLETD_DELAY,
             FullSyncFromGenesis { .. } => LIGHTWALLETD_FULL_SYNC_TIP_DELAY,
-            UpdateCachedState => LIGHTWALLETD_UPDATE_TIP_DELAY,
+            UpdateCachedState | UpdateZebraCachedStateNoRpc => LIGHTWALLETD_UPDATE_TIP_DELAY,
-        }
-    }
-
-    /// Returns the `lightwalletd` timeout for this test type.
-    pub fn lightwalletd_timeout(&self) -> Duration {
-        match self {
-            LaunchWithEmptyState => LIGHTWALLETD_DELAY,
-            FullSyncFromGenesis { .. } => LIGHTWALLETD_FULL_SYNC_TIP_DELAY,
-            UpdateCachedState => LIGHTWALLETD_UPDATE_TIP_DELAY,
         }
     }
 
@@ -375,7 +416,12 @@ impl LightwalletdTestType {
 
     /// Returns `lightwalletd` log regexes that indicate the tests have failed,
     /// and regexes of any failures that should be ignored.
+    #[track_caller]
     pub fn lightwalletd_failure_messages(&self) -> (Vec<String>, Vec<String>) {
+        if !self.launches_lightwalletd() {
+            panic!("lightwalletd must not be launched in the {self:?} test");
+        }
+
         let mut lightwalletd_failure_messages: Vec<String> = LIGHTWALLETD_FAILURE_MESSAGES
             .iter()
             .chain(PROCESS_FAILURE_MESSAGES)