feat: improve visibility for runtime performance

tracing::span records how long it took to run a block of code and prints this into into log
near · Mar 5, 2021 · 1679c78 · 1679c78
1 parent 25dbea3
commit 1679c78
Show file tree

Hide file tree

Showing 3 changed files with 5 additions and 0 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/runtime/runtime/Cargo.toml b/runtime/runtime/Cargo.toml
@@ -9,6 +9,7 @@ byteorder = "1.2"
 serde = { version = "1", features = ["derive"] }
 serde_json = "1.0"
 log = "0.4"
+tracing = "0.1.13"
 rand = "0.7"
 lazy_static = "1.4"
 num-rational = "0.3"

diff --git a/runtime/runtime/src/lib.rs b/runtime/runtime/src/lib.rs
@@ -209,6 +209,7 @@ impl Runtime {
         signed_transaction: &SignedTransaction,
         stats: &mut ApplyStats,
     ) -> Result<(Receipt, ExecutionOutcomeWithId), RuntimeError> {
+        let _span = tracing::info_span!("Runtime::process_transaction").entered();
         near_metrics::inc_counter(&metrics::TRANSACTION_PROCESSED_TOTAL);
         match verify_and_charge_transaction(
             &apply_state.config,
@@ -794,6 +795,7 @@ impl Runtime {
         stats: &mut ApplyStats,
         epoch_info_provider: &dyn EpochInfoProvider,
     ) -> Result<Option<ExecutionOutcomeWithId>, RuntimeError> {
+        let _span = tracing::info_span!("Runtime::process_receipt").entered();
         let account_id = &receipt.receiver_id;
         match receipt.receipt {
             ReceiptEnum::Data(ref data_receipt) => {
@@ -1073,6 +1075,7 @@ impl Runtime {
         transactions: &[SignedTransaction],
         epoch_info_provider: &dyn EpochInfoProvider,
     ) -> Result<ApplyResult, RuntimeError> {
+        let _span = tracing::info_span!("Runtime::apply").entered();
         let trie = Rc::new(trie);
         let initial_state = TrieUpdate::new(trie.clone(), root);
         let mut state_update = TrieUpdate::new(trie.clone(), root);