From 2ad85a327b3d1f4c551afac37037e2466674dd36 Mon Sep 17 00:00:00 2001
From: Martin Magnus <martin.beckmann@protonmail.com>
Date: Wed, 11 Dec 2024 10:18:47 +0100
Subject: [PATCH] [EASY] Improve logging for submitting transactions (#3158)

# Description
There was a wish to associate MEV blocker request logs with transactions
sent by the driver. This is currently not possible for 2 reasons:
1. there is no log right after submitting the tx so associating logs by
timestamp is not possible
2. the `/settle` handler spawns a new task to make sure transactions get
cancelled (if needed) even when the autopilot terminates the request.
Unfortunately how we pass around `request_ids` (which could also be used
to associated these logs) is very convoluted and was overlooked here.
Since the spawned task has its request_id variable not populated it
generates a new id which does not match the original id.

# Changes
1. add log right after submitting a tx. Additional tracing information
we get by default are `request_id`, `solver` and `mempool` type
2. spawn `/settle` task in a way that preserves the original
`request_id`


Reference slack
[thread](https://cowservices.slack.com/archives/C0375NV72SC/p1733768490743619)
---
 crates/driver/src/domain/mempools.rs            |  1 +
 .../driver/src/infra/api/routes/settle/mod.rs   |  8 +++++---
 crates/observe/src/request_id.rs                | 17 ++++++++++++++++-
 3 files changed, 22 insertions(+), 4 deletions(-)

diff --git a/crates/driver/src/domain/mempools.rs b/crates/driver/src/domain/mempools.rs
index 9872fd7f25..0d5df67404 100644
--- a/crates/driver/src/domain/mempools.rs
+++ b/crates/driver/src/domain/mempools.rs
@@ -103,6 +103,7 @@ impl Mempools {
         block_stream.next().await;
 
         let hash = mempool.submit(tx.clone(), settlement.gas, solver).await?;
+        tracing::debug!(?hash, "submitted tx to the mempool");
 
         // Wait for the transaction to be mined, expired or failing.
         let result = async {
diff --git a/crates/driver/src/infra/api/routes/settle/mod.rs b/crates/driver/src/infra/api/routes/settle/mod.rs
index b75bdb7435..6a169ce3b1 100644
--- a/crates/driver/src/infra/api/routes/settle/mod.rs
+++ b/crates/driver/src/infra/api/routes/settle/mod.rs
@@ -42,7 +42,9 @@ async fn route(
     // aborts the endpoint handler code.
     // This can happen due do connection issues or when the autopilot aborts
     // the `/settle` call when we reach the submission deadline.
-    Ok(tokio::task::spawn(handle_request)
-        .await
-        .unwrap_or_else(|_| Err(competition::Error::SubmissionError))?)
+    Ok(
+        ::observe::request_id::spawn_task_with_current_request_id(handle_request)
+            .await
+            .unwrap_or_else(|_| Err(competition::Error::SubmissionError))?,
+    )
 }
diff --git a/crates/observe/src/request_id.rs b/crates/observe/src/request_id.rs
index 087010867e..268684409e 100644
--- a/crates/observe/src/request_id.rs
+++ b/crates/observe/src/request_id.rs
@@ -16,7 +16,8 @@
 //! And when we issue requests to another process we can simply fetch the
 //! current identifier specific to our task and send that along with the
 //! request.
-use std::future::Future;
+use {std::future::Future, tokio::task::JoinHandle};
+
 tokio::task_local! {
     pub static REQUEST_ID: String;
 }
@@ -39,6 +40,20 @@ where
     REQUEST_ID.scope(id, scope).await
 }
 
+/// Spawns a new task and ensures it uses the same request id as the current
+/// task (if present). This allows for tracing requests across task boundaries.
+pub fn spawn_task_with_current_request_id<F>(future: F) -> JoinHandle<F::Output>
+where
+    F: Future + Send + 'static,
+    F::Output: Send + 'static,
+{
+    if let Some(id) = get_task_local_storage() {
+        tokio::task::spawn(REQUEST_ID.scope(id, future))
+    } else {
+        tokio::task::spawn(future)
+    }
+}
+
 /// Takes a `tower::Service` and embeds it in a `make_service` function that
 /// spawns one of these services per incoming request.
 /// But crucially before spawning that service task local storage will be