Try to fix flaky temp-base-path-work test (#13505)

* Try to fix flaky `temp-base-path-work` test

The test is most of the time failing when checking if the database path was deleted. The assumption
is that it takes a little bit more time by the OS to actually clean up the temp path under high
load. The pr tries to fix this by checking multiple times if the path was deleted. Besides that it
also ensures that the tests that require the benchmark feature don't fail when compiled without the feature.

* ".git/.scripts/commands/fmt/fmt.sh"

* Capture signals earlier

* Rewrite tests to let them having one big timeout

* Remove unneeded dep

* Update bin/node/cli/tests/common.rs

Co-authored-by: Koute <koute@users.noreply.github.com>

* Review feedback

* Update bin/node/cli/tests/common.rs

Co-authored-by: Anton <anton.kalyaev@gmail.com>

---------

Co-authored-by: command-bot <>
Co-authored-by: Koute <koute@users.noreply.github.com>
Co-authored-by: Anton <anton.kalyaev@gmail.com>

substrate/bin/node/cli/tests/benchmark_pallet_works.rs

@@ -16,6 +16,8 @@
 // You should have received a copy of the GNU General Public License
 // along with this program. If not, see <https://www.gnu.org/licenses/>.
 
+#![cfg(feature = "runtime-benchmarks")]
+
 use assert_cmd::cargo::cargo_bin;
 use std::process::Command;
 

substrate/bin/node/cli/tests/benchmark_storage_works.rs

@@ -16,6 +16,8 @@
 // You should have received a copy of the GNU General Public License
 // along with this program. If not, see <https://www.gnu.org/licenses/>.
 
+#![cfg(feature = "runtime-benchmarks")]
+
 use assert_cmd::cargo::cargo_bin;
 use std::{
 	path::Path,

substrate/bin/node/cli/tests/common.rs

@@ -20,54 +20,26 @@
 
 use assert_cmd::cargo::cargo_bin;
 use nix::{
-	sys::signal::{kill, Signal::SIGINT},
+	sys::signal::{kill, Signal, Signal::SIGINT},
 	unistd::Pid,
 };
 use node_primitives::{Hash, Header};
+use regex::Regex;
 use std::{
 	io::{BufRead, BufReader, Read},
 	ops::{Deref, DerefMut},
-	path::Path,
-	process::{self, Child, Command, ExitStatus},
+	path::{Path, PathBuf},
+	process::{self, Child, Command},
 	time::Duration,
 };
-use tokio::time::timeout;
 
-/// Wait for the given `child` the given number of `secs`.
-///
-/// Returns the `Some(exit status)` or `None` if the process did not finish in the given time.
-pub fn wait_for(child: &mut Child, secs: u64) -> Result<ExitStatus, ()> {
-	let result = wait_timeout::ChildExt::wait_timeout(child, Duration::from_secs(5.min(secs)))
-		.map_err(|_| ())?;
-	if let Some(exit_status) = result {
-		Ok(exit_status)
-	} else {
-		if secs > 5 {
-			eprintln!("Child process taking over 5 seconds to exit gracefully");
-			let result = wait_timeout::ChildExt::wait_timeout(child, Duration::from_secs(secs - 5))
-				.map_err(|_| ())?;
-			if let Some(exit_status) = result {
-				return Ok(exit_status)
-			}
-		}
-		eprintln!("Took too long to exit (> {} seconds). Killing...", secs);
-		let _ = child.kill();
-		child.wait().unwrap();
-		Err(())
-	}
-}
-
-/// Wait for at least n blocks to be finalized within a specified time.
-pub async fn wait_n_finalized_blocks(
-	n: usize,
-	timeout_secs: u64,
-	url: &str,
-) -> Result<(), tokio::time::error::Elapsed> {
-	timeout(Duration::from_secs(timeout_secs), wait_n_finalized_blocks_from(n, url)).await
+/// Run the given `future` and panic if the `timeout` is hit.
+pub async fn run_with_timeout(timeout: Duration, future: impl futures::Future<Output = ()>) {
+	tokio::time::timeout(timeout, future).await.expect("Hit timeout");
 }
 
 /// Wait for at least n blocks to be finalized from a specified node
-pub async fn wait_n_finalized_blocks_from(n: usize, url: &str) {
+pub async fn wait_n_finalized_blocks(n: usize, url: &str) {
 	use substrate_rpc_client::{ws_client, ChainApi};
 
 	let mut built_blocks = std::collections::HashSet::new();
@@ -87,47 +59,55 @@ pub async fn wait_n_finalized_blocks_from(n: usize, url: &str) {
 
 /// Run the node for a while (3 blocks)
 pub async fn run_node_for_a_while(base_path: &Path, args: &[&str]) {
-	let mut cmd = Command::new(cargo_bin("substrate"))
-		.stdout(process::Stdio::piped())
-		.stderr(process::Stdio::piped())
-		.args(args)
-		.arg("-d")
-		.arg(base_path)
-		.spawn()
-		.unwrap();
+	run_with_timeout(Duration::from_secs(60 * 10), async move {
+		let mut cmd = Command::new(cargo_bin("substrate"))
+			.stdout(process::Stdio::piped())
+			.stderr(process::Stdio::piped())
+			.args(args)
+			.arg("-d")
+			.arg(base_path)
+			.spawn()
+			.unwrap();
 
-	let stderr = cmd.stderr.take().unwrap();
+		let stderr = cmd.stderr.take().unwrap();
 
-	let mut child = KillChildOnDrop(cmd);
+		let mut child = KillChildOnDrop(cmd);
 
-	let (ws_url, _) = find_ws_url_from_output(stderr);
+		let ws_url = extract_info_from_output(stderr).0.ws_url;
 
-	// Let it produce some blocks.
-	let _ = wait_n_finalized_blocks(3, 30, &ws_url).await;
+		// Let it produce some blocks.
+		wait_n_finalized_blocks(3, &ws_url).await;
 
-	assert!(child.try_wait().unwrap().is_none(), "the process should still be running");
+		child.assert_still_running();
 
-	// Stop the process
-	kill(Pid::from_raw(child.id().try_into().unwrap()), SIGINT).unwrap();
-	assert!(wait_for(&mut child, 40).map(|x| x.success()).unwrap());
-}
-
-/// Run the node asserting that it fails with an error
-pub fn run_node_assert_fail(base_path: &Path, args: &[&str]) {
-	let mut cmd = Command::new(cargo_bin("substrate"));
-
-	let mut child = KillChildOnDrop(cmd.args(args).arg("-d").arg(base_path).spawn().unwrap());
-
-	// Let it produce some blocks, but it should die within 10 seconds.
-	assert_ne!(
-		wait_timeout::ChildExt::wait_timeout(&mut *child, Duration::from_secs(10)).unwrap(),
-		None,
-		"the process should not be running anymore"
-	);
+		// Stop the process
+		child.stop();
+	})
+	.await
 }
 
 pub struct KillChildOnDrop(pub Child);
 
+impl KillChildOnDrop {
+	/// Stop the child and wait until it is finished.
+	///
+	/// Asserts if the exit status isn't success.
+	pub fn stop(&mut self) {
+		self.stop_with_signal(SIGINT);
+	}
+
+	/// Same as [`Self::stop`] but takes the `signal` that is sent to stop the child.
+	pub fn stop_with_signal(&mut self, signal: Signal) {
+		kill(Pid::from_raw(self.id().try_into().unwrap()), signal).unwrap();
+		assert!(self.wait().unwrap().success());
+	}
+
+	/// Asserts that the child is still running.
+	pub fn assert_still_running(&mut self) {
+		assert!(self.try_wait().unwrap().is_none(), "the process should still be running");
+	}
+}
+
 impl Drop for KillChildOnDrop {
 	fn drop(&mut self) {
 		let _ = self.0.kill();
@@ -148,18 +128,22 @@ impl DerefMut for KillChildOnDrop {
 	}
 }
 
-/// Read the WS address from the output.
+/// Information extracted from a running node.
+pub struct NodeInfo {
+	pub ws_url: String,
+	pub db_path: PathBuf,
+}
+
+/// Extract [`NodeInfo`] from a running node by parsing its output.
 ///
-/// This is hack to get the actual binded sockaddr because
-/// substrate assigns a random port if the specified port was already binded.
-pub fn find_ws_url_from_output(read: impl Read + Send) -> (String, String) {
+/// Returns the [`NodeInfo`] and all the read data.
+pub fn extract_info_from_output(read: impl Read + Send) -> (NodeInfo, String) {
 	let mut data = String::new();
 
 	let ws_url = BufReader::new(read)
 		.lines()
 		.find_map(|line| {
-			let line =
-				line.expect("failed to obtain next line from stdout for WS address discovery");
+			let line = line.expect("failed to obtain next line while extracting node info");
 			data.push_str(&line);
 			data.push_str("\n");
 
@@ -176,5 +160,9 @@ pub fn find_ws_url_from_output(read: impl Read + Send) -> (String, String) {
 			panic!("We should get a WebSocket address")
 		});
 
-	(ws_url, data)
+	// Database path is printed before the ws url!
+	let re = Regex::new(r"Database: .+ at (\S+)").unwrap();
+	let db_path = PathBuf::from(re.captures(data.as_str()).unwrap().get(1).unwrap().as_str());
+
+	(NodeInfo { ws_url, db_path }, data)
 }

substrate/bin/node/cli/tests/running_the_node_and_interrupt.rs

@@ -18,94 +18,81 @@
 
 #![cfg(unix)]
 use assert_cmd::cargo::cargo_bin;
-use nix::{
-	sys::signal::{
-		kill,
-		Signal::{self, SIGINT, SIGTERM},
-	},
-	unistd::Pid,
+use nix::sys::signal::Signal::{self, SIGINT, SIGTERM};
+use std::{
+	process::{self, Child, Command},
+	time::Duration,
 };
-use std::process::{self, Child, Command};
 use tempfile::tempdir;
 
 pub mod common;
 
 #[tokio::test]
 async fn running_the_node_works_and_can_be_interrupted() {
-	async fn run_command_and_kill(signal: Signal) {
-		let base_path = tempdir().expect("could not create a temp dir");
-		let mut cmd = common::KillChildOnDrop(
-			Command::new(cargo_bin("substrate"))
-				.stdout(process::Stdio::piped())
-				.stderr(process::Stdio::piped())
-				.args(&["--dev", "-d"])
-				.arg(base_path.path())
-				.arg("--db=paritydb")
-				.arg("--no-hardware-benchmarks")
-				.spawn()
-				.unwrap(),
-		);
+	common::run_with_timeout(Duration::from_secs(60 * 10), async move {
+		async fn run_command_and_kill(signal: Signal) {
+			let base_path = tempdir().expect("could not create a temp dir");
+			let mut cmd = common::KillChildOnDrop(
+				Command::new(cargo_bin("substrate"))
+					.stdout(process::Stdio::piped())
+					.stderr(process::Stdio::piped())
+					.args(&["--dev", "-d"])
+					.arg(base_path.path())
+					.arg("--db=paritydb")
+					.arg("--no-hardware-benchmarks")
+					.spawn()
+					.unwrap(),
+			);
 
-		let stderr = cmd.stderr.take().unwrap();
+			let stderr = cmd.stderr.take().unwrap();
 
-		let (ws_url, _) = common::find_ws_url_from_output(stderr);
+			let ws_url = common::extract_info_from_output(stderr).0.ws_url;
 
-		common::wait_n_finalized_blocks(3, 30, &ws_url)
-			.await
-			.expect("Blocks are produced in time");
-		assert!(cmd.try_wait().unwrap().is_none(), "the process should still be running");
-		kill(Pid::from_raw(cmd.id().try_into().unwrap()), signal).unwrap();
-		assert_eq!(
-			common::wait_for(&mut cmd, 30).map(|x| x.success()),
-			Ok(true),
-			"the process must exit gracefully after signal {}",
-			signal,
-		);
-		// Check if the database was closed gracefully. If it was not,
-		// there may exist a ref cycle that prevents the Client from being dropped properly.
-		//
-		// parity-db only writes the stats file on clean shutdown.
-		let stats_file = base_path.path().join("chains/dev/paritydb/full/stats.txt");
-		assert!(std::path::Path::exists(&stats_file));
-	}
+			common::wait_n_finalized_blocks(3, &ws_url).await;
 
-	run_command_and_kill(SIGINT).await;
-	run_command_and_kill(SIGTERM).await;
+			cmd.assert_still_running();
+
+			cmd.stop_with_signal(signal);
+
+			// Check if the database was closed gracefully. If it was not,
+			// there may exist a ref cycle that prevents the Client from being dropped properly.
+			//
+			// parity-db only writes the stats file on clean shutdown.
+			let stats_file = base_path.path().join("chains/dev/paritydb/full/stats.txt");
+			assert!(std::path::Path::exists(&stats_file));
+		}
+
+		run_command_and_kill(SIGINT).await;
+		run_command_and_kill(SIGTERM).await;
+	})
+	.await;
 }
 
 #[tokio::test]
 async fn running_two_nodes_with_the_same_ws_port_should_work() {
-	fn start_node() -> Child {
-		Command::new(cargo_bin("substrate"))
-			.stdout(process::Stdio::piped())
-			.stderr(process::Stdio::piped())
-			.args(&["--dev", "--tmp", "--ws-port=45789", "--no-hardware-benchmarks"])
-			.spawn()
-			.unwrap()
-	}
+	common::run_with_timeout(Duration::from_secs(60 * 10), async move {
+		fn start_node() -> Child {
+			Command::new(cargo_bin("substrate"))
+				.stdout(process::Stdio::piped())
+				.stderr(process::Stdio::piped())
+				.args(&["--dev", "--tmp", "--ws-port=45789", "--no-hardware-benchmarks"])
+				.spawn()
+				.unwrap()
+		}
 
-	let mut first_node = common::KillChildOnDrop(start_node());
-	let mut second_node = common::KillChildOnDrop(start_node());
+		let mut first_node = common::KillChildOnDrop(start_node());
+		let mut second_node = common::KillChildOnDrop(start_node());
 
-	let stderr = first_node.stderr.take().unwrap();
-	let (ws_url, _) = common::find_ws_url_from_output(stderr);
+		let stderr = first_node.stderr.take().unwrap();
+		let ws_url = common::extract_info_from_output(stderr).0.ws_url;
 
-	common::wait_n_finalized_blocks(3, 30, &ws_url).await.unwrap();
+		common::wait_n_finalized_blocks(3, &ws_url).await;
 
-	assert!(first_node.try_wait().unwrap().is_none(), "The first node should still be running");
-	assert!(second_node.try_wait().unwrap().is_none(), "The second node should still be running");
+		first_node.assert_still_running();
+		second_node.assert_still_running();
 
-	kill(Pid::from_raw(first_node.id().try_into().unwrap()), SIGINT).unwrap();
-	kill(Pid::from_raw(second_node.id().try_into().unwrap()), SIGINT).unwrap();
-
-	assert_eq!(
-		common::wait_for(&mut first_node, 30).map(|x| x.success()),
-		Ok(true),
-		"The first node must exit gracefully",
-	);
-	assert_eq!(
-		common::wait_for(&mut second_node, 30).map(|x| x.success()),
-		Ok(true),
-		"The second node must exit gracefully",
-	);
+		first_node.stop();
+		second_node.stop();
+	})
+	.await;
 }

substrate/bin/node/cli/tests/telemetry.rs

@@ -17,78 +17,75 @@
 // along with this program. If not, see <https://www.gnu.org/licenses/>.
 
 use assert_cmd::cargo::cargo_bin;
-use nix::{
-	sys::signal::{kill, Signal::SIGINT},
-	unistd::Pid,
-};
-use std::process;
+use std::{process, time::Duration};
+
+use crate::common::KillChildOnDrop;
 
 pub mod common;
 pub mod websocket_server;
 
 #[tokio::test]
 async fn telemetry_works() {
-	let config = websocket_server::Config {
-		capacity: 1,
-		max_frame_size: 1048 * 1024,
-		send_buffer_len: 32,
-		bind_address: "127.0.0.1:0".parse().unwrap(),
-	};
-	let mut server = websocket_server::WsServer::new(config).await.unwrap();
+	common::run_with_timeout(Duration::from_secs(60 * 10), async move {
+		let config = websocket_server::Config {
+			capacity: 1,
+			max_frame_size: 1048 * 1024,
+			send_buffer_len: 32,
+			bind_address: "127.0.0.1:0".parse().unwrap(),
+		};
+		let mut server = websocket_server::WsServer::new(config).await.unwrap();
 
-	let addr = server.local_addr().unwrap();
+		let addr = server.local_addr().unwrap();
 
-	let server_task = tokio::spawn(async move {
-		loop {
-			use websocket_server::Event;
-			match server.next_event().await {
-				// New connection on the listener.
-				Event::ConnectionOpen { address } => {
-					println!("New connection from {:?}", address);
-					server.accept();
-				},
+		let server_task = tokio::spawn(async move {
+			loop {
+				use websocket_server::Event;
+				match server.next_event().await {
+					// New connection on the listener.
+					Event::ConnectionOpen { address } => {
+						println!("New connection from {:?}", address);
+						server.accept();
+					},
 
-				// Received a message from a connection.
-				Event::BinaryFrame { message, .. } => {
-					let json: serde_json::Value = serde_json::from_slice(&message).unwrap();
-					let object =
-						json.as_object().unwrap().get("payload").unwrap().as_object().unwrap();
-					if matches!(object.get("best"), Some(serde_json::Value::String(_))) {
-						break
-					}
-				},
+					// Received a message from a connection.
+					Event::BinaryFrame { message, .. } => {
+						let json: serde_json::Value = serde_json::from_slice(&message).unwrap();
+						let object =
+							json.as_object().unwrap().get("payload").unwrap().as_object().unwrap();
+						if matches!(object.get("best"), Some(serde_json::Value::String(_))) {
+							break
+						}
+					},
 
-				Event::TextFrame { .. } => panic!("Got a TextFrame over the socket, this is a bug"),
+					Event::TextFrame { .. } =>
+						panic!("Got a TextFrame over the socket, this is a bug"),
 
-				// Connection has been closed.
-				Event::ConnectionError { .. } => {},
+					// Connection has been closed.
+					Event::ConnectionError { .. } => {},
+				}
 			}
-		}
-	});
+		});
 
-	let mut substrate = process::Command::new(cargo_bin("substrate"));
+		let mut substrate = process::Command::new(cargo_bin("substrate"));
 
-	let mut substrate = substrate
-		.args(&["--dev", "--tmp", "--telemetry-url"])
-		.arg(format!("ws://{} 10", addr))
-		.arg("--no-hardware-benchmarks")
-		.stdout(process::Stdio::piped())
-		.stderr(process::Stdio::piped())
-		.stdin(process::Stdio::null())
-		.spawn()
-		.unwrap();
+		let mut substrate = KillChildOnDrop(
+			substrate
+				.args(&["--dev", "--tmp", "--telemetry-url"])
+				.arg(format!("ws://{} 10", addr))
+				.arg("--no-hardware-benchmarks")
+				.stdout(process::Stdio::piped())
+				.stderr(process::Stdio::piped())
+				.stdin(process::Stdio::null())
+				.spawn()
+				.unwrap(),
+		);
 
-	server_task.await.expect("server task panicked");
+		server_task.await.expect("server task panicked");
 
-	assert!(substrate.try_wait().unwrap().is_none(), "the process should still be running");
+		substrate.assert_still_running();
 
-	// Stop the process
-	kill(Pid::from_raw(substrate.id().try_into().unwrap()), SIGINT).unwrap();
-	assert!(common::wait_for(&mut substrate, 40).map(|x| x.success()).unwrap_or_default());
-
-	let output = substrate.wait_with_output().unwrap();
-
-	println!("{}", String::from_utf8(output.stdout).unwrap());
-	eprintln!("{}", String::from_utf8(output.stderr).unwrap());
-	assert!(output.status.success());
+		// Stop the process
+		substrate.stop();
+	})
+	.await;
 }

substrate/bin/node/cli/tests/temp_base_path_works.rs

@@ -19,45 +19,42 @@
 #![cfg(unix)]
 
 use assert_cmd::cargo::cargo_bin;
-use nix::{
-	sys::signal::{kill, Signal::SIGINT},
-	unistd::Pid,
-};
-use regex::Regex;
 use std::{
-	io::Read,
-	path::PathBuf,
 	process::{Command, Stdio},
+	time::Duration,
 };
 
 pub mod common;
 
 #[tokio::test]
 async fn temp_base_path_works() {
-	let mut cmd = Command::new(cargo_bin("substrate"));
-	let mut child = common::KillChildOnDrop(
-		cmd.args(&["--dev", "--tmp", "--no-hardware-benchmarks"])
-			.stdout(Stdio::piped())
-			.stderr(Stdio::piped())
-			.spawn()
-			.unwrap(),
-	);
+	common::run_with_timeout(Duration::from_secs(60 * 10), async move {
+		let mut cmd = Command::new(cargo_bin("substrate"));
+		let mut child = common::KillChildOnDrop(
+			cmd.args(&["--dev", "--tmp", "--no-hardware-benchmarks"])
+				.stdout(Stdio::piped())
+				.stderr(Stdio::piped())
+				.spawn()
+				.unwrap(),
+		);
 
-	let mut stderr = child.stderr.take().unwrap();
-	let (ws_url, mut data) = common::find_ws_url_from_output(&mut stderr);
+		let mut stderr = child.stderr.take().unwrap();
+		let node_info = common::extract_info_from_output(&mut stderr).0;
 
-	// Let it produce some blocks.
-	common::wait_n_finalized_blocks(3, 30, &ws_url).await.unwrap();
-	assert!(child.try_wait().unwrap().is_none(), "the process should still be running");
+		// Let it produce some blocks.
+		common::wait_n_finalized_blocks(3, &node_info.ws_url).await;
 
-	// Stop the process
-	kill(Pid::from_raw(child.id().try_into().unwrap()), SIGINT).unwrap();
-	assert!(common::wait_for(&mut child, 40).map(|x| x.success()).unwrap_or_default());
+		// Ensure the db path exists while the node is running
+		assert!(node_info.db_path.exists());
 
-	// Ensure the database has been deleted
-	stderr.read_to_string(&mut data).unwrap();
-	let re = Regex::new(r"Database: .+ at (\S+)").unwrap();
-	let db_path = PathBuf::from(re.captures(data.as_str()).unwrap().get(1).unwrap().as_str());
+		child.assert_still_running();
 
-	assert!(!db_path.exists());
+		// Stop the process
+		child.stop();
+
+		if node_info.db_path.exists() {
+			panic!("Database path `{}` wasn't deleted!", node_info.db_path.display());
+		}
+	})
+	.await;
 }