diff --git a/Cargo.toml b/Cargo.toml index 9535a6e4..ffa0446c 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -43,6 +43,7 @@ serde_derive = "1.0" thiserror = "1" tokio = { version = "1", features = ["sync", "rt-multi-thread", "macros"] } tonic = { version = "0.9", features = ["tls"] } +tracing = "0.1" [dev-dependencies] clap = "2" diff --git a/src/request/plan.rs b/src/request/plan.rs index ab72e8aa..51d8782e 100644 --- a/src/request/plan.rs +++ b/src/request/plan.rs @@ -11,6 +11,7 @@ use log::debug; use log::info; use tokio::sync::Semaphore; use tokio::time::sleep; +use tracing::instrument; use crate::backoff::Backoff; use crate::pd::PdClient; @@ -104,6 +105,7 @@ where { // A plan may involve multiple shards #[async_recursion] + #[instrument(skip_all)] async fn single_plan_handler( pd_client: Arc, current_plan: P, diff --git a/src/transaction/transaction.rs b/src/transaction/transaction.rs index 671d6140..389cdb4d 100644 --- a/src/transaction/transaction.rs +++ b/src/transaction/transaction.rs @@ -1,5 +1,6 @@ // Copyright 2019 TiKV Project Authors. Licensed under Apache-2.0. +use std::fmt; use std::iter; use std::marker::PhantomData; use std::sync::Arc; @@ -12,6 +13,7 @@ use log::debug; use log::warn; use tokio::sync::RwLock; use tokio::time::Duration; +use tracing::{instrument, Span}; use crate::backoff::Backoff; use crate::backoff::DEFAULT_REGION_BACKOFF; @@ -87,6 +89,17 @@ pub struct Transaction, } +impl> fmt::Debug for Transaction { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + f.debug_struct("Transaction") + .field("timestamp", &self.timestamp) + .field("options", &self.options) + .field("is_heartbeat_started", &self.is_heartbeat_started) + .field("start_instant", &self.start_instant) + .finish() + } +} + impl> Transaction { pub(crate) fn new( timestamp: Timestamp, @@ -353,6 +366,7 @@ impl> Transaction { /// txn.commit().await.unwrap(); /// # }); /// ``` + #[instrument(skip_all)] pub async fn scan( &mut self, range: impl Into, @@ -389,6 +403,7 @@ impl> Transaction { /// txn.commit().await.unwrap(); /// # }); /// ``` + #[instrument(skip_all)] pub async fn scan_keys( &mut self, range: impl Into, @@ -404,6 +419,7 @@ impl> Transaction { /// Create a 'scan_reverse' request. /// /// Similar to [`scan`](Transaction::scan), but scans in the reverse direction. + #[instrument(skip_all)] pub async fn scan_reverse( &mut self, range: impl Into, @@ -416,6 +432,7 @@ impl> Transaction { /// Create a 'scan_keys_reverse' request. /// /// Similar to [`scan`](Transaction::scan_keys), but scans in the reverse direction. + #[instrument(skip_all)] pub async fn scan_keys_reverse( &mut self, range: impl Into, @@ -758,6 +775,7 @@ impl> Transaction { plan.execute().await } + #[instrument(skip(range), fields(range))] async fn scan_inner( &mut self, range: impl Into, @@ -770,9 +788,12 @@ impl> Transaction { let rpc = self.rpc.clone(); let retry_options = self.options.retry_options.clone(); + let range = range.into(); + Span::current().record("range", &tracing::field::debug(&range)); + self.buffer .scan_and_fetch( - range.into(), + range, limit, !key_only, reverse,