Colocation logging improvements (#1986)

# Description

Ideally we can query a specific auction ID in kibana and get from a
concise overview of what happened in the auction only by looking at INFO
+ logs (DEBUG may be somewhat noisy, TRACE is off by default).

Currently when looking e.g. at [this
auction](https://production-6de61f.kb.eu-central-1.aws.cloud.es.io/app/r/s/8yS6J)
we can see a lot of noisy info logs telling us about solvers submitting
empty solutions, and their solver engines receiving the auction and
fetching liquidity.

At the same time, we don't see information about the runners up
solutions (unless they fail) in order to be able to easily reproduce
them in Tenderly or Phalcon.

This PR improves this

# Changes
- Log auction ID in execute call (this allows to get the auction_id from
the tx_hash in a single INFO level request)
- demote some noisy logs from info to debug
- Add a log for successfully simulated solution candidate (not just the
winning one)

## How to test
1. Run system with only INFO logs and see relevant information in a
concise way

## Related Issues

Fixes #1952

crates/driver/src/domain/competition/solution/settlement.rs

@@ -7,7 +7,7 @@ use {
             eth,
             mempools,
         },
-        infra::{blockchain::Ethereum, Simulator},
+        infra::{blockchain::Ethereum, observe, Simulator},
         util::conv::u256::U256Ext,
     },
     bigdecimal::Signed,
@@ -241,8 +241,9 @@ impl Settlement {
         let tx = tx.set_access_list(access_list.clone());
 
         // Simulate the settlement using the full access list and get the gas used.
-        let gas = simulator.gas(tx).await?;
+        let gas = simulator.gas(tx.clone()).await?;
 
+        observe::simulated(&tx, gas);
         Ok((access_list, gas))
     }
 

crates/driver/src/domain/mempools.rs

@@ -5,6 +5,7 @@ use {
     },
     futures::{future::select_ok, FutureExt},
     thiserror::Error,
+    tracing::Instrument,
 };
 
 /// The mempools used to execute settlements.
@@ -23,6 +24,8 @@ impl Mempools {
     /// Publish a settlement to the mempools. Wait until it is confirmed in the
     /// background.
     pub fn execute(&self, solver: &Solver, settlement: &Settlement) {
+        let auction_id = settlement.auction_id;
+        let solver_name = solver.name();
         tokio::spawn(select_ok(self.0.iter().cloned().map(|mempool| {
             let solver = solver.clone();
             let settlement = settlement.clone();
@@ -31,6 +34,11 @@ impl Mempools {
                 observe::mempool_executed(&mempool, &settlement, &result);
                 result
             }
+            .instrument(tracing::info_span!(
+                "execute",
+                solver = ?solver_name,
+                ?auction_id,
+            ))
             .boxed()
         })));
     }

crates/driver/src/infra/observe/mod.rs

@@ -15,7 +15,7 @@ use {
                 Solution,
                 Solved,
             },
-            eth,
+            eth::{self, Gas},
             quote::{self, Quote},
             Liquidity,
         },
@@ -37,7 +37,7 @@ pub fn init(log: &str) {
 
 /// Observe a received auction.
 pub fn auction(auction: &Auction) {
-    tracing::info!(?auction, "received auction");
+    tracing::debug!(?auction, "received auction");
 }
 
 /// Observe that liquidity fetching is about to start.
@@ -51,7 +51,7 @@ pub fn fetched_liquidity(liquidity: &[Liquidity]) {
     for liquidity in liquidity {
         *grouped.entry((&liquidity.kind).into()).or_default() += 1;
     }
-    tracing::info!(liquidity = ?grouped, "fetched liquidity sources");
+    tracing::debug!(liquidity = ?grouped, "fetched liquidity sources");
 }
 
 /// Observe that fetching liquidity failed.
@@ -61,12 +61,16 @@ pub fn fetching_liquidity_failed(err: &boundary::Error) {
 
 /// Observe the solutions returned by the solver.
 pub fn solutions(solutions: &[Solution]) {
-    tracing::info!(?solutions, "computed solutions");
+    if !solutions.is_empty() {
+        tracing::info!(?solutions, "computed solutions");
+    } else {
+        tracing::debug!("no solutions");
+    }
 }
 
 /// Observe that a solution was discarded because it is empty.
 pub fn empty_solution(solver: &solver::Name, id: solution::Id) {
-    tracing::info!(?id, "discarded solution: empty");
+    tracing::debug!(?id, "discarded solution: empty");
     metrics::get()
         .dropped_solutions
         .with_label_values(&[solver.as_str(), "EmptySolution"])
@@ -335,3 +339,8 @@ pub fn order_excluded_from_auction(
 ) {
     tracing::trace!(uid=?order.uid, ?reason, "order excluded from auction");
 }
+
+/// Observe that a settlement was simulated
+pub fn simulated(tx: &eth::Tx, gas: Gas) {
+    tracing::debug!(?tx, gas = ?gas.0, "simulated settlement");
+}