scylla integration tests: introduce setup_tracing()

As described in the previous commit, setup_tracing() enables captured
trace output for tests.
Not to make scylla crate depend on tracing_subscriber (now it's only a
dev-dependency), the function is simply copied to integration/utils.rs.
Integration tests are made call that function at the beginning.

Author: wprzytula

scylla/tests/integration/consistency.rs

@@ -1,4 +1,4 @@
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 
 use scylla::execution_profile::{ExecutionProfileBuilder, ExecutionProfileHandle};
 use scylla::load_balancing::{DefaultPolicy, LoadBalancingPolicy, RoutingInfo};
@@ -256,6 +256,7 @@ async fn check_for_all_consistencies_and_setting_options<
 #[ntest::timeout(60000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn consistency_is_correctly_set_in_cql_requests() {
+    setup_tracing();
     let res = test_with_3_node_cluster(
         ShardAwareness::QueryNode,
         |proxy_uris, translation_map, mut running_proxy| async move {
@@ -407,6 +408,7 @@ impl LoadBalancingPolicy for RoutingInfoReportingWrapper {
 #[ntest::timeout(60000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn consistency_is_correctly_set_in_routing_info() {
+    setup_tracing();
     let uri = std::env::var("SCYLLA_URI").unwrap_or_else(|_| "127.0.0.1:9042".to_string());
     let ks = unique_keyspace_name();
 
@@ -465,6 +467,7 @@ async fn consistency_is_correctly_set_in_routing_info() {
 #[ntest::timeout(60000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn consistency_allows_for_paxos_selects() {
+    setup_tracing();
     let uri = std::env::var("SCYLLA_URI").unwrap_or_else(|_| "127.0.0.1:9042".to_string());
 
     let session = SessionBuilder::new()

scylla/tests/integration/execution_profiles.rs

@@ -1,7 +1,7 @@
 use std::ops::Deref;
 use std::sync::Arc;
 
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 use assert_matches::assert_matches;
 use scylla::batch::BatchStatement;
 use scylla::batch::{Batch, BatchType};
@@ -124,6 +124,7 @@ impl<const NODE: u8> SpeculativeExecutionPolicy for BoundToPredefinedNodePolicy<
 #[ntest::timeout(20000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn test_execution_profiles() {
+    setup_tracing();
     let res = test_with_3_node_cluster(ShardAwareness::QueryNode, |proxy_uris, translation_map, mut running_proxy| async move {
 
         let (routing_tx, mut profile_rx) = mpsc::unbounded_channel();

scylla/tests/integration/lwt_optimisation.rs

@@ -1,4 +1,5 @@
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
+
 use scylla::frame::types;
 use scylla::retry_policy::FallthroughRetryPolicy;
 use scylla::transport::session::Session;
@@ -16,6 +17,8 @@ use scylla_proxy::{
 #[ntest::timeout(20000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn if_lwt_optimisation_mark_offered_then_negotiatied_and_lwt_routed_optimally() {
+    setup_tracing();
+
     // This is just to increase the likelihood that only intended prepared statements (which contain this mark) are captured by the proxy.
     const MAGIC_MARK: i32 = 123;
 

scylla/tests/integration/new_session.rs

@@ -1,10 +1,13 @@
+use crate::utils::setup_tracing;
+
 use assert_matches::assert_matches;
 use scylla::SessionBuilder;
 use scylla_cql::errors::NewSessionError;
 
 #[cfg(not(scylla_cloud_tests))]
 #[tokio::test]
 async fn proceed_if_only_some_hostnames_are_invalid() {
+    setup_tracing();
     // on purpose left without port
     let uri1 = "scylladbisthefastestdb.invalid".to_owned();
     // correctly provided port, but unknown domain
@@ -25,6 +28,7 @@ async fn proceed_if_only_some_hostnames_are_invalid() {
 #[cfg(not(scylla_cloud_tests))]
 #[tokio::test]
 async fn all_hostnames_invalid() {
+    setup_tracing();
     let uri = "cassandrasuckssomuch.invalid:9042".to_owned();
 
     assert_matches!(

scylla/tests/integration/retries.rs

@@ -1,4 +1,4 @@
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 use scylla::retry_policy::FallthroughRetryPolicy;
 use scylla::speculative_execution::SimpleSpeculativeExecutionPolicy;
 use scylla::transport::session::Session;
@@ -18,6 +18,7 @@ use scylla_proxy::{
 #[ntest::timeout(30000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn speculative_execution_is_fired() {
+    setup_tracing();
     const TIMEOUT_PER_REQUEST: Duration = Duration::from_millis(1000);
 
     let res = test_with_3_node_cluster(ShardAwareness::QueryNode, |proxy_uris, translation_map, mut running_proxy| async move {
@@ -99,6 +100,7 @@ async fn speculative_execution_is_fired() {
 #[ntest::timeout(30000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn retries_occur() {
+    setup_tracing();
     let res = test_with_3_node_cluster(ShardAwareness::QueryNode, |proxy_uris, translation_map, mut running_proxy| async move {
 
         // DB preparation phase

scylla/tests/integration/shards.rs

@@ -1,6 +1,6 @@
 use std::sync::Arc;
 
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 use scylla::{test_utils::unique_keyspace_name, SessionBuilder};
 use tokio::sync::mpsc;
 
@@ -14,6 +14,7 @@ use scylla_proxy::{ProxyError, RequestFrame, WorkerError};
 #[ntest::timeout(30000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn test_consistent_shard_awareness() {
+    setup_tracing();
     use std::collections::HashSet;
 
     let res = test_with_3_node_cluster(ShardAwareness::QueryNode, |proxy_uris, translation_map, mut running_proxy| async move {

scylla/tests/integration/silent_prepare_query.rs

@@ -1,4 +1,4 @@
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 use scylla::transport::session::Session;
 use scylla::SessionBuilder;
 use scylla::{query::Query, test_utils::unique_keyspace_name};
@@ -13,6 +13,7 @@ use std::time::Duration;
 #[ntest::timeout(30000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn test_prepare_query_with_values() {
+    setup_tracing();
     // unprepared query with non empty values should be prepared
     const TIMEOUT_PER_REQUEST: Duration = Duration::from_millis(1000);
 
@@ -63,6 +64,7 @@ async fn test_prepare_query_with_values() {
 #[ntest::timeout(30000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn test_query_with_no_values() {
+    setup_tracing();
     // unprepared query with empty values should not be prepared
     const TIMEOUT_PER_REQUEST: Duration = Duration::from_millis(1000);
 

scylla/tests/integration/skip_metadata_optimization.rs

@@ -1,4 +1,4 @@
-use crate::utils::test_with_3_node_cluster;
+use crate::utils::{setup_tracing, test_with_3_node_cluster};
 use scylla::transport::session::Session;
 use scylla::SessionBuilder;
 use scylla::{prepared_statement::PreparedStatement, test_utils::unique_keyspace_name};
@@ -13,6 +13,7 @@ use std::sync::Arc;
 #[ntest::timeout(20000)]
 #[cfg(not(scylla_cloud_tests))]
 async fn test_skip_result_metadata() {
+    setup_tracing();
     use scylla_proxy::{ResponseOpcode, ResponseRule};
 
     const NO_METADATA_FLAG: i32 = 0x0004;

scylla/tests/integration/utils.rs

@@ -11,10 +11,11 @@ use tracing::instrument::WithSubscriber;
 
 use scylla_proxy::{Node, Proxy, ProxyError, RunningProxy, ShardAwareness};
 
-pub(crate) fn init_logger() {
+#[cfg(test)]
+pub(crate) fn setup_tracing() {
     let _ = tracing_subscriber::fmt::fmt()
         .with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
-        .without_time()
+        .with_writer(tracing_subscriber::fmt::TestWriter::new())
         .try_init();
 }
 
@@ -86,7 +87,6 @@ where
     F: FnOnce([String; 3], HashMap<SocketAddr, SocketAddr>, RunningProxy) -> Fut,
     Fut: Future<Output = RunningProxy>,
 {
-    init_logger();
     let real1_uri = env::var("SCYLLA_URI").unwrap_or_else(|_| "127.0.0.1:9042".to_string());
     let proxy1_uri = format!("{}:9042", scylla_proxy::get_exclusive_local_address());
     let real2_uri = env::var("SCYLLA_URI2").unwrap_or_else(|_| "127.0.0.2:9042".to_string());