From aee5019329ec8a07328fa111c4ff4a5f6d773412 Mon Sep 17 00:00:00 2001
From: Thomas Eizinger <thomas@eizinger.io>
Date: Tue, 15 Oct 2024 09:45:03 +1100
Subject: [PATCH] ci: enable unstable tokio logging for tests (#7038)

Hopefully helps in debugging #6953.
---
 .github/workflows/_rust.yml           | 2 +-
 rust/Cargo.lock                       | 2 ++
 rust/phoenix-channel/Cargo.toml       | 3 ++-
 rust/phoenix-channel/src/heartbeat.rs | 5 +++++
 4 files changed, 10 insertions(+), 2 deletions(-)

diff --git a/.github/workflows/_rust.yml b/.github/workflows/_rust.yml
index fe07a4d5c..c228b61ce 100644
--- a/.github/workflows/_rust.yml
+++ b/.github/workflows/_rust.yml
@@ -13,7 +13,7 @@ permissions:
 
 # Never tolerate warnings. Duplicated in `_gtk.yml` and `_tauri.yml`
 env:
-  RUSTFLAGS: "-Dwarnings"
+  RUSTFLAGS: "-Dwarnings --cfg tokio_unstable"
   RUSTDOCFLAGS: "-D warnings"
 
 jobs:
diff --git a/rust/Cargo.lock b/rust/Cargo.lock
index 7fc0dd07b..c5138d05b 100644
--- a/rust/Cargo.lock
+++ b/rust/Cargo.lock
@@ -5621,6 +5621,7 @@ version = "0.1.0"
 dependencies = [
  "backoff",
  "base64 0.22.1",
+ "firezone-logging",
  "futures",
  "hex",
  "hostname",
@@ -7955,6 +7956,7 @@ dependencies = [
  "signal-hook-registry",
  "socket2",
  "tokio-macros",
+ "tracing",
  "windows-sys 0.52.0",
 ]
 
diff --git a/rust/phoenix-channel/Cargo.toml b/rust/phoenix-channel/Cargo.toml
index 89b1ded4e..6bf601b04 100644
--- a/rust/phoenix-channel/Cargo.toml
+++ b/rust/phoenix-channel/Cargo.toml
@@ -28,7 +28,8 @@ uuid = { version = "1.10", default-features = false, features = ["std", "v4"] }
 hostname = "0.4.0"
 
 [dev-dependencies]
-tokio = { workspace = true, features = ["macros", "rt"] }
+firezone-logging = { workspace = true }
+tokio = { workspace = true, features = ["macros", "rt", "tracing"] }
 
 [lints]
 workspace = true
diff --git a/rust/phoenix-channel/src/heartbeat.rs b/rust/phoenix-channel/src/heartbeat.rs
index 9350fc2d2..56a32fe03 100644
--- a/rust/phoenix-channel/src/heartbeat.rs
+++ b/rust/phoenix-channel/src/heartbeat.rs
@@ -58,12 +58,15 @@ impl Heartbeat {
     ) -> Poll<Result<OutboundRequestId, MissedLastHeartbeat>> {
         if let Some((_, timeout)) = self.pending.as_mut() {
             ready!(timeout.poll_unpin(cx));
+            tracing::trace!("Timeout waiting for heartbeat response");
             self.pending = None;
             return Poll::Ready(Err(MissedLastHeartbeat {}));
         }
 
         ready!(self.interval.poll_tick(cx));
 
+        tracing::trace!("Time to send a new heartbeat");
+
         let next_id = self
             .next_request_id
             .fetch_add(1, std::sync::atomic::Ordering::SeqCst);
@@ -138,6 +141,8 @@ mod tests {
 
     #[tokio::test]
     async fn fails_if_not_provided_within_timeout() {
+        let _guard = firezone_logging::test("trace");
+
         let mut heartbeat = Heartbeat::new(INTERVAL, TIMEOUT, Arc::new(AtomicU64::new(0)));
 
         let id = poll_fn(|cx| heartbeat.poll(cx)).await.unwrap();