refactor(android): use fmt::Layer with custom writer (#5558)

Currently, the logs that go to logcat on Android are pretty badly
formatted because we use `tracing-android` and it formats the span
fields and message fields itself. There is actually no reason for doing
the formatting ourselves. Instead, we can use the `MakeWriter`
abstraction from `tracing_subscriber` to plug in a custom writer that
writes to Android's logcat.

This results in logs like this:

```
[nix-shell:~/src/github.com/firezone/firezone/rust]$ adb logcat -s connlib
--------- beginning of main
06-28 19:41:20.057 19955 20213 D connlib : phoenix_channel: Connecting to portal host=api.firez.one user_agent=Android/14 5.15.137-android14-11-gbf4f9bc41c3b-ab11664771 connlib/1.1.1
06-28 19:41:20.058 19955 20213 I connlib : firezone_tunnel::client: Network change detected
06-28 19:41:20.061 19955 20213 D connlib : snownet::node: Closed all connections as part of reconnecting num_connections=0
06-28 19:41:20.365 19955 20213 I connlib : phoenix_channel: Connected to portal host=api.firez.one
06-28 19:41:20.601 19955 20213 I connlib : firezone_tunnel::io: Setting new DNS resolvers
06-28 19:41:21.031 19955 20213 D connlib : firezone_tunnel::client: TUN device initialized ip4=100.66.86.233 ip6=fd00:2021:1111::f:d9c1 name=tun1
06-28 19:41:21.031 19955 20213 I connlib : connlib_client_shared::eventloop: Firezone Started!
06-28 19:41:21.031 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.slackb.com
06-28 19:41:21.031 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.test-ipv6.com
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=5.4.6.7/32 name=5.4.6.7
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=10.0.32.101/32 name=IPerf3
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=ifconfig.net
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.slack-imgs.com
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.google.com
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=10.0.0.5/32 name=10.0.0.5
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.githubassets.com
06-28 19:41:21.032 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=dnsleaktest.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.slack-edge.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.github.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=speed.cloudflare.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.githubusercontent.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=10.0.14.11/32 name=Staging resource performance
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::dns: Activating DNS resource address=*.whatismyip.com
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=10.0.0.8/32 name=10.0.0.8
06-28 19:41:21.033 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=9.9.9.9/32 name=Quad9 DNS
06-28 19:41:21.034 19955 20213 I connlib : firezone_tunnel::client: Activating CIDR resource address=10.0.32.10/32 name=CoreDNS
06-28 19:41:21.216 19955 20213 I connlib : snownet::node: Added new TURN server id=bd6e9d1a-4696-4f8b-8337-aab5d5cea810 address=Dual { v4: 35.197.171.113:3478, v6: [2600:1900:40b0:1504:0:27::]:3478 }
```

---------

Signed-off-by: Thomas Eizinger <thomas@eizinger.io>

rust/Cargo.lock

@@ -81,9 +81,9 @@ checksum = "e999941b234f3131b00bc13c22d06e8c5ff726d1b6318ac7eb276997bbb4fef0"
 
 [[package]]
 name = "android_log-sys"
-version = "0.2.0"
+version = "0.3.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "85965b6739a430150bdd138e2374a98af0c3ee0d030b3bb7fc3bddff58d0102e"
+checksum = "5ecc8056bf6ab9892dcd53216c83d1597487d7dacac16c8df6b877d127df9937"
 
 [[package]]
 name = "android_system_properties"
@@ -1065,6 +1065,7 @@ dependencies = [
 name = "connlib-client-android"
 version = "1.1.1"
 dependencies = [
+ "android_log-sys",
  "connlib-client-shared",
  "ip_network",
  "jni 0.21.1",
@@ -1074,7 +1075,6 @@ dependencies = [
  "thiserror",
  "tokio",
  "tracing",
- "tracing-android",
  "tracing-appender",
  "tracing-subscriber",
  "url",
@@ -1119,7 +1119,6 @@ dependencies = [
  "tokio",
  "tokio-tungstenite",
  "tracing",
- "tracing-android",
  "tracing-appender",
  "tracing-stackdriver",
  "tracing-subscriber",
@@ -1159,7 +1158,6 @@ dependencies = [
  "thiserror",
  "tokio",
  "tracing",
- "tracing-android",
  "url",
  "uuid",
  "windows 0.57.0",
@@ -2062,7 +2060,6 @@ dependencies = [
  "thiserror",
  "tokio",
  "tracing",
- "tracing-android",
  "tracing-subscriber",
  "uuid",
  "windows 0.57.0",
@@ -6718,17 +6715,6 @@ dependencies = [
  "tracing-core",
 ]
 
-[[package]]
-name = "tracing-android"
-version = "0.2.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "12612be8f868a09c0ceae7113ff26afe79d81a24473a393cb9120ece162e86c0"
-dependencies = [
- "android_log-sys",
- "tracing",
- "tracing-subscriber",
-]
-
 [[package]]
 name = "tracing-appender"
 version = "0.2.3"

rust/connlib/clients/android/Cargo.toml

@@ -27,7 +27,7 @@ url = "2.4.0"
 tokio = { version = "1.38", default-features = false, features = ["rt"] }
 
 [target.'cfg(target_os = "android")'.dependencies]
-tracing-android = "0.2"
+android_log-sys = "0.3.1"
 
 [lints]
 workspace = true

rust/connlib/clients/android/src/lib.rs

@@ -26,6 +26,8 @@ use tokio::runtime::Runtime;
 use tracing_subscriber::prelude::*;
 use tracing_subscriber::EnvFilter;
 
+mod make_writer;
+
 /// The Android client doesn't use platform APIs to detect network connectivity changes,
 /// so we rely on connlib to do so. We have valid use cases for headless Android clients
 /// (IoT devices, point-of-sale devices, etc), so try to reconnect for 30 days.
@@ -108,22 +110,6 @@ fn call_method(
         .map_err(|source| CallbackError::CallMethodFailed { name, source })
 }
 
-#[cfg(target_os = "android")]
-fn android_layer<S>() -> impl tracing_subscriber::Layer<S>
-where
-    S: tracing::Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>,
-{
-    tracing_android::layer("connlib").unwrap()
-}
-
-#[cfg(not(target_os = "android"))]
-fn android_layer<S>() -> impl tracing_subscriber::Layer<S>
-where
-    S: tracing::Subscriber,
-{
-    tracing_subscriber::layer::Identity::new()
-}
-
 fn init_logging(log_dir: &Path, log_filter: String) -> file_logger::Handle {
     // On Android, logging state is persisted indefinitely after the System.loadLibrary
     // call, which means that a disconnect and tunnel process restart will not
@@ -146,7 +132,14 @@ fn init_logging(log_dir: &Path, log_filter: String) -> file_logger::Handle {
 
     let _ = tracing_subscriber::registry()
         .with(file_layer.with_filter(EnvFilter::new(log_filter.clone())))
-        .with(android_layer().with_filter(EnvFilter::new(log_filter)))
+        .with(
+            tracing_subscriber::fmt::layer()
+                .with_ansi(false)
+                .without_time()
+                .with_level(false)
+                .with_writer(make_writer::MakeWriter::new("connlib"))
+                .with_filter(EnvFilter::new(log_filter)),
+        )
         .try_init();
 
     handle

rust/connlib/clients/android/src/make_writer.rs

@@ -0,0 +1,89 @@
+//! Heavily inspired from https://github.com/Actyx/tracing-android/blob/master/src/android.rs.
+
+use std::{
+    ffi::{CStr, CString},
+    io::{self, BufWriter},
+};
+use tracing::Level;
+
+const LOGGING_MSG_MAX_LEN: usize = 4000;
+
+pub(crate) struct MakeWriter {
+    tag: CString,
+}
+
+pub(crate) struct Writer {
+    level: Level,
+    tag: CString,
+}
+
+impl MakeWriter {
+    pub(crate) fn new(tag: &'static str) -> Self {
+        Self {
+            tag: CString::new(tag).expect("tag must not contain nul-byte"),
+        }
+    }
+
+    fn make_writer_for_level(&self, level: Level) -> BufWriter<Writer> {
+        let inner = Writer {
+            level,
+            tag: self.tag.clone(),
+        };
+
+        BufWriter::with_capacity(LOGGING_MSG_MAX_LEN, inner)
+    }
+}
+
+impl tracing_subscriber::fmt::MakeWriter<'_> for MakeWriter {
+    type Writer = BufWriter<Writer>;
+
+    fn make_writer(&self) -> Self::Writer {
+        self.make_writer_for_level(Level::INFO)
+    }
+
+    fn make_writer_for(&self, meta: &tracing::Metadata<'_>) -> Self::Writer {
+        self.make_writer_for_level(*meta.level())
+    }
+}
+
+impl io::Write for Writer {
+    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+        let written = buf.len().min(LOGGING_MSG_MAX_LEN);
+
+        let msg = &buf[..written];
+        let msg = CString::new(msg.to_vec())?;
+
+        android_log(self.level, self.tag.as_c_str(), &msg);
+
+        Ok(written)
+    }
+
+    fn flush(&mut self) -> io::Result<()> {
+        Ok(())
+    }
+}
+
+#[cfg(target_os = "android")]
+fn android_log(level: Level, tag: &CStr, msg: &CStr) {
+    let prio = match level {
+        Level::WARN => android_log_sys::LogPriority::WARN,
+        Level::INFO => android_log_sys::LogPriority::INFO,
+        Level::DEBUG => android_log_sys::LogPriority::DEBUG,
+        Level::ERROR => android_log_sys::LogPriority::ERROR,
+        Level::TRACE => android_log_sys::LogPriority::VERBOSE,
+    };
+
+    // Safety: FFI calls are unsafe.
+    unsafe {
+        android_log_sys::__android_log_write(
+            prio as android_log_sys::c_int,
+            tag.as_ptr() as *const android_log_sys::c_char,
+            msg.as_ptr() as *const android_log_sys::c_char,
+        )
+    };
+}
+
+#[cfg(not(target_os = "android"))]
+fn android_log(_: Level, _: &CStr, _: &CStr) {
+    unimplemented!("Logger is not meant to be used in non-Android environments")
+}

rust/connlib/clients/shared/Cargo.toml

@@ -29,7 +29,6 @@ phoenix-channel = { workspace = true }
 
 [target.'cfg(target_os = "android")'.dependencies]
 tracing = { workspace = true, features = ["std", "attributes"] }
-tracing-android = "0.2"
 
 [dev-dependencies]
 chrono = { workspace = true }

rust/connlib/shared/Cargo.toml

@@ -44,9 +44,6 @@ tokio = { version = "1.38", features = ["macros", "rt"] }
 [target.'cfg(any(target_os = "macos", target_os = "ios"))'.dependencies]
 swift-bridge = { workspace = true }
 
-[target.'cfg(target_os = "android")'.dependencies]
-tracing-android = "0.2"
-
 [target.'cfg(target_os = "linux")'.dependencies]
 netlink-packet-route = { version = "0.19", default-features = false }
 netlink-packet-core = { version = "0.7", default-features = false }

rust/connlib/tunnel/Cargo.toml

@@ -59,10 +59,6 @@ netlink-packet-route = { version = "0.19", default-features = false }
 netlink-packet-core = { version = "0.7", default-features = false }
 rtnetlink = { workspace = true }
 
-# Android tunnel dependencies
-[target.'cfg(target_os = "android")'.dependencies]
-tracing-android = "0.2"
-
 # Windows tunnel dependencies
 [target.'cfg(target_os = "windows")'.dependencies]
 uuid = { version = "1.7.0", features = ["v4"] }