T3. add(test): check for failure messages in lightwalletd and Zebra logs (#3903)

* Make command test matching code accept generic regexes

And add generic conversions to regexes.

* Document test command structs

* Support matching multiple regexes internally in the test command

* Make it easier to call the generic regex methods

* Add a missing API usage comment

* Fix a potential hang in test child error reports

* Revert Option<Child> process handling

* Revert "Revert Option<Child> process handling"

This reverts commit 2af30086858d104dcb0ec87383996c36bcaa7371.

* Add a set of failure regexes to test command output

* Allow debug-printing TestChild again

* When the child is dropped, check any remaining output

* Document a wait_with_output edge case

* Improve failure regex panic output

* Improve builder ergonomics

* Add internal tests for failure regex panics

It would be easy to disable these panics, and never realise.

* Add some module structure TODOs

* Stop panicking if the child process has already been taken

* Add test APIs for consuming child output lines

* Fix a hang on child process drop

* Handle output being already taken in wait_with_output

And document some edge cases we don't handle yet

* Use bash's read command in the TestChild stderr test

And check the actual command we're using to see if it errors.

* Pretty print full failure regex list

* Add the test child command line to the failure regex logs

* Simplify the sync_until test code

* Check logs for failure messages in lightwalletd integration tests

* Add more TODOs and improve comments

* Allow missing branch ID 00000000 provided by zcashd

zebrad/tests/acceptance.rs

@@ -659,7 +659,7 @@ fn full_sync_testnet() {
 /// The timeout is specified using an environment variable, with the name configured by the
 /// `timeout_argument_name` parameter. The value of the environment variable must the number of
 /// minutes specified as an integer.
-fn full_sync_test(network: Network, timeout_argument_name: &'static str) -> Result<()> {
+fn full_sync_test(network: Network, timeout_argument_name: &str) -> Result<()> {
     let timeout_argument: Option<u64> = env::var(timeout_argument_name)
         .ok()
         .and_then(|timeout_string| timeout_string.parse().ok());
@@ -678,8 +678,7 @@ fn full_sync_test(network: Network, timeout_argument_name: &'static str) -> Resu
             // TODO: if full validation performance improves, do another test with checkpoint_sync off
             true,
             true,
-        )
+        )?;
-        .map(|_| ())
     } else {
         tracing::info!(
             ?network,
@@ -687,10 +686,10 @@ fn full_sync_test(network: Network, timeout_argument_name: &'static str) -> Resu
              set the {:?} environmental variable to run the test",
             timeout_argument_name,
         );
+    }
 
     Ok(())
 }
-}
 
 fn create_cached_database(network: Network) -> Result<()> {
     let height = network.mandatory_checkpoint_height();
@@ -989,6 +988,95 @@ async fn rpc_endpoint() -> Result<()> {
     Ok(())
 }
 
+/// Failure log messages for any process, from the OS or shell.
+const PROCESS_FAILURE_MESSAGES: &[&str] = &[
+    // Linux
+    "Aborted",
+    // macOS / BSDs
+    "Abort trap",
+    // TODO: add other OS or C library errors?
+];
+
+/// Failure log messages from Zebra.
+const ZEBRA_FAILURE_MESSAGES: &[&str] = &[
+    // Rust-specific panics
+    "The application panicked",
+    // RPC port errors
+    "Unable to start RPC server",
+    // TODO: disable if this actually happens during test zebrad shutdown
+    "Stopping RPC endpoint",
+    // Missing RPCs in zebrad logs (this log is from PR #3860)
+    //
+    // TODO: temporarily disable until enough RPCs are implemented, if needed
+    "Received unrecognized RPC request",
+    // RPC argument errors: parsing and data
+    //
+    // These logs are produced by jsonrpc_core inside Zebra,
+    // but it doesn't log them yet.
+    //
+    // TODO: log these errors in Zebra, and check for them in the Zebra logs?
+    "Invalid params",
+    "Method not found",
+];
+
+/// Failure log messages from lightwalletd.
+const LIGHTWALLETD_FAILURE_MESSAGES: &[&str] = &[
+    // Go-specific panics
+    "panic:",
+    // Missing RPCs in lightwalletd logs
+    // TODO: temporarily disable until enough RPCs are implemented, if needed
+    "unable to issue RPC call",
+    // RPC response errors: parsing and data
+    //
+    // jsonrpc_core error messages from Zebra,
+    // received by lightwalletd and written to its logs
+    "Invalid params",
+    "Method not found",
+    // Early termination
+    //
+    // TODO: temporarily disable until enough RPCs are implemented, if needed
+    "Lightwalletd died with a Fatal error",
+    // Go json package error messages:
+    "json: cannot unmarshal",
+    "into Go value of type",
+    // lightwalletd RPC error messages from:
+    // https://github.com/adityapk00/lightwalletd/blob/master/common/common.go
+    "block requested is newer than latest block",
+    "Cache add failed",
+    "error decoding",
+    "error marshaling",
+    "error parsing JSON",
+    "error reading JSON response",
+    "error with",
+    // We expect these errors when lightwalletd reaches the end of the zebrad cached state
+    // "error requesting block: 0: Block not found",
+    // "error zcashd getblock rpc",
+    "received overlong message",
+    "received unexpected height block",
+    "Reorg exceeded max",
+    "unable to issue RPC call",
+    // Missing fields for each specific RPC
+    //
+    // get_block_chain_info
+    //
+    // TODO: enable these checks after PR #3891 merges
+    //
+    // invalid sapling height
+    //"Got sapling height 0",
+    // missing BIP70 chain name, should be "main" or "test"
+    //" chain  ",
+    // missing branchID, should be 8 hex digits
+    //" branchID \"",
+    //
+    // TODO: complete this list for each RPC with fields?
+    // get_info
+    // get_raw_transaction
+    // z_get_tree_state
+    // get_address_txids
+    // get_address_balance
+    // get_address_utxos
+];
+
 /// Launch `zebrad` with an RPC port, and make sure `lightwalletd` works with Zebra.
 ///
 /// This test only runs when the `ZEBRA_TEST_LIGHTWALLETD` env var is set.
@@ -1011,7 +1099,16 @@ fn lightwalletd_integration() -> Result<()> {
     let mut config = random_known_rpc_port_config()?;
 
     let zdir = testdir()?.with_config(&mut config)?;
-    let mut zebrad = zdir.spawn_child(&["start"])?.with_timeout(LAUNCH_DELAY);
+    let mut zebrad = zdir
+        .spawn_child(&["start"])?
+        .with_timeout(LAUNCH_DELAY)
+        .with_failure_regex_iter(
+            // TODO: replace with a function that returns the full list and correct return type
+            ZEBRA_FAILURE_MESSAGES
+                .iter()
+                .chain(PROCESS_FAILURE_MESSAGES)
+                .cloned(),
+        );
 
     // Wait until `zebrad` has opened the RPC endpoint
     zebrad.expect_stdout_line_matches(
@@ -1027,7 +1124,15 @@ fn lightwalletd_integration() -> Result<()> {
     // Launch the lightwalletd process
     let result = ldir.spawn_lightwalletd_child(&[]);
     let (lightwalletd, zebrad) = zebrad.kill_on_error(result)?;
-    let mut lightwalletd = lightwalletd.with_timeout(LIGHTWALLETD_DELAY);
+    let mut lightwalletd = lightwalletd
+        .with_timeout(LIGHTWALLETD_DELAY)
+        .with_failure_regex_iter(
+            // TODO: replace with a function that returns the full list and correct return type
+            LIGHTWALLETD_FAILURE_MESSAGES
+                .iter()
+                .chain(PROCESS_FAILURE_MESSAGES)
+                .cloned(),
+        );
 
     // Wait until `lightwalletd` has launched
     let result = lightwalletd.expect_stdout_line_matches("Starting gRPC server");
@@ -1036,6 +1141,9 @@ fn lightwalletd_integration() -> Result<()> {
     // Check that `lightwalletd` is calling the expected Zebra RPCs
 
     // getblockchaininfo
+    //
+    // TODO: add correct sapling height, chain, branchID (PR #3891)
+    //       add "Waiting for zcashd height to reach Sapling activation height"
     let result = lightwalletd.expect_stdout_line_matches("Got sapling height");
     let (_, zebrad) = zebrad.kill_on_error(result)?;