DroidDeck/tools/xbox/droiddeck-credential-diagnostics.patch

diff --git a/crates/xodus/src/tokens/backend/keychain.rs b/crates/xodus/src/tokens/backend/keychain.rs
index 19480da..dc8f136 100644
--- a/crates/xodus/src/tokens/backend/keychain.rs
+++ b/crates/xodus/src/tokens/backend/keychain.rs
@@ -13,29 +13,24 @@ pub struct KeychainBackend;
 // keyed loopback port the app also listens on is used for the rest of the process.
 static LOOPBACK: AtomicBool = AtomicBool::new(false);
 static REPORTED: AtomicBool = AtomicBool::new(false);
+// The app seals credentials with the Android Keystore, which took over 10 s on some phones.
+const REPLY_TIMEOUT: Duration = Duration::from_secs(30);
 
-/// Letters and dashes only: the app passes `NEXUS_CREDENTIAL_ERROR_V1 [a-z-]{1,48}` lines to its log.
-fn reason(error: &std::io::Error) -> &'static str {
-    match error.raw_os_error() {
-        Some(111) => "refused",
-        Some(13) => "denied",
-        Some(1) => "not-permitted",
-        Some(2) => "missing",
-        Some(110) => "timed-out",
-        Some(38) => "unsupported",
-        Some(97) => "family-unsupported",
-        Some(22) => "invalid",
-        Some(104) => "reset",
-        Some(32) => "broken-pipe",
-        _ => match error.kind() {
-            std::io::ErrorKind::TimedOut | std::io::ErrorKind::WouldBlock => "timed-out",
-            std::io::ErrorKind::UnexpectedEof => "closed",
-            _ => "other",
-        },
-    }
+use crate::tokens::store::io_reason as reason;
+
+fn exchange<S: Read + Write>(stream: S, prefix: Option<&str>, value: &Value) -> Result<Value, TokenStoreError> {
+    let route = if prefix.is_some() { "loopback" } else { "socket" };
+    transfer(stream, prefix, value).inspect_err(|error| {
+        // Kind Other is the host's own refusal, already reported.
+        if let TokenStoreError::Io(error) = error
+            && error.kind() != std::io::ErrorKind::Other
+        {
+            eprintln!("NEXUS_CREDENTIAL_ERROR_V1 {route}-exchange-{}", reason(error));
+        }
+    })
 }
 
-fn exchange<S: Read + Write>(mut stream: S, prefix: Option<&str>, value: &Value) -> Result<Value, TokenStoreError> {
+fn transfer<S: Read + Write>(mut stream: S, prefix: Option<&str>, value: &Value) -> Result<Value, TokenStoreError> {
     if let Some(key) = prefix {
         stream.write_all(key.as_bytes())?;
         stream.write_all(b"\n")?;
@@ -45,6 +40,7 @@ fn exchange<S: Read + Write>(mut stream: S, prefix: Option<&str>, value: &Value)
     let mut bytes = Vec::new();
     std::io::BufReader::new(stream).take(2_097_153).read_until(b'\n', &mut bytes)?;
     if bytes.len() > 2_097_152 || bytes.last() != Some(&b'\n') {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 host-response-invalid");
         return Err(std::io::Error::other("Invalid Android credential response").into());
     }
     let response: Value = serde_json::from_slice(&bytes)?;
@@ -56,28 +52,36 @@ fn exchange<S: Read + Write>(mut stream: S, prefix: Option<&str>, value: &Value)
 }
 
 fn loopback(value: &Value) -> Result<Value, TokenStoreError> {
-    let port: u16 = std::env::var("DROIDDECK_XBOX_CREDENTIAL_PORT").ok().and_then(|v| v.parse().ok())
-        .ok_or_else(|| std::io::Error::other("Android credential port is unavailable"))?;
-    let key = std::env::var("DROIDDECK_XBOX_CREDENTIAL_KEY")
-        .map_err(|_| std::io::Error::other("Android credential key is unavailable"))?;
+    let port: u16 = std::env::var("DROIDDECK_XBOX_CREDENTIAL_PORT").ok().and_then(|v| v.parse().ok()).ok_or_else(|| {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 loopback-port-missing");
+        std::io::Error::other("Android credential port is unavailable")
+    })?;
+    let key = std::env::var("DROIDDECK_XBOX_CREDENTIAL_KEY").map_err(|_| {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 loopback-key-missing");
+        std::io::Error::other("Android credential key is unavailable")
+    })?;
     let address = SocketAddrV4::new(Ipv4Addr::LOCALHOST, port).into();
     let stream = TcpStream::connect_timeout(&address, Duration::from_secs(5)).inspect_err(|error| {
         eprintln!("NEXUS_CREDENTIAL_ERROR_V1 loopback-{}", reason(error));
     })?;
-    stream.set_read_timeout(Some(Duration::from_secs(10)))?;
-    stream.set_write_timeout(Some(Duration::from_secs(10)))?;
+    stream.set_read_timeout(Some(REPLY_TIMEOUT))?;
+    stream.set_write_timeout(Some(REPLY_TIMEOUT))?;
     exchange(stream, Some(&key), value)
 }
 
 fn request(value: Value) -> Result<Value, TokenStoreError> {
     if LOOPBACK.load(Ordering::Relaxed) { return loopback(&value); }
-    let name = std::env::var("DROIDDECK_XBOX_CREDENTIAL_SOCKET")
-        .map_err(|_| std::io::Error::other("Android credential host is unavailable"))?;
-    let address = SocketAddr::from_abstract_name(name)?;
+    let name = std::env::var("DROIDDECK_XBOX_CREDENTIAL_SOCKET").map_err(|_| {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 socket-name-missing");
+        std::io::Error::other("Android credential host is unavailable")
+    })?;
+    let address = SocketAddr::from_abstract_name(name).inspect_err(|_| {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 socket-name-invalid");
+    })?;
     match UnixStream::connect_addr(&address) {
         Ok(stream) => {
-            stream.set_read_timeout(Some(Duration::from_secs(10)))?;
-            stream.set_write_timeout(Some(Duration::from_secs(10)))?;
+            stream.set_read_timeout(Some(REPLY_TIMEOUT))?;
+            stream.set_write_timeout(Some(REPLY_TIMEOUT))?;
             exchange(stream, None, &value)
         }
         Err(error) => {
diff --git a/crates/xodus/src/tokens/session.rs b/crates/xodus/src/tokens/session.rs
index 38c4b2b..254c14f 100644
--- a/crates/xodus/src/tokens/session.rs
+++ b/crates/xodus/src/tokens/session.rs
@@ -44,14 +44,30 @@ async fn renewal_lock_at(
     wait: WaitDuration,
 ) -> std::io::Result<std::fs::File> {
     use std::os::unix::fs::{DirBuilderExt, MetadataExt, OpenOptionsExt};
+    fn report(stage: &'static str) -> impl Fn(&std::io::Error) {
+        move |error| eprintln!("NEXUS_CREDENTIAL_ERROR_V1 lock-{stage}-{}", super::store::io_reason(error))
+    }
+    fn unsafe_lock(stage: &str, check: &str) -> std::io::Error {
+        eprintln!("NEXUS_CREDENTIAL_ERROR_V1 lock-{stage}-{check}");
+        std::io::Error::other(if stage == "dir" { "Unsafe session lock directory" } else { "Unsafe session lock" })
+    }
     match std::fs::DirBuilder::new().mode(0o700).create(&root) {
         Ok(()) => {}
         Err(error) if error.kind() == std::io::ErrorKind::AlreadyExists => {}
-        Err(error) => return Err(error),
+        Err(error) => {
+            report("dir-create")(&error);
+            return Err(error);
+        }
+    }
+    let dir = std::fs::symlink_metadata(&root).inspect_err(report("dir-stat"))?;
+    if !dir.is_dir() {
+        return Err(unsafe_lock("dir", "type"));
+    }
+    if dir.uid() != uid {
+        return Err(unsafe_lock("dir", "owner"));
     }
-    let dir = std::fs::symlink_metadata(&root)?;
-    if !dir.is_dir() || dir.uid() != uid || dir.mode() & 0o077 != 0 {
-        return Err(std::io::Error::other("Unsafe session lock directory"));
+    if dir.mode() & 0o077 != 0 {
+        return Err(unsafe_lock("dir", "mode"));
     }
     let file = std::fs::OpenOptions::new()
         .read(true)
@@ -60,10 +76,20 @@ async fn renewal_lock_at(
         .truncate(false)
         .mode(0o600)
         .custom_flags(libc::O_NOFOLLOW | libc::O_CLOEXEC)
-        .open(root.join("device.lock"))?;
-    let meta = file.metadata()?;
-    if !meta.is_file() || meta.uid() != uid || meta.nlink() != 1 || meta.mode() & 0o077 != 0 {
-        return Err(std::io::Error::other("Unsafe session lock"));
+        .open(root.join("device.lock"))
+        .inspect_err(report("file-open"))?;
+    let meta = file.metadata().inspect_err(report("file-stat"))?;
+    if !meta.is_file() {
+        return Err(unsafe_lock("file", "type"));
+    }
+    if meta.uid() != uid {
+        return Err(unsafe_lock("file", "owner"));
+    }
+    if meta.nlink() != 1 {
+        return Err(unsafe_lock("file", "links"));
+    }
+    if meta.mode() & 0o077 != 0 {
+        return Err(unsafe_lock("file", "mode"));
     }
     let deadline = tokio::time::Instant::now() + wait;
     loop {
@@ -75,7 +101,10 @@ async fn renewal_lock_at(
             {
                 tokio::time::sleep(WaitDuration::from_millis(100)).await
             }
-            Err(error) => return Err(error),
+            Err(error) => {
+                report("flock")(&error);
+                return Err(error);
+            }
         }
     }
 }
diff --git a/crates/xodus/src/tokens/store.rs b/crates/xodus/src/tokens/store.rs
index 78b73d0..15cbff0 100644
--- a/crates/xodus/src/tokens/store.rs
+++ b/crates/xodus/src/tokens/store.rs
@@ -50,3 +50,51 @@ impl TokenStoreError {
         eprintln!("{self}");
     }
 }
+
+/// Letters and dashes only: DroidDeck passes `NEXUS_CREDENTIAL_ERROR_V1 [a-z-]{1,48}` lines to its
+/// log. Unlisted errno values are spelled with letters, a = 0 ... j = 9 (`os-dh` = errno 37).
+pub(crate) fn io_reason(error: &std::io::Error) -> String {
+    let known = match error.raw_os_error() {
+        Some(111) => "refused",
+        Some(13) => "denied",
+        Some(1) => "not-permitted",
+        Some(2) => "missing",
+        Some(110) => "timed-out",
+        Some(38) => "unsupported",
+        Some(97) => "family-unsupported",
+        Some(22) => "invalid",
+        Some(104) => "reset",
+        Some(32) => "broken-pipe",
+        Some(4) => "interrupted",
+        Some(11) => "would-block",
+        Some(17) => "exists",
+        Some(20) => "not-directory",
+        Some(21) => "is-directory",
+        Some(28) => "no-space",
+        Some(30) => "read-only",
+        Some(37) => "no-locks",
+        Some(40) => "symlink-loop",
+        Some(95) => "not-supported",
+        Some(code) => {
+            let letters: String = code.unsigned_abs().to_string().bytes().map(|b| (b - b'0' + b'a') as char).collect();
+            return format!("os-{letters}");
+        }
+        None => match error.kind() {
+            std::io::ErrorKind::TimedOut | std::io::ErrorKind::WouldBlock => "timed-out",
+            std::io::ErrorKind::UnexpectedEof => "closed",
+            _ => "other",
+        },
+    };
+    known.to_string()
+}
+
+#[cfg(test)]
+mod io_reason_tests {
+    #[test]
+    fn io_reason_is_letters_and_dashes() {
+        for (code, expected) in [(37, "no-locks"), (13, "denied"), (99, "os-jj"), (125, "os-bcf")] {
+            assert_eq!(super::io_reason(&std::io::Error::from_raw_os_error(code)), expected);
+        }
+        assert_eq!(super::io_reason(&std::io::Error::other("x")), "other");
+    }
+}