ci: enable unstable tokio logging for tests (#7038)

Hopefully helps in debugging #6953.

.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:

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",
 ]
 

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

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();