Add tokio console and more debugging feats

Cargo.lock

@@ -121,12 +121,90 @@ dependencies = [
  "pin-project-lite",
 ]
 
+[[package]]
+name = "async-stream"
+version = "0.3.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "cd56dd203fef61ac097dd65721a419ddccb106b2d2b70ba60a6b529f03961a51"
+dependencies = [
+ "async-stream-impl",
+ "futures-core",
+ "pin-project-lite",
+]
+
+[[package]]
+name = "async-stream-impl"
+version = "0.3.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "16e62a023e7c117e27523144c5d2459f4397fcc3cab0085af8e2224f643a0193"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn 2.0.39",
+]
+
+[[package]]
+name = "async-trait"
+version = "0.1.76"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "531b97fb4cd3dfdce92c35dedbfdc1f0b9d8091c8ca943d6dae340ef5012d514"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn 2.0.39",
+]
+
 [[package]]
 name = "autocfg"
 version = "1.1.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "d468802bab17cbc0cc575e9b053f41e72aa36bfa6b7f55e3529ffa43161b97fa"
 
+[[package]]
+name = "axum"
+version = "0.6.20"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3b829e4e32b91e643de6eafe82b1d90675f5874230191a4ffbc1b336dec4d6bf"
+dependencies = [
+ "async-trait",
+ "axum-core",
+ "bitflags 1.3.2",
+ "bytes",
+ "futures-util",
+ "http",
+ "http-body",
+ "hyper",
+ "itoa",
+ "matchit",
+ "memchr",
+ "mime",
+ "percent-encoding",
+ "pin-project-lite",
+ "rustversion",
+ "serde",
+ "sync_wrapper",
+ "tower",
+ "tower-layer",
+ "tower-service",
+]
+
+[[package]]
+name = "axum-core"
+version = "0.3.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "759fa577a247914fd3f7f76d62972792636412fbfd634cd452f6a385a74d2d2c"
+dependencies = [
+ "async-trait",
+ "bytes",
+ "futures-util",
+ "http",
+ "http-body",
+ "mime",
+ "rustversion",
+ "tower-layer",
+ "tower-service",
+]
+
 [[package]]
 name = "backtrace"
 version = "0.3.68"
@@ -247,6 +325,7 @@ dependencies = [
  "caps",
  "chacha20poly1305",
  "clap",
+ "console-subscriber",
  "env_logger",
  "etherparse",
  "fehler",
@@ -459,6 +538,43 @@ dependencies = [
  "windows-sys 0.45.0",
 ]
 
+[[package]]
+name = "console-api"
+version = "0.6.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "fd326812b3fd01da5bb1af7d340d0d555fd3d4b641e7f1dfcf5962a902952787"
+dependencies = [
+ "futures-core",
+ "prost",
+ "prost-types",
+ "tonic",
+ "tracing-core",
+]
+
+[[package]]
+name = "console-subscriber"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7481d4c57092cd1c19dd541b92bdce883de840df30aa5d03fd48a3935c01842e"
+dependencies = [
+ "console-api",
+ "crossbeam-channel",
+ "crossbeam-utils",
+ "futures-task",
+ "hdrhistogram",
+ "humantime",
+ "prost-types",
+ "serde",
+ "serde_json",
+ "thread_local",
+ "tokio",
+ "tokio-stream",
+ "tonic",
+ "tracing",
+ "tracing-core",
+ "tracing-subscriber",
+]
+
 [[package]]
 name = "constant_time_eq"
 version = "0.1.5"
@@ -500,14 +616,20 @@ dependencies = [
 ]
 
 [[package]]
-name = "crossbeam-utils"
+name = "crossbeam-channel"
-version = "0.8.16"
+version = "0.5.11"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "5a22b2d63d4d1dc0b7f1b6b2747dd0088008a9be28b6ddf0b1e7d335e3037294"
+checksum = "176dc175b78f56c0f321911d9c8eb2b77a78a4860b9c19db83835fea1a46649b"
 dependencies = [
- "cfg-if",
+ "crossbeam-utils",
 ]
 
+[[package]]
+name = "crossbeam-utils"
+version = "0.8.19"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "248e3bacc7dc6baa3b21e405ee045c3047101a49145e7e9eca583ab4c2ca5345"
+
 [[package]]
 name = "crypto-common"
 version = "0.1.6"
@@ -870,6 +992,19 @@ version = "0.12.3"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "8a9ee70c43aaf417c914396645a0fa852624801b24ebb7ae78fe8272889ac888"
 
+[[package]]
+name = "hdrhistogram"
+version = "7.5.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "765c9198f173dd59ce26ff9f95ef0aafd0a0fe01fb9d72841bc5066a4c06511d"
+dependencies = [
+ "base64",
+ "byteorder",
+ "flate2",
+ "nom",
+ "num-traits",
+]
+
 [[package]]
 name = "heck"
 version = "0.4.1"
@@ -961,6 +1096,18 @@ dependencies = [
  "want",
 ]
 
+[[package]]
+name = "hyper-timeout"
+version = "0.4.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "bbb958482e8c7be4bc3cf272a766a2b0bf1a6755e7a6ae777f017a31d11b13b1"
+dependencies = [
+ "hyper",
+ "pin-project-lite",
+ "tokio",
+ "tokio-io-timeout",
+]
+
 [[package]]
 name = "hyper-tls"
 version = "0.5.0"
@@ -1079,6 +1226,15 @@ dependencies = [
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "itertools"
+version = "0.11.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b1c173a5686ce8bfa551b3563d0c2170bf24ca44da99c7ca4bfdab5418c3fe57"
+dependencies = [
+ "either",
+]
+
 [[package]]
 name = "itoa"
 version = "1.0.6"
@@ -1192,6 +1348,12 @@ dependencies = [
  "regex-automata",
 ]
 
+[[package]]
+name = "matchit"
+version = "0.7.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "0e7465ac9959cc2b1404e8e2367b43684a6d13790fe23056cc8c6c5a6b7bcb94"
+
 [[package]]
 name = "memchr"
 version = "2.5.0"
@@ -1314,6 +1476,15 @@ dependencies = [
  "winapi",
 ]
 
+[[package]]
+name = "num-traits"
+version = "0.2.17"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "39e3200413f237f41ab11ad6d161bc7239c84dcb631773ccd7de3dfe4b5c267c"
+dependencies = [
+ "autocfg",
+]
+
 [[package]]
 name = "num_cpus"
 version = "1.16.0"
@@ -1459,6 +1630,26 @@ version = "2.3.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "9b2a4787296e9989611394c33f193f676704af1686e70b8f8033ab5ba9a35a94"
 
+[[package]]
+name = "pin-project"
+version = "1.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "fda4ed1c6c173e3fc7a83629421152e01d7b1f9b7f65fb301e490e8cfc656422"
+dependencies = [
+ "pin-project-internal",
+]
+
+[[package]]
+name = "pin-project-internal"
+version = "1.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4359fd9c9171ec6e8c62926d6faaf553a8dc3f64e1507e76da7911b4f6a04405"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn 2.0.39",
+]
+
 [[package]]
 name = "pin-project-lite"
 version = "0.2.13"
@@ -1519,6 +1710,38 @@ dependencies = [
  "unicode-ident",
 ]
 
+[[package]]
+name = "prost"
+version = "0.12.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "146c289cda302b98a28d40c8b3b90498d6e526dd24ac2ecea73e4e491685b94a"
+dependencies = [
+ "bytes",
+ "prost-derive",
+]
+
+[[package]]
+name = "prost-derive"
+version = "0.12.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "efb6c9a1dd1def8e2124d17e83a20af56f1570d6c2d2bd9e266ccb768df3840e"
+dependencies = [
+ "anyhow",
+ "itertools",
+ "proc-macro2",
+ "quote",
+ "syn 2.0.39",
+]
+
+[[package]]
+name = "prost-types"
+version = "0.12.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "193898f59edcf43c26227dcd4c8427f00d99d61e95dcde58dabd49fa291d470e"
+dependencies = [
+ "prost",
+]
+
 [[package]]
 name = "quote"
 version = "1.0.33"
@@ -1698,6 +1921,12 @@ dependencies = [
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "rustversion"
+version = "1.0.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "7ffc183a10b4478d04cbbbfc96d0873219d962dd5accaff2ffbd4ceb7df837f4"
+
 [[package]]
 name = "ryu"
 version = "1.0.13"
@@ -1967,6 +2196,12 @@ dependencies = [
  "unicode-ident",
 ]
 
+[[package]]
+name = "sync_wrapper"
+version = "0.1.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2047c6ded9c721764247e62cd3b03c09ffc529b2ba5b10ec482ae507a4a70160"
+
 [[package]]
 name = "tempfile"
 version = "3.6.0"
@@ -2066,9 +2301,20 @@ dependencies = [
  "pin-project-lite",
  "socket2",
  "tokio-macros",
+ "tracing",
  "windows-sys 0.48.0",
 ]
 
+[[package]]
+name = "tokio-io-timeout"
+version = "1.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "30b74022ada614a1b4834de765f9bb43877f910cc8ce4be40e89042c9223a8bf"
+dependencies = [
+ "pin-project-lite",
+ "tokio",
+]
+
 [[package]]
 name = "tokio-macros"
 version = "2.1.0"
@@ -2090,6 +2336,17 @@ dependencies = [
  "tokio",
 ]
 
+[[package]]
+name = "tokio-stream"
+version = "0.1.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "397c988d37662c7dda6d2208364a706264bf3d6138b11d436cbac0ad38832842"
+dependencies = [
+ "futures-core",
+ "pin-project-lite",
+ "tokio",
+]
+
 [[package]]
 name = "tokio-util"
 version = "0.7.8"
@@ -2104,6 +2361,59 @@ dependencies = [
  "tracing",
 ]
 
+[[package]]
+name = "tonic"
+version = "0.10.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d560933a0de61cf715926b9cac824d4c883c2c43142f787595e48280c40a1d0e"
+dependencies = [
+ "async-stream",
+ "async-trait",
+ "axum",
+ "base64",
+ "bytes",
+ "h2",
+ "http",
+ "http-body",
+ "hyper",
+ "hyper-timeout",
+ "percent-encoding",
+ "pin-project",
+ "prost",
+ "tokio",
+ "tokio-stream",
+ "tower",
+ "tower-layer",
+ "tower-service",
+ "tracing",
+]
+
+[[package]]
+name = "tower"
+version = "0.4.13"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b8fa9be0de6cf49e536ce1851f987bd21a43b771b09473c3549a6c853db37c1c"
+dependencies = [
+ "futures-core",
+ "futures-util",
+ "indexmap",
+ "pin-project",
+ "pin-project-lite",
+ "rand",
+ "slab",
+ "tokio",
+ "tokio-util",
+ "tower-layer",
+ "tower-service",
+ "tracing",
+]
+
+[[package]]
+name = "tower-layer"
+version = "0.3.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "c20c8dbed6283a09604c3e69b4b7eeb54e298b8a600d4d5ecb5ad39de609f1d0"
+
 [[package]]
 name = "tower-service"
 version = "0.3.2"

Makefile

@@ -1,4 +1,6 @@
 tun_num := $(shell ifconfig | awk -F 'utun|[: ]' '/utun[0-9]/ {print $$2}' | tail -n 1)
+cargo_console := RUST_BACKTRACE=1 RUST_LOG=debug RUSTFLAGS='--cfg tokio_unstable' cargo run --all-features
+cargo_norm := RUST_BACKTRACE=1 RUST_LOG=debug cargo run
 
 check:
 	@cargo check
@@ -6,11 +8,14 @@ check:
 build:
 	@cargo run build
 
+daemon-console:
+	@$(cargo_console) daemon
+
 daemon:
-	@RUST_BACKTRACE=1 RUST_LOG=debug cargo run daemon
+	@$(cargo_norm) daemon
 
 start:
-	@RUST_BACKTRACE=1 RUST_LOG=debug cargo run start
+	@$(cargo_norm) start
 
 test-dns:
 	@sudo route delete 8.8.8.8

burrow/Cargo.toml

@@ -10,7 +10,7 @@ crate-type = ["lib", "staticlib"]
 
 [dependencies]
 anyhow = "1.0"
-tokio = { version = "1.21", features = ["rt", "macros", "sync", "io-util", "rt-multi-thread", "time"] }
+tokio = { version = "1.21", features = ["rt", "macros", "sync", "io-util", "rt-multi-thread", "time", "tracing"] }
 tun = { version = "0.1", path = "../tun", features = ["serde", "tokio"] }
 clap = { version = "4.3.2", features = ["derive"] }
 tracing = "0.1"
@@ -40,6 +40,7 @@ async-channel = "2.1.1"
 schemars = "0.8"
 futures = "0.3.28"
 uuid = { version = "1.6.1", features = ["v4"] }
+console-subscriber = { version = "0.2.0" , optional = true}
 
 [target.'cfg(target_os = "linux")'.dependencies]
 caps = "0.5.5"
@@ -60,3 +61,6 @@ assets = [
 ]
 post_install_script = "../package/rpm/post_install"
 pre_uninstall_script = "../package/rpm/pre_uninstall"
+
+[features]
+tokio-console = ["dep:console-subscriber"]

burrow/src/main.rs

@@ -100,17 +100,25 @@ async fn initialize_tracing() -> Result<()> {
     {
     let maybe_layer = system_log()?;
     if let Some(layer) = maybe_layer {
-            let logger = layer.with_subscriber(
+        let registry = tracing_subscriber::registry()
-                FmtSubscriber::builder()
+            .with(layer)
+            .with(tracing_subscriber::fmt::layer()
                 .with_line_number(true)
-                    .with_env_filter(EnvFilter::from_default_env())
+                .with_filter(EnvFilter::from_default_env())
-                    .finish(),
             );
-            tracing::subscriber::set_global_default(logger)
-                .context("Failed to set the global tracing subscriber")?;
-        }
-    }
 
+        #[cfg(feature = "tokio-console")]
+        let registry =  registry.with(
+            console_subscriber::spawn()
+                .with_filter(EnvFilter::from_default_env()
+                    .add_directive("tokio=trace".parse()?)
+                    .add_directive("runtime=trace".parse()?)
+                )
+        );
+
+        tracing::subscriber::set_global_default(registry).context("Failed to set the global tracing subscriber")?;
+        }
+    }
     Ok(())
 }
 

burrow/src/wireguard/pcb.rs

@@ -115,9 +115,12 @@ impl PeerPcb {
     }
 
     pub async fn send(&self, src: &[u8]) -> Result<(), Error> {
+        tracing::debug!("Sending packet: {:?}", src);
         let mut dst_buf = [0u8; 3000];
         match self.tunnel.write().await.encapsulate(src, &mut dst_buf[..]) {
-            TunnResult::Done => {}
+            TunnResult::Done => {
+                tracing::debug!("Encapsulate done");
+            }
             TunnResult::Err(e) => {
                 tracing::error!(message = "Encapsulate error", error = ?e)
             }
@@ -137,6 +140,7 @@ impl PeerPcb {
     }
 
     pub async fn update_timers(&self, dst: &mut [u8]) -> Result<(), Error> {
+        tracing::debug!("update timers called...");
         match self.tunnel.write().await.update_timers(dst) {
             TunnResult::Done => {}
             TunnResult::Err(WireGuardError::ConnectionExpired) => {
@@ -147,6 +151,7 @@ impl PeerPcb {
                 tracing::error!(message = "Update timers error", error = ?e)
             }
             TunnResult::WriteToNetwork(packet) => {
+                tracing::debug!("Sending Packet for timer update: {:?}", packet);
                 self.open_if_closed().await?;
                 let handle = self.socket.read().await;
                 let Some(socket) = handle.as_ref() else {
@@ -154,9 +159,11 @@ impl PeerPcb {
                     return Ok(())
                 };
                 socket.send(packet).await?;
+                tracing::debug!("Sent Packet for timer update");
             }
             _ => panic!("Unexpected result from update_timers"),
         };
+        tracing::debug!("update timers exit...");
         Ok(())
     }