From ecf887fc616cfea1d3dd1a9a4d33fe2ffe0a5a0c Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 17:26:49 +0100 Subject: [PATCH 01/10] docs: add logging policy Defines tracing level semantics (error for library faults only, warn for unexpected device behaviour, info for sparse lifecycle, debug for protocol flow and lengths, trace for raw bytes), the sensitive-data rule, and the static-message-with-structured-fields form. Closes the policy half of #223. --- docs/logging.md | 126 ++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 126 insertions(+) create mode 100644 docs/logging.md diff --git a/docs/logging.md b/docs/logging.md new file mode 100644 index 00000000..e262b7cd --- /dev/null +++ b/docs/logging.md @@ -0,0 +1,126 @@ +# Logging policy + +libwebauthn uses the [`tracing`](https://docs.rs/tracing) crate for all +diagnostics. This document defines how to choose a level, what must never be +logged, and how to write the call. The mechanical rules are enforced by a custom +dylint lint (see [Enforcement](#enforcement)). + +## Principles + +1. libwebauthn is a library, not an application. Errors reach the caller through + `Result`. Logging is for diagnosis and must not drive control flow. +2. A run at the default level must be quiet and safe to share. An INFO-level log + should be safe to paste into a bug report, with no secrets and no per-packet + noise. +3. Messages are static. Dynamic data goes into structured fields so logs stay + greppable and machine-parseable. + +## Levels + +Choose the level by the nature of the event, not by how much you care about it. + +### `error!` + +Only for faults inside libwebauthn itself: a broken invariant, an unreachable +state, a bug. If correct library code cannot produce the condition, it belongs +at `error!`. + +Not for: a device returning a CTAP error status, an IO or transport failure, a +timeout, user cancellation, or an authenticator rejecting a request. Those are +returned to the caller and logged at `warn!` or lower. + +### `warn!` + +Unexpected behaviour from the device or peer, and recoverable anomalies the +operator may want to know about. For example a malformed or out-of-spec response +that we can still handle, a fallback to a less preferred protocol, an unexpected +field we ignore, or a non-fatal failure we continue past. + +### `info!` + +Sparse, high-level lifecycle events meaningful to an operator. For example +enumerating devices, establishing a connection, selecting a transport or FIDO +revision, or the start and end of a ceremony. INFO carries no sensitive data and +never appears inside a loop or per packet. + +### `debug!` + +Developer-facing protocol flow: command and response codes, status, lengths, +small non-sensitive fields, and state transitions. Byte arrays appear here only +as their length. Sensitive values appear here only as a length or a presence +flag, never in full. + +### `trace!` + +Raw wire data: full byte arrays, raw CBOR and APDU buffers, full request and +response structures, per-packet dumps. This is the only level at which a raw +secret may appear. + +## Sensitive data + +These are sensitive and must never be logged above `debug!`: + +- PINs, PIN hashes, and PIN tokens +- shared secrets and key-agreement material +- `pinUvAuthToken` and `pinUvAuthParam` +- HMAC salts and outputs, and PRF values +- large-blob plaintext +- private keys +- credential IDs +- user handles and user names + +At `debug!` log only a length or a presence flag. A full value may appear only +at `trace!`. + +## How to write a log call + +The message is always a static string literal. Never interpolate (`"{x}"`) and +never pass `format!`. Put dynamic data in fields. + +- Use `%value` for `Display` and `?value` for `Debug`. +- Name fields in snake_case: `field = value`. +- One field: bare. Two or more: a brace block. + +```rust +// one field: bare +warn!(?err, "Authenticator returned a malformed response"); + +// two or more fields: brace block +debug!({ rp_id = %rp_id, cred_count = creds.len() }, "Starting preflight"); + +// byte arrays: length at debug, full bytes at trace +debug!(len = apdu.len(), "Received APDU"); +trace!(?apdu, "Received APDU"); +``` + +Prefer a span over repeating the same field on every event. A ceremony or a +transport can open a span carrying shared context such as the transport and the +rp_id. + +Do not use `println!`, `eprintln!`, or the `log` crate's macros in the library. +Everything goes through `tracing`. + +## Enforcement + +A custom dylint lint in [`lints/`](../lints) checks the mechanical rules: + +- the message must be a static string literal, with no interpolation or + `format!` +- no `println!`, `eprintln!`, `print!`, or `eprint!` +- no `log::` macros +- a best-effort denylist flags sensitive field names (pin, secret, token, and so + on) used at `info!` and above + +Level choice, and whether a particular value is sensitive, cannot be decided by a +tool. Those rules are upheld in review against this document. + +Run it locally: + +```sh +cargo install cargo-dylint dylint-link # once +cargo dylint --all --workspace -- --all-features +``` + +CI runs the same command on every push. The three deterministic lints fail the +build. The sensitive-field heuristic stays a warning, since whether a value is +sensitive cannot be decided by a tool. From 6bbb4baac84cb4d628270b3cd132ebc3f95af505 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:19:15 +0100 Subject: [PATCH 02/10] build(lint): add dylint logging lints and CI A logging_lints dylint library enforcing the mechanical parts of the logging policy: - tracing_message_interpolation: messages must be static string literals - print_macro_in_library: no print/println/eprint/eprintln - log_crate_macro: no log crate macros - sensitive_field_above_debug: best-effort denylist at info and above Registered in the workspace metadata and run in CI, where the three deterministic lints fail the build. The heuristic stays a warning. --- .github/workflows/dylint.yml | 38 + Cargo.toml | 5 + lints/logging_lints/.cargo/config.toml | 6 + lints/logging_lints/.gitignore | 1 + lints/logging_lints/Cargo.lock | 1581 ++++++++++++++++++++++++ lints/logging_lints/Cargo.toml | 22 + lints/logging_lints/README.md | 40 + lints/logging_lints/rust-toolchain | 3 + lints/logging_lints/src/lib.rs | 394 ++++++ lints/logging_lints/ui/main.rs | 65 + lints/logging_lints/ui/main.stderr | 109 ++ 11 files changed, 2264 insertions(+) create mode 100644 .github/workflows/dylint.yml create mode 100644 lints/logging_lints/.cargo/config.toml create mode 100644 lints/logging_lints/.gitignore create mode 100644 lints/logging_lints/Cargo.lock create mode 100644 lints/logging_lints/Cargo.toml create mode 100644 lints/logging_lints/README.md create mode 100644 lints/logging_lints/rust-toolchain create mode 100644 lints/logging_lints/src/lib.rs create mode 100644 lints/logging_lints/ui/main.rs create mode 100644 lints/logging_lints/ui/main.stderr diff --git a/.github/workflows/dylint.yml b/.github/workflows/dylint.yml new file mode 100644 index 00000000..4e9dbf1b --- /dev/null +++ b/.github/workflows/dylint.yml @@ -0,0 +1,38 @@ +name: Logging policy lints + +on: [push, pull_request] + +jobs: + dylint: + name: dylint logging policy + runs-on: ubuntu-latest + steps: + - uses: actions/checkout@v2 + - name: Checkout submodules + run: git submodule update --init --recursive + - name: Update apt cache + run: sudo apt-get update + - name: Install system dependencies + run: sudo apt-get install libudev-dev libdbus-1-dev libsodium-dev libnfc-dev libpcsclite-dev + - name: Install Rust (stable, builds cargo-dylint) + uses: actions-rs/toolchain@16499b5e05bf2e26879000db0c1d13f7e13fa3af #@v1 + with: + profile: minimal + toolchain: stable + override: true + - name: Install the lint toolchain + run: | + TOOLCHAIN=$(grep '^channel' lints/logging_lints/rust-toolchain | sed -E 's/.*"(.*)".*/\1/') + rustup toolchain install "$TOOLCHAIN" --profile minimal -c rustc-dev -c llvm-tools-preview + - name: Install cargo-dylint + run: cargo install cargo-dylint dylint-link + - name: Run logging policy lints + # The three deterministic lints fail the build. The sensitive-field + # heuristic stays a warning, as documented in docs/logging.md. + run: | + set -o pipefail + cargo dylint --all --workspace -- --all-features 2>&1 | tee dylint.log + if grep -qE 'dylint::(tracing_message_interpolation|print_macro_in_library|log_crate_macro)' dylint.log; then + echo "::error::Logging policy violations found, see docs/logging.md" + exit 1 + fi diff --git a/Cargo.toml b/Cargo.toml index af703773..f32fc689 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -2,6 +2,11 @@ resolver = "2" members = ["libwebauthn", "libwebauthn-tests"] +# Custom dylint lints enforcing the logging policy (docs/logging.md). +# Run with `cargo dylint --all --workspace -- --all-features`. +[workspace.metadata.dylint] +libraries = [{ path = "lints/logging_lints" }] + # The trussed ecosystem is currently a bit messy, so we have to do some patching of the versions [patch.crates-io] trussed = { git = "https://github.com/trussed-dev/trussed.git", rev = "024e0eca5fb7dbd2457831f7c7bffe4341e08775" } diff --git a/lints/logging_lints/.cargo/config.toml b/lints/logging_lints/.cargo/config.toml new file mode 100644 index 00000000..226eca53 --- /dev/null +++ b/lints/logging_lints/.cargo/config.toml @@ -0,0 +1,6 @@ +[target.'cfg(all())'] +rustflags = ["-C", "linker=dylint-link"] + +# For Rust versions 1.74.0 and onward, the following alternative can be used +# (see https://github.com/rust-lang/cargo/pull/12535): +# linker = "dylint-link" diff --git a/lints/logging_lints/.gitignore b/lints/logging_lints/.gitignore new file mode 100644 index 00000000..ea8c4bf7 --- /dev/null +++ b/lints/logging_lints/.gitignore @@ -0,0 +1 @@ +/target diff --git a/lints/logging_lints/Cargo.lock b/lints/logging_lints/Cargo.lock new file mode 100644 index 00000000..b51d9ade --- /dev/null +++ b/lints/logging_lints/Cargo.lock @@ -0,0 +1,1581 @@ +# This file is automatically @generated by Cargo. +# It is not intended for manual editing. +version = 4 + +[[package]] +name = "aho-corasick" +version = "1.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ddd31a130427c27518df266943a5308ed92d4b226cc639f5a8f1002816174301" +dependencies = [ + "memchr", +] + +[[package]] +name = "anstream" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "824a212faf96e9acacdbd09febd34438f8f711fb84e09a8916013cd7815ca28d" +dependencies = [ + "anstyle", + "anstyle-parse", + "anstyle-query", + "anstyle-wincon", + "colorchoice", + "is_terminal_polyfill", + "utf8parse", +] + +[[package]] +name = "anstyle" +version = "1.0.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "940b3a0ca603d1eade50a4846a2afffd5ef57a9feac2c0e2ec2e14f9ead76000" + +[[package]] +name = "anstyle-parse" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "52ce7f38b242319f7cabaa6813055467063ecdc9d355bbb4ce0c68908cd8130e" +dependencies = [ + "utf8parse", +] + +[[package]] +name = "anstyle-query" +version = "1.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "40c48f72fd53cd289104fc64099abca73db4166ad86ea0b4341abe65af83dadc" +dependencies = [ + "windows-sys 0.61.2", +] + +[[package]] +name = "anstyle-wincon" +version = "3.0.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "291e6a250ff86cd4a820112fb8898808a366d8f9f58ce16d1f538353ad55747d" +dependencies = [ + "anstyle", + "once_cell_polyfill", + "windows-sys 0.61.2", +] + +[[package]] +name = "anyhow" +version = "1.0.102" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7f202df86484c868dbad7eaa557ef785d5c66295e41b460ef922eca0723b842c" + +[[package]] +name = "bitflags" +version = "2.13.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b4388bee8683e3d04af747c73422af53102d2bd24d9eadb6cbc100baef4b43f8" + +[[package]] +name = "camino" +version = "1.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e629a66d692cb9ff1a1c664e41771b3dcaf961985a9774c0eb0bd1b51cf60a48" +dependencies = [ + "serde_core", +] + +[[package]] +name = "cargo-platform" +version = "0.3.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dd0061da739915fae12ea00e16397555ed4371a6bb285431aab930f61b0aa4ba" +dependencies = [ + "serde", + "serde_core", +] + +[[package]] +name = "cargo_metadata" +version = "0.23.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ef987d17b0a113becdd19d3d0022d04d7ef41f9efe4f3fb63ac44ba61df3ade9" +dependencies = [ + "camino", + "cargo-platform", + "semver", + "serde", + "serde_json", + "thiserror 2.0.18", +] + +[[package]] +name = "cc" +version = "1.2.63" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "556e016178bb5662a08681bbe0f00f8e17631781a4dfc8c45e466e4b185ec27f" +dependencies = [ + "find-msvc-tools", + "jobserver", + "libc", + "shlex", +] + +[[package]] +name = "cfg-if" +version = "1.0.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9330f8b2ff13f34540b44e946ef35111825727b38d33286ef986142615121801" + +[[package]] +name = "colorchoice" +version = "1.0.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1d07550c9036bf2ae0c684c4297d503f838287c83c53686d05370d0e139ae570" + +[[package]] +name = "compiletest_rs" +version = "0.11.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f150fe9105fcd2a57cad53f0c079a24de65195903ef670990f5909f695eac04c" +dependencies = [ + "diff", + "filetime", + "getopts", + "lazy_static", + "libc", + "log", + "miow", + "regex", + "rustfix", + "serde", + "serde_derive", + "serde_json", + "tester", + "windows-sys 0.59.0", +] + +[[package]] +name = "diff" +version = "0.1.13" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "56254986775e3233ffa9c4d7d3faaf6d36a2c09d30b20687e9f88bc8bafc16c8" + +[[package]] +name = "dirs-next" +version = "2.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b98cf8ebf19c3d1b223e151f99a4f9f0690dca41414773390fc824184ac833e1" +dependencies = [ + "cfg-if", + "dirs-sys-next", +] + +[[package]] +name = "dirs-sys-next" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4ebda144c4fe02d1f7ea1a7d9641b6fc6b580adcfa024ae48797ecdeb6825b4d" +dependencies = [ + "libc", + "redox_users", + "winapi", +] + +[[package]] +name = "displaydoc" +version = "0.2.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ac70aa55017e108007fbaf5aa0f54b021c98f92ff8af59d42eda9da96e3dd4f" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "dylint" +version = "6.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c738fb72ea7d248df2995a31b3698beb63d0f1f9ca5a5dc0188c4b64cd0e86e4" +dependencies = [ + "anstyle", + "anyhow", + "cargo_metadata", + "dylint_internal", + "log", + "once_cell", + "semver", + "serde", + "serde_json", + "tempfile", +] + +[[package]] +name = "dylint_internal" +version = "6.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9796d3441d7894cbaf4992640799efffc1661978f0cc1266ec788c32254fdfb3" +dependencies = [ + "anstyle", + "anyhow", + "bitflags", + "cargo_metadata", + "git2", + "home", + "log", + "regex", + "serde", + "tar", + "thiserror 2.0.18", + "toml", +] + +[[package]] +name = "dylint_linting" +version = "6.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c213635b3eaa84f43b9b497377f17d9a8d4feb413bab1d82e03ad1c73e4f6d8c" +dependencies = [ + "cargo_metadata", + "dylint_internal", + "paste", + "rustversion", + "serde", + "thiserror 2.0.18", + "toml", +] + +[[package]] +name = "dylint_testing" +version = "6.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4f5f50ee06be9ebfb5b9538ba0d7bb08adc33e8f31c901e7d398de2a9b1ae290" +dependencies = [ + "anyhow", + "cargo_metadata", + "compiletest_rs", + "dylint", + "dylint_internal", + "env_logger", + "once_cell", + "regex", + "serde_json", + "tempfile", +] + +[[package]] +name = "env_filter" +version = "1.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32e90c2accc4b07a8456ea0debdc2e7587bdd890680d71173a15d4ae604f6eef" +dependencies = [ + "log", + "regex", +] + +[[package]] +name = "env_logger" +version = "0.11.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0621c04f2196ac3f488dd583365b9c09be011a4ab8b9f37248ffcc8f6198b56a" +dependencies = [ + "anstream", + "anstyle", + "env_filter", + "jiff", + "log", +] + +[[package]] +name = "equivalent" +version = "1.0.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "877a4ace8713b0bcf2a4e7eec82529c029f1d0619886d18145fea96c3ffe5c0f" + +[[package]] +name = "errno" +version = "0.3.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "39cab71617ae0d63f51a36d69f866391735b51691dbda63cf6f96d042b63efeb" +dependencies = [ + "libc", + "windows-sys 0.61.2", +] + +[[package]] +name = "fastrand" +version = "2.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9f1f227452a390804cdb637b74a86990f2a7d7ba4b7d5693aac9b4dd6defd8d6" + +[[package]] +name = "filetime" +version = "0.2.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c287a33c7f0a620c38e641e7f60827713987b3c0f26e8ddc9462cc69cf75759" +dependencies = [ + "cfg-if", + "libc", +] + +[[package]] +name = "find-msvc-tools" +version = "0.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5baebc0774151f905a1a2cc41989300b1e6fbb29aff0ceffa1064fdd3088d582" + +[[package]] +name = "foldhash" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d9c4f5dac5e15c24eb999c26181a6ca40b39fe946cbe4c263c7209467bc83af2" + +[[package]] +name = "form_urlencoded" +version = "1.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cb4cb245038516f5f85277875cdaa4f7d2c9a0fa0468de06ed190163b1581fcf" +dependencies = [ + "percent-encoding", +] + +[[package]] +name = "getopts" +version = "0.2.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cfe4fbac503b8d1f88e6676011885f34b7174f46e59956bba534ba83abded4df" +dependencies = [ + "unicode-width", +] + +[[package]] +name = "getrandom" +version = "0.2.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ff2abc00be7fca6ebc474524697ae276ad847ad0a6b3faa4bcb027e9a4614ad0" +dependencies = [ + "cfg-if", + "libc", + "wasi", +] + +[[package]] +name = "getrandom" +version = "0.3.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "899def5c37c4fd7b2664648c28120ecec138e4d395b459e5ca34f9cce2dd77fd" +dependencies = [ + "cfg-if", + "libc", + "r-efi 5.3.0", + "wasip2", +] + +[[package]] +name = "getrandom" +version = "0.4.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0de51e6874e94e7bf76d726fc5d13ba782deca734ff60d5bb2fb2607c7406555" +dependencies = [ + "cfg-if", + "libc", + "r-efi 6.0.0", + "wasip2", + "wasip3", +] + +[[package]] +name = "git2" +version = "0.20.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7b88256088d75a56f8ecfa070513a775dd9107f6530ef14919dac831af9cfe2b" +dependencies = [ + "bitflags", + "libc", + "libgit2-sys", + "log", + "openssl-probe", + "openssl-sys", + "url", +] + +[[package]] +name = "hashbrown" +version = "0.15.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9229cfe53dfd69f0609a49f65461bd93001ea1ef889cd5529dd176593f5338a1" +dependencies = [ + "foldhash", +] + +[[package]] +name = "hashbrown" +version = "0.17.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ed5909b6e89a2db4456e54cd5f673791d7eca6732202bbf2a9cc504fe2f9b84a" + +[[package]] +name = "heck" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2304e00983f87ffb38b55b444b5e3b60a884b5d30c0fca7d82fe33449bbe55ea" + +[[package]] +name = "hermit-abi" +version = "0.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fc0fef456e4baa96da950455cd02c081ca953b141298e41db3fc7e36b1da849c" + +[[package]] +name = "home" +version = "0.5.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cc627f471c528ff0c4a49e1d5e60450c8f6461dd6d10ba9dcd3a61d3dff7728d" +dependencies = [ + "windows-sys 0.61.2", +] + +[[package]] +name = "icu_collections" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2984d1cd16c883d7935b9e07e44071dca8d917fd52ecc02c04d5fa0b5a3f191c" +dependencies = [ + "displaydoc", + "potential_utf", + "utf8_iter", + "yoke", + "zerofrom", + "zerovec", +] + +[[package]] +name = "icu_locale_core" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "92219b62b3e2b4d88ac5119f8904c10f8f61bf7e95b640d25ba3075e6cac2c29" +dependencies = [ + "displaydoc", + "litemap", + "tinystr", + "writeable", + "zerovec", +] + +[[package]] +name = "icu_normalizer" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c56e5ee99d6e3d33bd91c5d85458b6005a22140021cc324cea84dd0e72cff3b4" +dependencies = [ + "icu_collections", + "icu_normalizer_data", + "icu_properties", + "icu_provider", + "smallvec", + "zerovec", +] + +[[package]] +name = "icu_normalizer_data" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "da3be0ae77ea334f4da67c12f149704f19f81d1adf7c51cf482943e84a2bad38" + +[[package]] +name = "icu_properties" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bee3b67d0ea5c2cca5003417989af8996f8604e34fb9ddf96208a033901e70de" +dependencies = [ + "icu_collections", + "icu_locale_core", + "icu_properties_data", + "icu_provider", + "zerotrie", + "zerovec", +] + +[[package]] +name = "icu_properties_data" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8e2bbb201e0c04f7b4b3e14382af113e17ba4f63e2c9d2ee626b720cbce54a14" + +[[package]] +name = "icu_provider" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "139c4cf31c8b5f33d7e199446eff9c1e02decfc2f0eec2c8d71f65befa45b421" +dependencies = [ + "displaydoc", + "icu_locale_core", + "writeable", + "yoke", + "zerofrom", + "zerotrie", + "zerovec", +] + +[[package]] +name = "id-arena" +version = "2.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3d3067d79b975e8844ca9eb072e16b31c3c1c36928edf9c6789548c524d0d954" + +[[package]] +name = "idna" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3b0875f23caa03898994f6ddc501886a45c7d3d62d04d2d90788d47be1b1e4de" +dependencies = [ + "idna_adapter", + "smallvec", + "utf8_iter", +] + +[[package]] +name = "idna_adapter" +version = "1.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cb68373c0d6620ef8105e855e7745e18b0d00d3bdb07fb532e434244cdb9a714" +dependencies = [ + "icu_normalizer", + "icu_properties", +] + +[[package]] +name = "indexmap" +version = "2.14.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d466e9454f08e4a911e14806c24e16fba1b4c121d1ea474396f396069cf949d9" +dependencies = [ + "equivalent", + "hashbrown 0.17.1", + "serde", + "serde_core", +] + +[[package]] +name = "is_terminal_polyfill" +version = "1.70.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a6cb138bb79a146c1bd460005623e142ef0181e3d0219cb493e02f7d08a35695" + +[[package]] +name = "itoa" +version = "1.0.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8f42a60cbdf9a97f5d2305f08a87dc4e09308d1276d28c869c684d7777685682" + +[[package]] +name = "jiff" +version = "0.2.28" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4603d3033e49e2b0e31229fcab20a5d40089c607d975cd9c80551dc69eed9102" +dependencies = [ + "jiff-static", + "log", + "portable-atomic", + "portable-atomic-util", + "serde_core", +] + +[[package]] +name = "jiff-static" +version = "0.2.28" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "782d32378dddf207193ac91cefb848ad41abb58195c95168e1291227a0832b47" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "jobserver" +version = "0.1.34" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9afb3de4395d6b3e67a780b6de64b51c978ecf11cb9a462c66be7d4ca9039d33" +dependencies = [ + "getrandom 0.3.4", + "libc", +] + +[[package]] +name = "lazy_static" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" + +[[package]] +name = "leb128fmt" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2" + +[[package]] +name = "libc" +version = "0.2.186" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "68ab91017fe16c622486840e4c83c9a37afeff978bd239b5293d61ece587de66" + +[[package]] +name = "libgit2-sys" +version = "0.18.5+1.9.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "005d6ae6eac1912906073e069f7db60b1fa98e052a68227824afe3e3a1c59ca2" +dependencies = [ + "cc", + "libc", + "libssh2-sys", + "libz-sys", + "openssl-sys", + "pkg-config", +] + +[[package]] +name = "libredox" +version = "0.1.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f02ab6bace2054fb888a3c16f990117b579d14a3088e472d63c6011fa185c9d3" +dependencies = [ + "libc", +] + +[[package]] +name = "libssh2-sys" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "220e4f05ad4a218192533b300327f5150e809b54c4ec83b5a1d91833601811b9" +dependencies = [ + "cc", + "libc", + "libz-sys", + "openssl-sys", + "pkg-config", + "vcpkg", +] + +[[package]] +name = "libz-sys" +version = "1.1.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85bc9657773828b90eeb625adff10eeac83cc21bbfd8e23a03eaa8a33c9e28d9" +dependencies = [ + "cc", + "libc", + "pkg-config", + "vcpkg", +] + +[[package]] +name = "linux-raw-sys" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32a66949e030da00e8c7d4434b251670a91556f4144941d37452769c25d58a53" + +[[package]] +name = "litemap" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "92daf443525c4cce67b150400bc2316076100ce0b3686209eb8cf3c31612e6f0" + +[[package]] +name = "log" +version = "0.4.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "953f07c43838f8e6f9758cab68bf5bed85465e7587ebe0b823f1bcd81978ad3a" + +[[package]] +name = "logging_lints" +version = "0.1.0" +dependencies = [ + "dylint_linting", + "dylint_testing", +] + +[[package]] +name = "memchr" +version = "2.8.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6b947ae49db0d222b1dbc6b113ce7248a3fc3a6ca21b696717bfc000ba4484d8" + +[[package]] +name = "miow" +version = "0.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "536bfad37a309d62069485248eeaba1e8d9853aaf951caaeaed0585a95346f08" +dependencies = [ + "windows-sys 0.61.2", +] + +[[package]] +name = "num_cpus" +version = "1.17.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "91df4bbde75afed763b708b7eee1e8e7651e02d97f6d5dd763e89367e957b23b" +dependencies = [ + "hermit-abi", + "libc", +] + +[[package]] +name = "once_cell" +version = "1.21.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9f7c3e4beb33f85d45ae3e3a1792185706c8e16d043238c593331cc7cd313b50" + +[[package]] +name = "once_cell_polyfill" +version = "1.70.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "384b8ab6d37215f3c5301a95a4accb5d64aa607f1fcb26a11b5303878451b4fe" + +[[package]] +name = "openssl-probe" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d05e27ee213611ffe7d6348b942e8f942b37114c00cc03cec254295a4a17852e" + +[[package]] +name = "openssl-sys" +version = "0.9.116" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f28a22dc7140cda5f096e5e7724a6962ca81a7f8bfd2979f9b18c11af56318c4" +dependencies = [ + "cc", + "libc", + "pkg-config", + "vcpkg", +] + +[[package]] +name = "paste" +version = "1.0.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "57c0d7b74b563b49d38dae00a0c37d4d6de9b432382b2892f0574ddcae73fd0a" + +[[package]] +name = "percent-encoding" +version = "2.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9b4f627cb1b25917193a259e49bdad08f671f8d9708acfd5fe0a8c1455d87220" + +[[package]] +name = "pin-project-lite" +version = "0.2.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a89322df9ebe1c1578d689c92318e070967d1042b512afbe49518723f4e6d5cd" + +[[package]] +name = "pkg-config" +version = "0.3.33" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "19f132c84eca552bf34cab8ec81f1c1dcc229b811638f9d283dceabe58c5569e" + +[[package]] +name = "portable-atomic" +version = "1.13.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c33a9471896f1c69cecef8d20cbe2f7accd12527ce60845ff44c153bb2a21b49" + +[[package]] +name = "portable-atomic-util" +version = "0.2.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c2a106d1259c23fac8e543272398ae0e3c0b8d33c88ed73d0cc71b0f1d902618" +dependencies = [ + "portable-atomic", +] + +[[package]] +name = "potential_utf" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0103b1cef7ec0cf76490e969665504990193874ea05c85ff9bab8b911d0a0564" +dependencies = [ + "zerovec", +] + +[[package]] +name = "prettyplease" +version = "0.2.37" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "479ca8adacdd7ce8f1fb39ce9ecccbfe93a3f1344b3d0d97f20bc0196208f62b" +dependencies = [ + "proc-macro2", + "syn", +] + +[[package]] +name = "proc-macro2" +version = "1.0.106" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8fd00f0bb2e90d81d1044c2b32617f68fcb9fa3bb7640c23e9c748e53fb30934" +dependencies = [ + "unicode-ident", +] + +[[package]] +name = "quote" +version = "1.0.45" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "41f2619966050689382d2b44f664f4bc593e129785a36d6ee376ddf37259b924" +dependencies = [ + "proc-macro2", +] + +[[package]] +name = "r-efi" +version = "5.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "69cdb34c158ceb288df11e18b4bd39de994f6657d83847bdffdbd7f346754b0f" + +[[package]] +name = "r-efi" +version = "6.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f8dcc9c7d52a811697d2151c701e0d08956f92b0e24136cf4cf27b57a6a0d9bf" + +[[package]] +name = "redox_users" +version = "0.4.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba009ff324d1fc1b900bd1fdb31564febe58a8ccc8a6fdbb93b543d33b13ca43" +dependencies = [ + "getrandom 0.2.17", + "libredox", + "thiserror 1.0.69", +] + +[[package]] +name = "regex" +version = "1.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e10754a14b9137dd7b1e3e5b0493cc9171fdd105e0ab477f51b72e7f3ac0e276" +dependencies = [ + "aho-corasick", + "memchr", + "regex-automata", + "regex-syntax", +] + +[[package]] +name = "regex-automata" +version = "0.4.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6e1dd4122fc1595e8162618945476892eefca7b88c52820e74af6262213cae8f" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax", +] + +[[package]] +name = "regex-syntax" +version = "0.8.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dc897dd8d9e8bd1ed8cdad82b5966c3e0ecae09fb1907d58efaa013543185d0a" + +[[package]] +name = "rustfix" +version = "0.8.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "82fa69b198d894d84e23afde8e9ab2af4400b2cba20d6bf2b428a8b01c222c5a" +dependencies = [ + "serde", + "serde_json", + "thiserror 1.0.69", + "tracing", +] + +[[package]] +name = "rustix" +version = "1.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b6fe4565b9518b83ef4f91bb47ce29620ca828bd32cb7e408f0062e9930ba190" +dependencies = [ + "bitflags", + "errno", + "libc", + "linux-raw-sys", + "windows-sys 0.61.2", +] + +[[package]] +name = "rustversion" +version = "1.0.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b39cdef0fa800fc44525c84ccb54a029961a8215f9619753635a9c0d2538d46d" + +[[package]] +name = "semver" +version = "1.0.28" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8a7852d02fc848982e0c167ef163aaff9cd91dc640ba85e263cb1ce46fae51cd" +dependencies = [ + "serde", + "serde_core", +] + +[[package]] +name = "serde" +version = "1.0.228" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a8e94ea7f378bd32cbbd37198a4a91436180c5bb472411e48b5ec2e2124ae9e" +dependencies = [ + "serde_core", + "serde_derive", +] + +[[package]] +name = "serde_core" +version = "1.0.228" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "41d385c7d4ca58e59fc732af25c3983b67ac852c1a25000afe1175de458b67ad" +dependencies = [ + "serde_derive", +] + +[[package]] +name = "serde_derive" +version = "1.0.228" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d540f220d3187173da220f885ab66608367b6574e925011a9353e4badda91d79" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "serde_json" +version = "1.0.150" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8014e44b4736ed0538adeecded0fce2a272f22dc9578a7eb6b2d9993c74cfb9" +dependencies = [ + "itoa", + "memchr", + "serde", + "serde_core", + "zmij", +] + +[[package]] +name = "serde_spanned" +version = "1.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6662b5879511e06e8999a8a235d848113e942c9124f211511b16466ee2995f26" +dependencies = [ + "serde_core", +] + +[[package]] +name = "shlex" +version = "2.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f8fadd59c855ef2080decdef8ff161eb6661b86933c9d82e5ba29dc602a55aba" + +[[package]] +name = "smallvec" +version = "1.15.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "67b1b7a3b5fe4f1376887184045fcf45c69e92af734b7aaddc05fb777b6fbd03" + +[[package]] +name = "stable_deref_trait" +version = "1.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6ce2be8dc25455e1f91df71bfa12ad37d7af1092ae736f3a6cd0e37bc7810596" + +[[package]] +name = "syn" +version = "2.0.117" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e665b8803e7b1d2a727f4023456bbbbe74da67099c585258af0ad9c5013b9b99" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + +[[package]] +name = "synstructure" +version = "0.13.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "728a70f3dbaf5bab7f0c4b1ac8d7ae5ea60a4b5549c8a5914361c99147a709d2" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "tar" +version = "0.4.46" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3f6221d9a6003c78398e3b239969f352578258df48c8eb051caadae0015bc840" +dependencies = [ + "filetime", + "libc", + "xattr", +] + +[[package]] +name = "tempfile" +version = "3.27.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32497e9a4c7b38532efcdebeef879707aa9f794296a4f0244f6f69e9bc8574bd" +dependencies = [ + "fastrand", + "getrandom 0.4.2", + "once_cell", + "rustix", + "windows-sys 0.61.2", +] + +[[package]] +name = "term" +version = "0.7.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c59df8ac95d96ff9bede18eb7300b0fda5e5d8d90960e76f8e14ae765eedbf1f" +dependencies = [ + "dirs-next", + "rustversion", + "winapi", +] + +[[package]] +name = "tester" +version = "0.9.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "89e8bf7e0eb2dd7b4228cc1b6821fc5114cd6841ae59f652a85488c016091e5f" +dependencies = [ + "cfg-if", + "getopts", + "libc", + "num_cpus", + "term", +] + +[[package]] +name = "thiserror" +version = "1.0.69" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b6aaf5339b578ea85b50e080feb250a3e8ae8cfcdff9a461c9ec2904bc923f52" +dependencies = [ + "thiserror-impl 1.0.69", +] + +[[package]] +name = "thiserror" +version = "2.0.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4288b5bcbc7920c07a1149a35cf9590a2aa808e0bc1eafaade0b80947865fbc4" +dependencies = [ + "thiserror-impl 2.0.18", +] + +[[package]] +name = "thiserror-impl" +version = "1.0.69" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4fee6c4efc90059e10f81e6d42c60a18f76588c3d74cb83a0b242a2b6c7504c1" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "thiserror-impl" +version = "2.0.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ebc4ee7f67670e9b64d05fa4253e753e016c6c95ff35b89b7941d6b856dec1d5" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "tinystr" +version = "0.8.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c8323304221c2a851516f22236c5722a72eaa19749016521d6dff0824447d96d" +dependencies = [ + "displaydoc", + "zerovec", +] + +[[package]] +name = "toml" +version = "1.1.2+spec-1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "81f3d15e84cbcd896376e6730314d59fb5a87f31e4b038454184435cd57defee" +dependencies = [ + "indexmap", + "serde_core", + "serde_spanned", + "toml_datetime", + "toml_parser", + "toml_writer", + "winnow", +] + +[[package]] +name = "toml_datetime" +version = "1.1.1+spec-1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3165f65f62e28e0115a00b2ebdd37eb6f3b641855f9d636d3cd4103767159ad7" +dependencies = [ + "serde_core", +] + +[[package]] +name = "toml_parser" +version = "1.1.2+spec-1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a2abe9b86193656635d2411dc43050282ca48aa31c2451210f4202550afb7526" +dependencies = [ + "winnow", +] + +[[package]] +name = "toml_writer" +version = "1.1.1+spec-1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "756daf9b1013ebe47a8776667b466417e2d4c5679d441c26230efd9ef78692db" + +[[package]] +name = "tracing" +version = "0.1.44" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100" +dependencies = [ + "pin-project-lite", + "tracing-core", +] + +[[package]] +name = "tracing-core" +version = "0.1.36" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" +dependencies = [ + "once_cell", +] + +[[package]] +name = "unicode-ident" +version = "1.0.24" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e6e4313cd5fcd3dad5cafa179702e2b244f760991f45397d14d4ebf38247da75" + +[[package]] +name = "unicode-width" +version = "0.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b4ac048d71ede7ee76d585517add45da530660ef4390e49b098733c6e897f254" + +[[package]] +name = "unicode-xid" +version = "0.2.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ebc1c04c71510c7f702b52b7c350734c9ff1295c464a03335b00bb84fc54f853" + +[[package]] +name = "url" +version = "2.5.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ff67a8a4397373c3ef660812acab3268222035010ab8680ec4215f38ba3d0eed" +dependencies = [ + "form_urlencoded", + "idna", + "percent-encoding", + "serde", +] + +[[package]] +name = "utf8_iter" +version = "1.0.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b6c140620e7ffbb22c2dee59cafe6084a59b5ffc27a8859a5f0d494b5d52b6be" + +[[package]] +name = "utf8parse" +version = "0.2.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821" + +[[package]] +name = "vcpkg" +version = "0.2.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "accd4ea62f7bb7a82fe23066fb0957d48ef677f6eeb8215f372f52e48bb32426" + +[[package]] +name = "wasi" +version = "0.11.1+wasi-snapshot-preview1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ccf3ec651a847eb01de73ccad15eb7d99f80485de043efb2f370cd654f4ea44b" + +[[package]] +name = "wasip2" +version = "1.0.3+wasi-0.2.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "20064672db26d7cdc89c7798c48a0fdfac8213434a1186e5ef29fd560ae223d6" +dependencies = [ + "wit-bindgen 0.57.1", +] + +[[package]] +name = "wasip3" +version = "0.4.0+wasi-0.3.0-rc-2026-01-06" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5428f8bf88ea5ddc08faddef2ac4a67e390b88186c703ce6dbd955e1c145aca5" +dependencies = [ + "wit-bindgen 0.51.0", +] + +[[package]] +name = "wasm-encoder" +version = "0.244.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "990065f2fe63003fe337b932cfb5e3b80e0b4d0f5ff650e6985b1048f62c8319" +dependencies = [ + "leb128fmt", + "wasmparser", +] + +[[package]] +name = "wasm-metadata" +version = "0.244.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bb0e353e6a2fbdc176932bbaab493762eb1255a7900fe0fea1a2f96c296cc909" +dependencies = [ + "anyhow", + "indexmap", + "wasm-encoder", + "wasmparser", +] + +[[package]] +name = "wasmparser" +version = "0.244.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "47b807c72e1bac69382b3a6fb3dbe8ea4c0ed87ff5629b8685ae6b9a611028fe" +dependencies = [ + "bitflags", + "hashbrown 0.15.5", + "indexmap", + "semver", +] + +[[package]] +name = "winapi" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419" +dependencies = [ + "winapi-i686-pc-windows-gnu", + "winapi-x86_64-pc-windows-gnu", +] + +[[package]] +name = "winapi-i686-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" + +[[package]] +name = "winapi-x86_64-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" + +[[package]] +name = "windows-link" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f0805222e57f7521d6a62e36fa9163bc891acd422f971defe97d64e70d0a4fe5" + +[[package]] +name = "windows-sys" +version = "0.59.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1e38bc4d79ed67fd075bcc251a1c39b32a1776bbe92e5bef1f0bf1f8c531853b" +dependencies = [ + "windows-targets", +] + +[[package]] +name = "windows-sys" +version = "0.61.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ae137229bcbd6cdf0f7b80a31df61766145077ddf49416a728b02cb3921ff3fc" +dependencies = [ + "windows-link", +] + +[[package]] +name = "windows-targets" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9b724f72796e036ab90c1021d4780d4d3d648aca59e491e6b98e725b84e99973" +dependencies = [ + "windows_aarch64_gnullvm", + "windows_aarch64_msvc", + "windows_i686_gnu", + "windows_i686_gnullvm", + "windows_i686_msvc", + "windows_x86_64_gnu", + "windows_x86_64_gnullvm", + "windows_x86_64_msvc", +] + +[[package]] +name = "windows_aarch64_gnullvm" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32a4622180e7a0ec044bb555404c800bc9fd9ec262ec147edd5989ccd0c02cd3" + +[[package]] +name = "windows_aarch64_msvc" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "09ec2a7bb152e2252b53fa7803150007879548bc709c039df7627cabbd05d469" + +[[package]] +name = "windows_i686_gnu" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8e9b5ad5ab802e97eb8e295ac6720e509ee4c243f69d781394014ebfe8bbfa0b" + +[[package]] +name = "windows_i686_gnullvm" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0eee52d38c090b3caa76c563b86c3a4bd71ef1a819287c19d586d7334ae8ed66" + +[[package]] +name = "windows_i686_msvc" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "240948bc05c5e7c6dabba28bf89d89ffce3e303022809e73deaefe4f6ec56c66" + +[[package]] +name = "windows_x86_64_gnu" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "147a5c80aabfbf0c7d901cb5895d1de30ef2907eb21fbbab29ca94c5b08b1a78" + +[[package]] +name = "windows_x86_64_gnullvm" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "24d5b23dc417412679681396f2b49f3de8c1473deb516bd34410872eff51ed0d" + +[[package]] +name = "windows_x86_64_msvc" +version = "0.52.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "589f6da84c646204747d1270a2a5661ea66ed1cced2631d546fdfb155959f9ec" + +[[package]] +name = "winnow" +version = "1.0.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0592e1c9d151f854e6fd382574c3a0855250e1d9b2f99d9281c6e6391af352f1" + +[[package]] +name = "wit-bindgen" +version = "0.51.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d7249219f66ced02969388cf2bb044a09756a083d0fab1e566056b04d9fbcaa5" +dependencies = [ + "wit-bindgen-rust-macro", +] + +[[package]] +name = "wit-bindgen" +version = "0.57.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ebf944e87a7c253233ad6766e082e3cd714b5d03812acc24c318f549614536e" + +[[package]] +name = "wit-bindgen-core" +version = "0.51.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ea61de684c3ea68cb082b7a88508a8b27fcc8b797d738bfc99a82facf1d752dc" +dependencies = [ + "anyhow", + "heck", + "wit-parser", +] + +[[package]] +name = "wit-bindgen-rust" +version = "0.51.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b7c566e0f4b284dd6561c786d9cb0142da491f46a9fbed79ea69cdad5db17f21" +dependencies = [ + "anyhow", + "heck", + "indexmap", + "prettyplease", + "syn", + "wasm-metadata", + "wit-bindgen-core", + "wit-component", +] + +[[package]] +name = "wit-bindgen-rust-macro" +version = "0.51.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0c0f9bfd77e6a48eccf51359e3ae77140a7f50b1e2ebfe62422d8afdaffab17a" +dependencies = [ + "anyhow", + "prettyplease", + "proc-macro2", + "quote", + "syn", + "wit-bindgen-core", + "wit-bindgen-rust", +] + +[[package]] +name = "wit-component" +version = "0.244.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9d66ea20e9553b30172b5e831994e35fbde2d165325bec84fc43dbf6f4eb9cb2" +dependencies = [ + "anyhow", + "bitflags", + "indexmap", + "log", + "serde", + "serde_derive", + "serde_json", + "wasm-encoder", + "wasm-metadata", + "wasmparser", + "wit-parser", +] + +[[package]] +name = "wit-parser" +version = "0.244.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ecc8ac4bc1dc3381b7f59c34f00b67e18f910c2c0f50015669dde7def656a736" +dependencies = [ + "anyhow", + "id-arena", + "indexmap", + "log", + "semver", + "serde", + "serde_derive", + "serde_json", + "unicode-xid", + "wasmparser", +] + +[[package]] +name = "writeable" +version = "0.6.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1ffae5123b2d3fc086436f8834ae3ab053a283cfac8fe0a0b8eaae044768a4c4" + +[[package]] +name = "xattr" +version = "1.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "32e45ad4206f6d2479085147f02bc2ef834ac85886624a23575ae137c8aa8156" +dependencies = [ + "libc", + "rustix", +] + +[[package]] +name = "yoke" +version = "0.8.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "709fe23a0424b6a435d82152b1bd3fdfb0833487d5fa90d05d42762a9891fef5" +dependencies = [ + "stable_deref_trait", + "yoke-derive", + "zerofrom", +] + +[[package]] +name = "yoke-derive" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "de844c262c8848816172cef550288e7dc6c7b7814b4ee56b3e1553f275f1858e" +dependencies = [ + "proc-macro2", + "quote", + "syn", + "synstructure", +] + +[[package]] +name = "zerofrom" +version = "0.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0ec05a11813ea801ff6d75110ad09cd0824ddba17dfe17128ea0d5f68e6c5272" +dependencies = [ + "zerofrom-derive", +] + +[[package]] +name = "zerofrom-derive" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "11532158c46691caf0f2593ea8358fed6bbf68a0315e80aae9bd41fbade684a1" +dependencies = [ + "proc-macro2", + "quote", + "syn", + "synstructure", +] + +[[package]] +name = "zerotrie" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0f9152d31db0792fa83f70fb2f83148effb5c1f5b8c7686c3459e361d9bc20bf" +dependencies = [ + "displaydoc", + "yoke", + "zerofrom", +] + +[[package]] +name = "zerovec" +version = "0.11.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "90f911cbc359ab6af17377d242225f4d75119aec87ea711a880987b18cd7b239" +dependencies = [ + "yoke", + "zerofrom", + "zerovec-derive", +] + +[[package]] +name = "zerovec-derive" +version = "0.11.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "625dc425cab0dca6dc3c3319506e6593dcb08a9f387ea3b284dbd52a92c40555" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "zmij" +version = "1.0.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b8848ee67ecc8aedbaf3e4122217aff892639231befc6a1b58d29fff4c2cabaa" diff --git a/lints/logging_lints/Cargo.toml b/lints/logging_lints/Cargo.toml new file mode 100644 index 00000000..9d11781b --- /dev/null +++ b/lints/logging_lints/Cargo.toml @@ -0,0 +1,22 @@ +[package] +name = "logging_lints" +version = "0.1.0" +description = "Custom dylint lints enforcing the libwebauthn logging policy (docs/logging.md)" +edition = "2024" +publish = false + +[lib] +crate-type = ["cdylib"] + +[dependencies] +dylint_linting = "6.0.1" + +[dev-dependencies] +dylint_testing = "6.0.1" + +[package.metadata.rust-analyzer] +rustc_private = true + +# Keep this crate out of the main libwebauthn workspace: it builds on a pinned +# nightly with rustc_private and must not be pulled into the stable build. +[workspace] diff --git a/lints/logging_lints/README.md b/lints/logging_lints/README.md new file mode 100644 index 00000000..2f003f34 --- /dev/null +++ b/lints/logging_lints/README.md @@ -0,0 +1,40 @@ +# logging_lints + +Custom [dylint](https://github.com/trailofbits/dylint) lints that enforce the +mechanical parts of the libwebauthn [logging policy](../../docs/logging.md). + +They run before macro expansion, so they inspect the macro tokens as written. + +## Lints + +- **`tracing_message_interpolation`** — a `tracing` event or span message must be + a static string literal. Flags interpolated messages (`info!("got {x}")`, + `info!("got {}", x)`) and messages built with `format!`. Dynamic data belongs + in structured fields. +- **`print_macro_in_library`** — flags `print!`, `println!`, `eprint!`, + `eprintln!`. Library code logs through `tracing`. +- **`log_crate_macro`** — flags `log::` macros. libwebauthn standardises on + `tracing`. +- **`sensitive_field_above_debug`** — best-effort denylist that flags + sensitive-looking field names (pin, secret, token, shared secret, credential + id, ...) used at `info!` and above. Length and presence fields (`*_len`, + `*_count`) and PIN protocol metadata (`pin_protocol`) are not flagged. This is + a heuristic and can have false positives. Silence a checked case with + `#[allow(dylint::sensitive_field_above_debug)]`. + +## Running + +```sh +cargo install cargo-dylint dylint-link # once +cargo dylint --all --workspace -- --all-features +``` + +The lints are registered for the workspace in the top-level `Cargo.toml` under +`[workspace.metadata.dylint]`, and run in CI (`.github/workflows/dylint.yml`), +where the three deterministic lints fail the build. + +## Toolchain + +This crate builds on the pinned nightly in `rust-toolchain` with `rustc_private`. +It is deliberately kept out of the main workspace so the library still builds on +stable. Bump it with `cargo dylint upgrade logging_lints` when updating dylint. diff --git a/lints/logging_lints/rust-toolchain b/lints/logging_lints/rust-toolchain new file mode 100644 index 00000000..992f9665 --- /dev/null +++ b/lints/logging_lints/rust-toolchain @@ -0,0 +1,3 @@ +[toolchain] +channel = "nightly-2026-04-16" +components = ["llvm-tools-preview", "rustc-dev"] diff --git a/lints/logging_lints/src/lib.rs b/lints/logging_lints/src/lib.rs new file mode 100644 index 00000000..9b44c013 --- /dev/null +++ b/lints/logging_lints/src/lib.rs @@ -0,0 +1,394 @@ +#![feature(rustc_private)] +#![warn(unused_extern_crates)] + +//! Custom dylint lints enforcing the libwebauthn logging policy (docs/logging.md). +//! +//! These run before macro expansion so they can inspect the tokens as written: +//! +//! - `tracing_message_interpolation`: a tracing event/span message must be a +//! static string literal, never an interpolated or `format!`-built string. +//! - `print_macro_in_library`: no `print!`/`println!`/`eprint!`/`eprintln!`. +//! - `log_crate_macro`: no `log::` macros, use `tracing`. +//! - `sensitive_field_above_debug`: best-effort denylist of sensitive field +//! names used at `info!` and above. + +extern crate rustc_ast; +extern crate rustc_errors; +extern crate rustc_lint; +extern crate rustc_session; +extern crate rustc_span; + +use rustc_ast::ast::{Expr, ExprKind, MacCall, Stmt, StmtKind}; +use rustc_ast::token::{Delimiter, IdentIsRaw, LitKind, TokenKind}; +use rustc_ast::tokenstream::{TokenStream, TokenTree}; +use rustc_lint::{EarlyContext, EarlyLintPass, Lint, LintContext, LintStore}; +use rustc_session::Session; +use rustc_span::{Span, Symbol}; + +dylint_linting::dylint_library!(); + +rustc_session::declare_tool_lint! { + /// Tracing event and span messages must be static string literals. Dynamic + /// data belongs in structured fields, not interpolated into the message. + pub dylint::TRACING_MESSAGE_INTERPOLATION, + Warn, + "tracing message must be a static string literal, not interpolated or formatted" +} + +rustc_session::declare_tool_lint! { + /// The print family writes to stdout/stderr and bypasses tracing. Library + /// code must use tracing. + pub dylint::PRINT_MACRO_IN_LIBRARY, + Warn, + "use tracing instead of the print family in library code" +} + +rustc_session::declare_tool_lint! { + /// libwebauthn standardises on tracing. The `log` crate's macros must not be + /// used. + pub dylint::LOG_CRATE_MACRO, + Warn, + "use tracing instead of the log crate" +} + +rustc_session::declare_tool_lint! { + /// Best-effort check that sensitive-looking field names are not logged at + /// info or above. Sensitive values belong at debug (length/presence) or + /// trace (full). + pub dylint::SENSITIVE_FIELD_ABOVE_DEBUG, + Warn, + "possibly sensitive field logged at info or above" +} + +rustc_session::declare_lint_pass!(LoggingLints => [ + TRACING_MESSAGE_INTERPOLATION, + PRINT_MACRO_IN_LIBRARY, + LOG_CRATE_MACRO, + SENSITIVE_FIELD_ABOVE_DEBUG, +]); + +#[expect(clippy::no_mangle_with_rust_abi)] +#[unsafe(no_mangle)] +pub fn register_lints(_sess: &Session, lint_store: &mut LintStore) { + lint_store.register_lints(&[ + TRACING_MESSAGE_INTERPOLATION, + PRINT_MACRO_IN_LIBRARY, + LOG_CRATE_MACRO, + SENSITIVE_FIELD_ABOVE_DEBUG, + ]); + lint_store.register_pre_expansion_pass(|| Box::new(LoggingLints)); +} + +const TRACING_MACROS: &[&str] = &["trace", "debug", "info", "warn", "error", "event", "span"]; +const HIGH_LEVELS: &[&str] = &["info", "warn", "error"]; +const PRINT_MACROS: &[&str] = &["print", "println", "eprint", "eprintln"]; +const LOG_LEVELS: &[&str] = &["trace", "debug", "info", "warn", "error"]; + +/// Whole underscore-separated components that mark a field as sensitive. +const SENSITIVE_WORDS: &[&str] = &["token"]; +/// Components that, alongside a `pin` component, mean the field is PIN protocol +/// metadata (a version or capability) rather than a PIN value. +const PIN_BENIGN: &[&str] = &[ + "proto", + "protos", + "protocol", + "protocols", + "version", + "versions", + "support", + "supported", + "option", + "options", +]; +/// Substrings (underscores removed, lowercased) that mark a field as sensitive. +const SENSITIVE_SUBSTRINGS: &[&str] = &[ + "secret", + "hmac", + "salt", + "passphrase", + "password", + "privatekey", + "sharedsecret", + "pinhash", + "pintoken", + "pinuvauthtoken", + "pinuvauthparam", + "credential", + "userhandle", + "seed", + "prf", + "puat", +]; +/// Components that make a field a harmless metric (length, count) even when it +/// names a sensitive value. +const METRIC_WORDS: &[&str] = &["len", "length", "count", "size", "num", "idx", "index"]; + +impl EarlyLintPass for LoggingLints { + fn check_expr(&mut self, cx: &EarlyContext<'_>, expr: &Expr) { + if let ExprKind::MacCall(mac) = &expr.kind { + check_mac(cx, mac); + } + } + + fn check_stmt(&mut self, cx: &EarlyContext<'_>, stmt: &Stmt) { + if let StmtKind::MacCall(mac_stmt) = &stmt.kind { + check_mac(cx, &mac_stmt.mac); + } + } +} + +fn check_mac(cx: &EarlyContext<'_>, mac: &MacCall) { + let segments = &mac.path.segments; + let Some(name) = segments.last().map(|s| s.ident.name) else { + return; + }; + let name = name.as_str(); + let single = segments.len() == 1; + let prev = (segments.len() >= 2).then(|| segments[segments.len() - 2].ident.name); + let prev = prev.as_ref().map(Symbol::as_str); + + if PRINT_MACROS.contains(&name) && (single || prev == Some("std") || prev == Some("core")) { + emit( + cx, + PRINT_MACRO_IN_LIBRARY, + mac.path.span, + format!("`{name}!` in library code"), + "use a tracing macro instead; see docs/logging.md", + ); + return; + } + + if prev == Some("log") && LOG_LEVELS.contains(&name) { + emit( + cx, + LOG_CRATE_MACRO, + mac.path.span, + format!("`log::{name}!` used"), + "use the equivalent tracing macro; see docs/logging.md", + ); + return; + } + + let is_tracing = TRACING_MACROS.contains(&name) && (single || prev == Some("tracing")); + if !is_tracing { + return; + } + + let segs = top_level_segments(&mac.args.tokens); + let msg_index = segs.iter().position(|s| sole_str_literal(s).is_some()); + + if let Some(i) = msg_index { + if let Some((sym, span)) = sole_str_literal(&segs[i]) { + if has_placeholder(sym.as_str()) { + emit( + cx, + TRACING_MESSAGE_INTERPOLATION, + span, + "tracing message interpolates dynamic data".to_string(), + "use a static message and structured fields, e.g. \ + info!(field = value, \"message\"); see docs/logging.md", + ); + } + } + } + if let Some(span) = format_macro_segment(&segs) { + emit( + cx, + TRACING_MESSAGE_INTERPOLATION, + span, + "tracing message built with `format!`".to_string(), + "use a static message and structured fields; see docs/logging.md", + ); + } + for seg in &segs { + if let Some(span) = dynamic_message_field(seg) { + emit( + cx, + TRACING_MESSAGE_INTERPOLATION, + span, + "tracing `message` field is not a static string literal".to_string(), + "set the message to a static string literal; see docs/logging.md", + ); + } + } + + if HIGH_LEVELS.contains(&name) { + for unit in field_units(&segs, msg_index) { + if segment_has_metric(&unit) { + continue; + } + if let Some((field, span)) = first_sensitive_ident(&unit) { + emit( + cx, + SENSITIVE_FIELD_ABOVE_DEBUG, + span, + format!("possibly sensitive field `{field}` logged at `{name}!`"), + "log sensitive data only at debug! (length or presence) or \ + trace! (full); see docs/logging.md", + ); + } + } + } +} + +fn emit(cx: &EarlyContext<'_>, lint: &'static Lint, span: Span, msg: String, help: &'static str) { + cx.opt_span_lint( + lint, + Some(span), + rustc_errors::DiagDecorator(|diag: &mut rustc_errors::Diag<'_, ()>| { + diag.primary_message(msg); + diag.help(help); + }), + ); +} + +/// Split a macro's token stream on top-level commas. +fn top_level_segments(tokens: &TokenStream) -> Vec> { + let mut out = Vec::new(); + let mut cur = Vec::new(); + for tt in tokens.iter() { + if let TokenTree::Token(tok, _) = tt { + if tok.kind == TokenKind::Comma { + out.push(std::mem::take(&mut cur)); + continue; + } + } + cur.push(tt); + } + if !cur.is_empty() { + out.push(cur); + } + out +} + +/// Field segments to inspect for sensitivity, descending into a `{ ... }` brace +/// block (the form the policy uses for two or more fields) so its inner fields +/// are checked too. The message segment is skipped. +fn field_units<'a>( + segs: &[Vec<&'a TokenTree>], + msg_index: Option, +) -> Vec> { + let mut units = Vec::new(); + for (i, seg) in segs.iter().enumerate() { + if Some(i) == msg_index { + continue; + } + if let [TokenTree::Delimited(_, _, Delimiter::Brace, inner)] = seg[..] { + units.extend(top_level_segments(inner)); + } else { + units.push(seg.clone()); + } + } + units +} + +/// If a segment is exactly one string literal, return its value and span. +fn sole_str_literal(seg: &[&TokenTree]) -> Option<(Symbol, Span)> { + if let [TokenTree::Token(tok, _)] = seg { + if let TokenKind::Literal(lit) = tok.kind { + if matches!(lit.kind, LitKind::Str | LitKind::StrRaw(_)) { + return Some((lit.symbol, tok.span)); + } + } + } + None +} + +/// True if a format string contains a `{...}` placeholder (ignoring `{{`/`}}`). +fn has_placeholder(s: &str) -> bool { + s.replace("{{", "").replace("}}", "").contains('{') +} + +/// Span of a `format!`/`format_args!` call appearing as a top-level segment. +fn format_macro_segment(segs: &[Vec<&TokenTree>]) -> Option { + for seg in segs { + if let [TokenTree::Token(t0, _), TokenTree::Token(t1, _), ..] = seg[..] { + if t1.kind == TokenKind::Bang { + if let TokenKind::Ident(sym, IdentIsRaw::No) = t0.kind { + if matches!(sym.as_str(), "format" | "format_args") { + return Some(t0.span); + } + } + } + } + } + None +} + +/// True if the tokens are exactly one string literal. +fn is_static_str_value(value: &[&TokenTree]) -> bool { + if let [TokenTree::Token(tok, _)] = value { + if let TokenKind::Literal(lit) = tok.kind { + return matches!(lit.kind, LitKind::Str | LitKind::StrRaw(_)); + } + } + false +} + +/// Span of a `message = ` field whose value is not a static string +/// literal (e.g. `message = %x` or `message = format!(...)`), which sets a +/// dynamic event message and bypasses the static-message rule. +fn dynamic_message_field(seg: &[&TokenTree]) -> Option { + if seg.len() < 2 { + return None; + } + if let (TokenTree::Token(t0, _), TokenTree::Token(t1, _)) = (seg[0], seg[1]) { + if t1.kind == TokenKind::Eq { + if let TokenKind::Ident(sym, IdentIsRaw::No) = t0.kind { + if sym.as_str() == "message" && !is_static_str_value(&seg[2..]) { + return Some(t0.span); + } + } + } + } + None +} + +fn ident_tokens(seg: &[&TokenTree]) -> Vec<(Symbol, Span)> { + seg.iter() + .filter_map(|tt| { + if let TokenTree::Token(tok, _) = tt { + if let TokenKind::Ident(sym, _) = tok.kind { + return Some((sym, tok.span)); + } + } + None + }) + .collect() +} + +fn segment_has_metric(seg: &[&TokenTree]) -> bool { + ident_tokens(seg) + .iter() + .any(|(sym, _)| name_has_word(sym.as_str(), METRIC_WORDS)) +} + +fn first_sensitive_ident(seg: &[&TokenTree]) -> Option<(String, Span)> { + ident_tokens(seg) + .into_iter() + .find(|(sym, _)| is_sensitive(sym.as_str())) + .map(|(sym, span)| (sym.to_string(), span)) +} + +fn name_has_word(name: &str, words: &[&str]) -> bool { + let lower = name.to_ascii_lowercase(); + lower.split('_').any(|part| words.contains(&part)) +} + +fn is_sensitive(name: &str) -> bool { + let lower = name.to_ascii_lowercase(); + let parts: Vec<&str> = lower.split('_').collect(); + if parts.iter().any(|p| SENSITIVE_WORDS.contains(p)) { + return true; + } + if parts.contains(&"pin") && !parts.iter().any(|p| PIN_BENIGN.contains(p)) { + return true; + } + let norm = lower.replace('_', ""); + SENSITIVE_SUBSTRINGS.iter().any(|s| norm.contains(s)) +} + +#[test] +fn ui() { + dylint_testing::ui_test(env!("CARGO_PKG_NAME"), "ui"); +} diff --git a/lints/logging_lints/ui/main.rs b/lints/logging_lints/ui/main.rs new file mode 100644 index 00000000..f9bc14c2 --- /dev/null +++ b/lints/logging_lints/ui/main.rs @@ -0,0 +1,65 @@ +// Test fixtures for the logging lints. Local dummy macros stand in for the +// tracing/log macros: the lints run before expansion and match by macro name, +// so the bodies are irrelevant. + +macro_rules! trace { + ($($t:tt)*) => {{}}; +} +macro_rules! debug { + ($($t:tt)*) => {{}}; +} +macro_rules! info { + ($($t:tt)*) => {{}}; +} +macro_rules! warn { + ($($t:tt)*) => {{}}; +} +macro_rules! error { + ($($t:tt)*) => {{}}; +} + +fn main() { + let count = 3u32; + let err = "boom"; + let pin = 1234u32; + let shared_secret = [0u8; 32]; + + // OK: static message, structured fields. + info!("Listing devices"); + warn!(?err, "Authenticator returned a malformed response"); + debug!(count, "Filtered credentials"); + trace!(?shared_secret, "Raw shared secret"); // OK: trace may carry secrets + + // tracing_message_interpolation + info!("found {} credentials", count); + debug!("found {count} credentials"); + error!("failed: {err:?}"); + warn!(?err, "failed after {} tries", count); + + // print_macro_in_library + println!("hello {}", count); + eprintln!("oops"); + print!("no newline"); + + // sensitive_field_above_debug + warn!(?pin, "logging a pin at warn"); + error!(?shared_secret, "logging a secret at error"); + // OK: sensitive name but only at debug, and benign pin metadata. + debug!(?pin, "pin at debug is allowed"); + info!(pin_protocol = count, "pin protocol is benign"); + info!(pin_len = count, "a length is benign"); + + // sensitive_field_above_debug inside a brace block (the policy form for 2+ fields) + let bar = 7u32; + warn!({ pin = ?pin, attempt = count }, "pin in a brace block"); + error!({ ?shared_secret, attempt = count }, "secret in a brace block"); + // OK: brace block of benign fields, and a brace block at debug + info!({ rp_id = bar, attempt = count }, "benign brace block"); + debug!({ pin = ?pin, attempt = count }, "pin in a brace block at debug is allowed"); + + // print_macro_in_library: std-qualified + std::println!("qualified {}", count); + + // tracing_message_interpolation: dynamic message field + info!(message = %count, attempt = count); +} diff --git a/lints/logging_lints/ui/main.stderr b/lints/logging_lints/ui/main.stderr new file mode 100644 index 00000000..49cebbc1 --- /dev/null +++ b/lints/logging_lints/ui/main.stderr @@ -0,0 +1,109 @@ +warning: tracing message interpolates dynamic data + --> $DIR/main.rs:34:11 + | +LL | info!("found {} credentials", count); + | ^^^^^^^^^^^^^^^^^^^^^^ + | + = help: use a static message and structured fields, e.g. info!(field = value, "message"); see docs/logging.md + = note: `#[warn(dylint::tracing_message_interpolation)]` on by default + +warning: tracing message interpolates dynamic data + --> $DIR/main.rs:35:12 + | +LL | debug!("found {count} credentials"); + | ^^^^^^^^^^^^^^^^^^^^^^^^^^^ + | + = help: use a static message and structured fields, e.g. info!(field = value, "message"); see docs/logging.md + +warning: tracing message interpolates dynamic data + --> $DIR/main.rs:36:12 + | +LL | error!("failed: {err:?}"); + | ^^^^^^^^^^^^^^^^^ + | + = help: use a static message and structured fields, e.g. info!(field = value, "message"); see docs/logging.md + +warning: tracing message interpolates dynamic data + --> $DIR/main.rs:37:17 + | +LL | warn!(?err, "failed after {} tries", count); + | ^^^^^^^^^^^^^^^^^^^^^^^ + | + = help: use a static message and structured fields, e.g. info!(field = value, "message"); see docs/logging.md + +warning: `println!` in library code + --> $DIR/main.rs:40:5 + | +LL | println!("hello {}", count); + | ^^^^^^^ + | + = help: use a tracing macro instead; see docs/logging.md + = note: `#[warn(dylint::print_macro_in_library)]` on by default + +warning: `eprintln!` in library code + --> $DIR/main.rs:41:5 + | +LL | eprintln!("oops"); + | ^^^^^^^^ + | + = help: use a tracing macro instead; see docs/logging.md + +warning: `print!` in library code + --> $DIR/main.rs:42:5 + | +LL | print!("no newline"); + | ^^^^^ + | + = help: use a tracing macro instead; see docs/logging.md + +warning: possibly sensitive field `pin` logged at `warn!` + --> $DIR/main.rs:45:12 + | +LL | warn!(?pin, "logging a pin at warn"); + | ^^^ + | + = help: log sensitive data only at debug! (length or presence) or trace! (full); see docs/logging.md + = note: `#[warn(dylint::sensitive_field_above_debug)]` on by default + +warning: possibly sensitive field `shared_secret` logged at `error!` + --> $DIR/main.rs:46:13 + | +LL | error!(?shared_secret, "logging a secret at error"); + | ^^^^^^^^^^^^^ + | + = help: log sensitive data only at debug! (length or presence) or trace! (full); see docs/logging.md + +warning: possibly sensitive field `pin` logged at `warn!` + --> $DIR/main.rs:54:13 + | +LL | warn!({ pin = ?pin, attempt = count }, "pin in a brace block"); + | ^^^ + | + = help: log sensitive data only at debug! (length or presence) or trace! (full); see docs/logging.md + +warning: possibly sensitive field `shared_secret` logged at `error!` + --> $DIR/main.rs:55:15 + | +LL | error!({ ?shared_secret, attempt = count }, "secret in a brace block"); + | ^^^^^^^^^^^^^ + | + = help: log sensitive data only at debug! (length or presence) or trace! (full); see docs/logging.md + +warning: `println!` in library code + --> $DIR/main.rs:61:5 + | +LL | std::println!("qualified {}", count); + | ^^^^^^^^^^^^ + | + = help: use a tracing macro instead; see docs/logging.md + +warning: tracing `message` field is not a static string literal + --> $DIR/main.rs:64:11 + | +LL | info!(message = %count, attempt = count); + | ^^^^^^^ + | + = help: set the message to a static string literal; see docs/logging.md + +warning: 13 warnings emitted + From 7bb8096637235fad6faf417d1a1c474662b6a2e7 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 03/10] refactor(cable): apply the logging policy Downgrade peer, transport, IO and decode failures from error! to warn!, keeping error! only for in-memory crypto invariants. Reduce byte-array dumps to lengths at debug! with full values at trace!, and stop the trial-decrypt span from recording the EID key. --- .../src/transport/cable/advertisement.rs | 17 ++--- libwebauthn/src/transport/cable/channel.rs | 12 +-- .../src/transport/cable/connection_stages.rs | 8 +- libwebauthn/src/transport/cable/crypto.rs | 14 ++-- .../src/transport/cable/data_channel.rs | 10 +-- .../src/transport/cable/known_devices.rs | 4 +- libwebauthn/src/transport/cable/l2cap.rs | 14 ++-- libwebauthn/src/transport/cable/protocol.rs | 73 +++++++++---------- libwebauthn/src/transport/cable/tunnel.rs | 8 +- 9 files changed, 74 insertions(+), 86 deletions(-) diff --git a/libwebauthn/src/transport/cable/advertisement.rs b/libwebauthn/src/transport/cable/advertisement.rs index 1e21abba..fe8b537d 100644 --- a/libwebauthn/src/transport/cable/advertisement.rs +++ b/libwebauthn/src/transport/cable/advertisement.rs @@ -83,7 +83,7 @@ pub(crate) async fn await_advertisement( let mut stream = pin!(stream); while let Some((adapter, peripheral, data)) = stream.as_mut().next().await { - debug!({ ?peripheral, ?data }, "Found device with service data"); + debug!({ ?peripheral, data_len = data.len() }, "Found device with service data"); let Some(device) = btleplug::manager::get_device(peripheral.clone()) .await @@ -96,12 +96,12 @@ pub(crate) async fn await_advertisement( continue; }; - trace!(?device, ?data, ?eid_key); + trace!({ ?device, ?data, ?eid_key }, "Trial-decrypting advertisement"); let Some(decrypted) = trial_decrypt_advert(eid_key, &data) else { - warn!(?device, "Trial decrypt failed, ignoring"); + debug!(?device, "Trial decrypt failed, ignoring"); continue; }; - trace!(?decrypted); + trace!(?decrypted, "Decrypted advertisement"); let mut advert = DecryptedAdvert::from(decrypted); if let Some(suffix_bytes) = data.get(20..).filter(|s| !s.is_empty()) { @@ -111,17 +111,12 @@ pub(crate) async fn await_advertisement( advert.suffix = Some(suffix); } Err(e) => warn!( - ?device, - ?e, + { ?device, ?e }, "Failed to parse advertisement suffix, ignoring it" ), } } - debug!( - ?device, - ?decrypted, - "Successfully decrypted advertisement from device" - ); + debug!(?device, "Successfully decrypted advertisement from device"); adapter .stop_scan() diff --git a/libwebauthn/src/transport/cable/channel.rs b/libwebauthn/src/transport/cable/channel.rs index 0212138a..bbabc3f0 100644 --- a/libwebauthn/src/transport/cable/channel.rs +++ b/libwebauthn/src/transport/cable/channel.rs @@ -5,7 +5,7 @@ use std::time::Duration; use async_trait::async_trait; use tokio::sync::{broadcast, mpsc, watch}; use tokio::{task, time}; -use tracing::error; +use tracing::warn; use crate::pin::persistent_token::PersistentTokenStore; use crate::proto::{ @@ -141,12 +141,12 @@ impl Channel for CableChannel { } async fn apdu_send(&mut self, _request: &ApduRequest, _timeout: Duration) -> Result<(), Error> { - error!("APDU send not supported in caBLE transport"); + warn!("APDU send not supported in caBLE transport"); Err(Error::Transport(TransportError::TransportUnavailable)) } async fn apdu_recv(&mut self, _timeout: Duration) -> Result { - error!("APDU recv not supported in caBLE transport"); + warn!("APDU recv not supported in caBLE transport"); Err(Error::Transport(TransportError::TransportUnavailable)) } @@ -158,11 +158,11 @@ impl Channel for CableChannel { match time::timeout(timeout, self.cbor_sender.send(request.clone())).await { Ok(Ok(_)) => Ok(()), Ok(Err(error)) => { - error!(%error, "CBOR request send failure"); + warn!(%error, "CBOR request send failure"); Err(Error::Transport(TransportError::TransportUnavailable)) } Err(elapsed) => { - error!({ %elapsed, ?timeout }, "CBOR request send timeout"); + warn!({ %elapsed, ?timeout }, "CBOR request send timeout"); Err(Error::Transport(TransportError::Timeout)) } } @@ -177,7 +177,7 @@ impl Channel for CableChannel { Ok(Some(response)) => Ok(response), Ok(None) => Err(Error::Transport(TransportError::TransportUnavailable)), Err(elapsed) => { - error!({ %elapsed, ?timeout }, "CBOR response recv timeout"); + warn!({ %elapsed, ?timeout }, "CBOR response recv timeout"); Err(Error::Transport(TransportError::Timeout)) } } diff --git a/libwebauthn/src/transport/cable/connection_stages.rs b/libwebauthn/src/transport/cable/connection_stages.rs index 24ed19f7..5fbb2625 100644 --- a/libwebauthn/src/transport/cable/connection_stages.rs +++ b/libwebauthn/src/transport/cable/connection_stages.rs @@ -1,7 +1,7 @@ use ::btleplug::api::{AddressType, BDAddr}; use async_trait::async_trait; use tokio::sync::{broadcast, mpsc, watch}; -use tracing::{debug, error, info, instrument, trace, warn}; +use tracing::{debug, info, instrument, trace, warn}; use super::advertisement::{await_advertisement, DecryptedAdvert}; use super::channel::{CableUpdate, CableUxUpdate, ConnectionState}; @@ -249,7 +249,7 @@ impl UxUpdateSender for MpscUxUpdateSender { async fn send_update(&self, update: CableUxUpdate) { trace!("Sending UX update"); if let Err(err) = self.sender.send(update) { - warn!(?err, "No receivers found for UX update."); + warn!(?err, "No receivers found for UX update"); } } @@ -286,7 +286,7 @@ pub(crate) async fn connection_stage( input: ConnectionInput, ux_sender: &dyn UxUpdateSender, ) -> Result { - debug!(?input.tunnel_domain, "Starting connection stage"); + debug!(tunnel_domain = %input.tunnel_domain, "Starting connection stage"); ux_sender .send_update(CableUxUpdate::CableUpdate(CableUpdate::Connecting)) @@ -376,7 +376,7 @@ pub(crate) fn decode_tunnel_domain_from_advert( ) -> Result { tunnel::decode_tunnel_server_domain(advert.encoded_tunnel_server_domain) .ok_or_else(|| { - error!({ encoded = %advert.encoded_tunnel_server_domain }, "Failed to decode tunnel server domain"); + warn!(encoded = %advert.encoded_tunnel_server_domain, "Failed to decode tunnel server domain"); TransportError::InvalidFraming }) } diff --git a/libwebauthn/src/transport/cable/crypto.rs b/libwebauthn/src/transport/cable/crypto.rs index bb8dc67d..af19e7ec 100644 --- a/libwebauthn/src/transport/cable/crypto.rs +++ b/libwebauthn/src/transport/cable/crypto.rs @@ -2,7 +2,7 @@ use aes::cipher::{generic_array::GenericArray, BlockDecrypt, KeyInit}; use aes::{Aes256, Block}; use hkdf::Hkdf; use sha2::Sha256; -use tracing::{instrument, warn}; +use tracing::{debug, error, instrument, trace, warn, Level}; use crate::pin::hmac_sha256; use crate::transport::error::TransportError; @@ -28,17 +28,17 @@ fn reserved_bits_are_zero(plaintext: &[u8]) -> bool { plaintext.first().copied() == Some(0) } -#[instrument] +#[instrument(level = Level::DEBUG, skip_all)] pub fn trial_decrypt_advert(eid_key: &[u8], candidate_advert: &[u8]) -> Option<[u8; 16]> { // Only the first 20 bytes are the encrypted advert; any remainder is the // advertisement suffix and is parsed separately by the caller. let Some(advert) = candidate_advert.get(..20) else { - warn!("candidate advert is shorter than 20 bytes"); + debug!("Candidate advert is shorter than 20 bytes"); return None; }; if eid_key.len() != 64 { - warn!("EID key is not 64 bytes"); + error!("EID key is not 64 bytes"); return None; } @@ -48,8 +48,8 @@ pub fn trial_decrypt_advert(eid_key: &[u8], candidate_advert: &[u8]) -> Option<[ let expected_tag = hmac_sha256(mac_key, advert_body).ok()?; let expected_tag_truncated = expected_tag.get(..4)?; if expected_tag_truncated != advert_tag { - warn!({ expected = ?expected_tag_truncated, actual = ?advert_tag }, - "candidate advert HMAC tag does not match"); + trace!({ expected = ?expected_tag_truncated, actual = ?advert_tag }, + "Candidate advert HMAC tag does not match"); return None; } @@ -59,7 +59,7 @@ pub fn trial_decrypt_advert(eid_key: &[u8], candidate_advert: &[u8]) -> Option<[ cipher.decrypt_block(&mut block); if !reserved_bits_are_zero(&block) { - warn!("reserved bits are not zero"); + warn!("Reserved bits are not zero"); return None; } diff --git a/libwebauthn/src/transport/cable/data_channel.rs b/libwebauthn/src/transport/cable/data_channel.rs index e27979a9..8a8ba779 100644 --- a/libwebauthn/src/transport/cable/data_channel.rs +++ b/libwebauthn/src/transport/cable/data_channel.rs @@ -4,7 +4,7 @@ use futures::{SinkExt, StreamExt}; use tokio::net::TcpStream; use tokio_tungstenite::tungstenite::{Error, Message}; use tokio_tungstenite::{MaybeTlsStream, WebSocketStream}; -use tracing::error; +use tracing::warn; use crate::transport::error::TransportError; @@ -40,7 +40,7 @@ impl CableDataChannel for WebSocketDataChannel { .send(Message::Binary(message.to_vec().into())) .await .map_err(|e| { - error!(?e, "Failed to send WebSocket message"); + warn!(?e, "Failed to send WebSocket message"); match e { Error::Io(io) => TransportError::IoError(io.kind()), _ => TransportError::ConnectionFailed, @@ -57,15 +57,15 @@ impl CableDataChannel for WebSocketDataChannel { return Ok(None) } Some(Ok(other)) => { - error!(?other, "Unexpected WebSocket message type"); + warn!(?other, "Unexpected WebSocket message type"); return Err(TransportError::ConnectionFailed); } Some(Err(Error::Io(e))) => { - error!(?e, "Failed to read WebSocket message"); + warn!(?e, "Failed to read WebSocket message"); return Err(TransportError::IoError(e.kind())); } Some(Err(e)) => { - error!(?e, "Failed to read WebSocket message"); + warn!(?e, "Failed to read WebSocket message"); return Err(TransportError::ConnectionFailed); } } diff --git a/libwebauthn/src/transport/cable/known_devices.rs b/libwebauthn/src/transport/cable/known_devices.rs index 3eadfb03..97605c8b 100644 --- a/libwebauthn/src/transport/cable/known_devices.rs +++ b/libwebauthn/src/transport/cable/known_devices.rs @@ -68,7 +68,7 @@ impl CableKnownDeviceInfoStore for EphemeralDeviceInfoStore { device: &CableKnownDeviceInfo, ) { debug!(?device_id, "Inserting or updating known device"); - trace!(?device); + trace!(?device, "Known device info"); let mut known_devices = self.known_devices.lock().await; known_devices.insert(device_id.clone(), device.clone()); } @@ -193,7 +193,7 @@ impl CableKnownDevice { #[async_trait] impl<'d> Device<'d, Cable, CableChannel> for CableKnownDevice { async fn channel(&'d mut self, settings: ChannelSettings) -> Result { - debug!(?self.device_info.tunnel_domain, "Creating channel to tunnel server"); + debug!(tunnel_domain = %self.device_info.tunnel_domain, "Creating channel to tunnel server"); let (ux_update_sender, _) = broadcast::channel(16); let (cbor_tx_send, cbor_tx_recv) = mpsc::channel(16); diff --git a/libwebauthn/src/transport/cable/l2cap.rs b/libwebauthn/src/transport/cable/l2cap.rs index ad197921..cf54aabe 100644 --- a/libwebauthn/src/transport/cable/l2cap.rs +++ b/libwebauthn/src/transport/cable/l2cap.rs @@ -6,7 +6,7 @@ use async_trait::async_trait; use btleplug::api::{AddressType, BDAddr}; use tokio::io::{AsyncReadExt, AsyncWriteExt}; use tokio::time::Instant; -use tracing::{debug, error, warn}; +use tracing::{debug, warn}; use super::data_channel::CableDataChannel; use crate::transport::error::TransportError; @@ -47,7 +47,7 @@ impl L2capDataChannel { bluer::l2cap::Stream::connect(bluer::l2cap::SocketAddr::new(addr, addr_type, psm)) .await .map_err(|e| { - error!(?e, %addr, psm, "Failed to connect L2CAP CoC"); + warn!({ ?e, %addr, psm }, "Failed to connect L2CAP CoC"); TransportError::ConnectionFailed })?; @@ -88,11 +88,11 @@ async fn await_send_mtu(stream: &bluer::l2cap::Stream) { impl CableDataChannel for L2capDataChannel { async fn send(&mut self, message: &[u8]) -> Result<(), TransportError> { self.stream.write_all(message).await.map_err(|e| { - error!(?e, "Failed to write L2CAP message"); + warn!(?e, "Failed to write L2CAP message"); TransportError::IoError(e.kind()) })?; self.stream.write_all(&EOM).await.map_err(|e| { - error!(?e, "Failed to write L2CAP EOM"); + warn!(?e, "Failed to write L2CAP EOM"); TransportError::IoError(e.kind()) })?; Ok(()) @@ -120,7 +120,7 @@ impl CableDataChannel for L2capDataChannel { 0 } Err(e) => { - error!(?e, "Failed to read L2CAP message"); + warn!(?e, "Failed to read L2CAP message"); return Err(TransportError::IoError(e.kind())); } }; @@ -129,7 +129,7 @@ impl CableDataChannel for L2capDataChannel { if self.read_buf.is_empty() { return Ok(None); } - error!(buffered = self.read_buf.len(), "L2CAP closed mid-message"); + warn!(buffered = self.read_buf.len(), "L2CAP closed mid-message"); return Err(TransportError::ConnectionLost); } self.read_buf @@ -154,7 +154,7 @@ fn bdaddr_to_bluer( addr_type: Option, ) -> Result<(bluer::Address, bluer::AddressType), TransportError> { let addr = bluer::Address::from_str(&addr.to_string()).map_err(|e| { - error!(?e, "Failed to parse Bluetooth address"); + warn!(?e, "Failed to parse Bluetooth address"); TransportError::InvalidEndpoint })?; let addr_type = match addr_type { diff --git a/libwebauthn/src/transport/cable/protocol.rs b/libwebauthn/src/transport/cable/protocol.rs index ede4795c..ec246b99 100644 --- a/libwebauthn/src/transport/cable/protocol.rs +++ b/libwebauthn/src/transport/cable/protocol.rs @@ -215,10 +215,7 @@ pub(crate) async fn do_handshake( .get(..initial_msg_len) .map(<[u8]>::to_vec) .ok_or(TransportError::ConnectionFailed)?; - trace!( - { handshake = ?initial_msg }, - "Sending initial handshake message" - ); + trace!(handshake = ?initial_msg, "Sending initial handshake message"); data_channel.send(&initial_msg).await?; debug!("Sent initial handshake message"); @@ -231,20 +228,17 @@ pub(crate) async fn do_handshake( response } Ok(None) => { - error!("Connection was closed before handshake was complete"); + warn!("Connection was closed before handshake was complete"); return Err(TransportError::ConnectionFailed); } Err(e) => { - error!(?e, "Failed to read handshake response"); + warn!(?e, "Failed to read handshake response"); return Err(e); } }; if response.len() < P256_X962_LENGTH { - error!( - { len = response.len() }, - "Peer handshake message is too short" - ); + warn!(len = response.len(), "Peer handshake message is too short"); return Err(TransportError::ConnectionFailed); } @@ -252,18 +246,15 @@ pub(crate) async fn do_handshake( let payload_len = match noise_handshake.read_message(&response, &mut payload) { Ok(len) => len, Err(e) => { - error!(?e, "Failed to read handshake response message"); + warn!(?e, "Failed to read handshake response message"); return Err(TransportError::ConnectionFailed); } }; - debug!( - { handshake = ?payload.get(..payload_len) }, - "Received handshake response" - ); + debug!(handshake_len = payload_len, "Received handshake response"); if !noise_handshake.is_handshake_finished() { - error!("Handshake did not complete"); + warn!("Handshake did not complete"); return Err(TransportError::ConnectionFailed); } @@ -280,20 +271,23 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), T Ok(Some(message)) => match connection_recv_initial(message, &mut input.noise_state).await { Ok(initial) => initial, Err(e) => { - error!(?e, "Failed to process initial message"); + warn!(?e, "Failed to process initial message"); return Err(e); } }, Ok(None) => { - error!("Connection closed before initial message was received"); + warn!("Connection closed before initial message was received"); return Err(TransportError::ConnectionLost); } Err(e) => { - error!(?e, "Failed to read initial message"); + warn!(?e, "Failed to read initial message"); return Err(e); } }; - debug!(?get_info_response_serialized, "Received initial message"); + debug!( + get_info_response_serialized_len = get_info_response_serialized.len(), + "Received initial message" + ); loop { tokio::select! { @@ -315,7 +309,7 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), T Ok(RecvOutcome::Continue) => {} Ok(RecvOutcome::PeerShutdown) => return Ok(()), Err(e) => { - error!(?e, "Fatal error processing inbound frame"); + warn!(?e, "Fatal error processing inbound frame"); return Err(e); } } @@ -325,7 +319,7 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), T return Ok(()); } Err(e) => { - error!(?e, "Failed to read encrypted CBOR message"); + warn!(?e, "Failed to read encrypted CBOR message"); return Err(e); } } @@ -337,7 +331,7 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), T debug!("Responding to GetInfo request with cached response"); let response = CborResponse::new_success_from_slice(&get_info_response_serialized); if let Err(e) = input.cbor_rx_send.send(response).await { - error!(?e, "CBOR response receiver dropped"); + warn!(?e, "CBOR response receiver dropped"); return Err(TransportError::ConnectionFailed); } } @@ -350,7 +344,7 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), T ) .await { - error!(?e, "Fatal error sending CBOR request"); + warn!(?e, "Fatal error sending CBOR request"); return Err(e); } } @@ -372,13 +366,13 @@ async fn connection_send( .raw_long() .map_err(|e| TransportError::IoError(e.kind()))?; if cbor_request.len() > MAX_CBOR_SIZE { - error!( + warn!( cbor_request_len = cbor_request.len(), "CBOR request too large" ); return Err(TransportError::InvalidFraming); } - trace!(?cbor_request, cbor_request_len = cbor_request.len()); + trace!({ ?cbor_request, cbor_request_len = cbor_request.len() }); let extra_bytes = PADDING_GRANULARITY - (cbor_request.len() % PADDING_GRANULARITY); let padded_len = cbor_request.len() + extra_bytes; @@ -421,7 +415,7 @@ fn strip_frame_padding(mut decrypted_frame: Vec) -> Result, Transpor let padding_len = match decrypted_frame.last() { Some(&b) => b as usize, None => { - error!("Decrypted frame is empty; cannot read padding length"); + warn!("Decrypted frame is empty; cannot read padding length"); return Err(TransportError::InvalidFraming); } }; @@ -429,9 +423,9 @@ fn strip_frame_padding(mut decrypted_frame: Vec) -> Result, Transpor .len() .checked_sub(padding_len + 1) .ok_or_else(|| { - error!( - frame_len = decrypted_frame.len(), - padding_len, "Padding length exceeds frame length" + warn!( + { frame_len = decrypted_frame.len(), padding_len }, + "Padding length exceeds frame length" ); TransportError::InvalidFraming })?; @@ -454,15 +448,14 @@ async fn decrypt_frame( trace!(?decrypted_frame); } Err(e) => { - error!(?e, "Failed to decrypt CBOR response"); + warn!(?e, "Failed to decrypt CBOR response"); return Err(TransportError::EncryptionFailed); } } let decrypted_frame = strip_frame_padding(decrypted_frame)?; trace!( - ?decrypted_frame, - decrypted_frame_len = decrypted_frame.len(), + { ?decrypted_frame, decrypted_frame_len = decrypted_frame.len() }, "Trimmed padding" ); @@ -478,7 +471,7 @@ async fn connection_recv_initial( let initial_message: CableInitialMessage = match cbor::from_slice(&decrypted_frame) { Ok(initial_message) => initial_message, Err(e) => { - error!(?e, "Failed to decode initial message"); + warn!(?e, "Failed to decode initial message"); return Err(TransportError::InvalidFraming); } }; @@ -486,7 +479,7 @@ async fn connection_recv_initial( let _: Ctap2GetInfoResponse = match cbor::from_slice(&initial_message.info) { Ok(get_info_response) => get_info_response, Err(e) => { - error!(?e, "Failed to decode GetInfo response"); + warn!(?e, "Failed to decode GetInfo response"); return Err(TransportError::InvalidFraming); } }; @@ -503,7 +496,7 @@ async fn connection_recv_update( let update_message: BTreeMap = match serde_cbor::from_slice(message) { Ok(update_message) => update_message, Err(e) => { - error!(?e, "Failed to decode update message"); + warn!(?e, "Failed to decode update message"); return Err(TransportError::InvalidFraming); } }; @@ -570,7 +563,7 @@ async fn connection_recv( let decrypted_frame = decrypt_frame(encrypted_frame, noise_state).await?; let cable_message: CableTunnelMessage = CableTunnelMessage::from_slice(&decrypted_frame) - .inspect_err(|e| error!(?e, "Failed to decode CABLE tunnel message"))?; + .inspect_err(|e| warn!(?e, "Failed to decode CABLE tunnel message"))?; trace!(?cable_message); match cable_message.message_type { @@ -658,7 +651,7 @@ fn parse_known_device( let Ok(authenticator_public_key) = PublicKey::from_sec1_bytes(&linking_info.authenticator_public_key) else { - error!("Failed to parse public key."); + warn!("Failed to parse public key"); return Err(TransportError::InvalidKey); }; @@ -675,8 +668,8 @@ fn parse_known_device( let expected_mac = hmac.finalize().into_bytes().to_vec(); if expected_mac != linking_info.handshake_signature { - error!("Invalid handshake signature, rejecting update message"); - trace!(?expected_mac, ?linking_info.handshake_signature); + warn!("Invalid handshake signature, rejecting update message"); + trace!({ ?expected_mac, ?linking_info.handshake_signature }); return Err(TransportError::InvalidSignature); } diff --git a/libwebauthn/src/transport/cable/tunnel.rs b/libwebauthn/src/transport/cable/tunnel.rs index d1e2c7ab..c067d6a5 100644 --- a/libwebauthn/src/transport/cable/tunnel.rs +++ b/libwebauthn/src/transport/cable/tunnel.rs @@ -3,7 +3,7 @@ use sha2::{Digest, Sha256}; use tokio::net::TcpStream; use tokio_tungstenite::tungstenite::http::StatusCode; use tokio_tungstenite::{connect_async, MaybeTlsStream, WebSocketStream}; -use tracing::{debug, error, trace}; +use tracing::{debug, trace, warn}; use tungstenite::client::IntoClientRequest; use super::protocol::CableTunnelConnectionType; @@ -95,19 +95,19 @@ pub(crate) async fn connect( .or(Err(TransportError::InvalidEndpoint))?, ); } - trace!(?request); + trace!(?request, "Tunnel server request"); let (ws_stream, response) = match connect_async(request).await { Ok((ws_stream, response)) => (ws_stream, response), Err(e) => { - error!(?e, "Failed to connect to tunnel server"); + warn!(?e, "Failed to connect to tunnel server"); return Err(TransportError::ConnectionFailed); } }; debug!(?response, "Connected to tunnel server"); if response.status() != StatusCode::SWITCHING_PROTOCOLS { - error!(?response, "Failed to switch to websocket protocol"); + warn!(?response, "Failed to switch to websocket protocol"); return Err(TransportError::ConnectionFailed); } debug!("Tunnel server returned success"); From fb8608e95f7ce1c7bba7729d88b9e62e4295d35d Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 04/10] refactor(hid): apply the logging policy Wire-framing and packet-validation failures are device behaviour, so they move from error! to warn!. Demote the device-blink notices to debug! and use static messages with structured fields. --- libwebauthn/src/transport/hid/channel.rs | 24 +++++++++--------------- libwebauthn/src/transport/hid/device.rs | 2 +- libwebauthn/src/transport/hid/framing.rs | 18 +++++++++--------- 3 files changed, 19 insertions(+), 25 deletions(-) diff --git a/libwebauthn/src/transport/hid/channel.rs b/libwebauthn/src/transport/hid/channel.rs index 552a0948..45dace4a 100644 --- a/libwebauthn/src/transport/hid/channel.rs +++ b/libwebauthn/src/transport/hid/channel.rs @@ -13,7 +13,7 @@ use tokio::sync::broadcast; use tokio::sync::mpsc::error::TryRecvError; use tokio::sync::mpsc::{self, Receiver, Sender}; use tokio::time::sleep; -use tracing::{debug, info, instrument, trace, warn, Level}; +use tracing::{debug, instrument, trace, warn, Level}; use crate::pin::persistent_token::PersistentTokenStore; use crate::proto::ctap1::apdu::{ApduRequest, ApduResponse}; @@ -157,7 +157,7 @@ impl<'d> HidChannel<'d> { Err(_) => Ok(false), } } else { - info!("Creating dummy request to make the device blink"); + debug!("Creating dummy request to make the device blink"); let ctap2_request = Ctap2MakeCredentialRequest::dummy(); match self.ctap2_make_credential(&ctap2_request, timeout).await { Ok(_) @@ -168,7 +168,7 @@ impl<'d> HidChannel<'d> { } } } else if supported.u2f { - info!("Creating dummy request to make the device blink"); + debug!("Creating dummy request to make the device blink"); let register_request = Ctap1RegisterRequest::dummy(timeout); match self.ctap1_register(®ister_request).await { Ok(_) @@ -197,10 +197,7 @@ impl<'d> HidChannel<'d> { } if response.payload.len() < INIT_PAYLOAD_LEN { - warn!( - { len = response.payload.len() }, - "INIT payload is too small" - ); + warn!(len = response.payload.len(), "INIT payload is too small"); return Err(Error::Transport(TransportError::InvalidEndpoint)); } @@ -209,7 +206,7 @@ impl<'d> HidChannel<'d> { .get(..INIT_NONCE_LEN) .ok_or(Error::Transport(TransportError::InvalidEndpoint))?; if payload_nonce != nonce.as_slice() { - warn!("INIT nonce mismatch. Terminating."); + warn!("INIT nonce mismatch"); return Err(Error::Transport(TransportError::InvalidEndpoint)); } @@ -457,7 +454,7 @@ impl<'d> HidChannel<'d> { trace!("hidapi read_timeout returned 0 bytes, continuing"); continue; } - debug!({ len = bytes_read }, "Received HID report"); + debug!(len = bytes_read, "Received HID report"); trace!(?report); if let HidMessageParserState::Done = parser .update(&report) @@ -524,7 +521,7 @@ impl Channel for HidChannel<'_> { _timeout: std::time::Duration, ) -> Result<(), Error> { let cid = self.init.cid; - debug!({ cid }, "Sending APDU request"); + debug!(cid, "Sending APDU request"); trace!(?request); let apdu_raw = request .raw_long() @@ -545,7 +542,7 @@ impl Channel for HidChannel<'_> { async fn cbor_send(&mut self, request: &CborRequest, _timeout: Duration) -> Result<(), Error> { let cid = self.init.cid; - debug!({ cid }, "Sending CBOR request"); + debug!(cid, "Sending CBOR request"); trace!(?request); self.hid_send(&HidMessage::new( cid, @@ -560,10 +557,7 @@ impl Channel for HidChannel<'_> { let hid_response = self.hid_recv(timeout).await?; let cbor_response = CborResponse::try_from(&hid_response.payload) .or(Err(Error::Transport(TransportError::InvalidFraming)))?; - debug!( - { status = ?cbor_response.status_code }, - "Received CBOR response" - ); + debug!(status = ?cbor_response.status_code, "Received CBOR response"); trace!(?cbor_response); Ok(cbor_response) } diff --git a/libwebauthn/src/transport/hid/device.rs b/libwebauthn/src/transport/hid/device.rs index b860ecb9..cbb5431e 100644 --- a/libwebauthn/src/transport/hid/device.rs +++ b/libwebauthn/src/transport/hid/device.rs @@ -68,7 +68,7 @@ pub async fn list_devices() -> Result, Error> { .filter(|device| device.usage() == 0x0001) .map(|device| device.into()) .collect(); - info!({ count = devices.len() }, "Listing available HID devices"); + info!(count = devices.len(), "Listing available HID devices"); debug!(?devices); Ok(devices) } diff --git a/libwebauthn/src/transport/hid/framing.rs b/libwebauthn/src/transport/hid/framing.rs index 3ebbcd0b..26a330cc 100644 --- a/libwebauthn/src/transport/hid/framing.rs +++ b/libwebauthn/src/transport/hid/framing.rs @@ -3,7 +3,7 @@ use std::io::{Cursor as IOCursor, Error as IOError, ErrorKind as IOErrorKind}; use byteorder::{BigEndian, ReadBytesExt, WriteBytesExt}; use num_enum::{IntoPrimitive, TryFromPrimitive}; -use tracing::error; +use tracing::warn; const BROADCAST_CID: u32 = 0xFFFFFFFF; const PACKET_INITIAL_HEADER_SIZE: usize = 7; @@ -122,7 +122,7 @@ impl HidMessageParser { if (self.packets.is_empty() && packet.len() < PACKET_INITIAL_HEADER_SIZE) || packet.len() < PACKET_CONT_HEADER_SIZE + 1 { - error!("Packet length is invalid"); + warn!("Packet length is invalid"); return Err(IOError::new( IOErrorKind::InvalidInput, "Packet length is invalid", @@ -131,7 +131,7 @@ impl HidMessageParser { // CID 0x00000000 is reserved (CTAP 2.2 §11.2.4); reject all-zero frames. if packet.iter().all(|&b| b == 0) { - error!("Received all-zero packet, rejecting"); + warn!("Received all-zero packet, rejecting"); return Err(IOError::new( IOErrorKind::InvalidData, "All-zero packet is not a valid CTAPHID frame", @@ -145,7 +145,7 @@ impl HidMessageParser { .get(4) .is_some_and(|&byte| byte & PACKET_INITIAL_CMD_MASK != 0); if !is_initialization { - error!("First packet is not an initialization packet"); + warn!("First packet is not an initialization packet"); return Err(IOError::new( IOErrorKind::InvalidData, "First packet must be an initialization packet", @@ -156,7 +156,7 @@ impl HidMessageParser { // high bit cleared, SEQ starts at 0 and increments monotonically. let initial_cid = self.packets.first().and_then(|initial| initial.get(..4)); if packet.get(..4) != initial_cid { - error!("Continuation packet CID does not match initial packet"); + warn!("Continuation packet CID does not match initial packet"); return Err(IOError::new( IOErrorKind::InvalidData, "Continuation packet CID mismatch", @@ -169,7 +169,7 @@ impl HidMessageParser { )); }; if seq & PACKET_INITIAL_CMD_MASK != 0 { - error!(seq, "Unexpected init packet during continuation"); + warn!(seq, "Unexpected init packet during continuation"); return Err(IOError::new( IOErrorKind::InvalidData, "Unexpected initialization packet during continuation", @@ -177,14 +177,14 @@ impl HidMessageParser { } let expected_seq = (self.packets.len() - 1) as u8; if expected_seq > PACKET_CONT_SEQ_MAX { - error!(seq, "Continuation count exceeds maximum SEQ"); + warn!(seq, "Continuation count exceeds maximum SEQ"); return Err(IOError::new( IOErrorKind::InvalidData, "Too many continuation packets", )); } if seq != expected_seq { - error!(seq, expected_seq, "Out-of-order continuation SEQ"); + warn!({ seq, expected_seq }, "Out-of-order continuation SEQ"); return Err(IOError::new( IOErrorKind::InvalidData, "Out-of-order continuation SEQ", @@ -243,7 +243,7 @@ impl HidMessageParser { let cid = cursor.read_u32::()?; let cmd = cursor.read_u8()? ^ PACKET_INITIAL_CMD_MASK; let Ok(cmd) = cmd.try_into() else { - error!(?cmd, "Invalid HID message command"); + warn!(?cmd, "Invalid HID message command"); return Err(IOError::new( IOErrorKind::InvalidData, format!("Invalid HID message command: {:?}", cmd), From 97e7978518d75146bc0d8d8cef7629596fee1ee7 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 05/10] refactor(ble): apply the logging policy Downgrade connect, GATT, read/write and pairing failures from error! to warn!, demote the device-cancelled notice to debug!, and reduce the service-data dump to a length at debug!. --- libwebauthn/src/transport/ble/btleplug/connection.rs | 8 ++++---- libwebauthn/src/transport/ble/btleplug/manager.rs | 6 +++--- libwebauthn/src/transport/ble/btleplug/pairing.rs | 8 ++++---- libwebauthn/src/transport/ble/channel.rs | 10 +++++----- libwebauthn/src/transport/ble/device.rs | 2 +- 5 files changed, 17 insertions(+), 17 deletions(-) diff --git a/libwebauthn/src/transport/ble/btleplug/connection.rs b/libwebauthn/src/transport/ble/btleplug/connection.rs index f8d6b3bc..03ddcd81 100644 --- a/libwebauthn/src/transport/ble/btleplug/connection.rs +++ b/libwebauthn/src/transport/ble/btleplug/connection.rs @@ -79,7 +79,7 @@ impl Connection { if max_fragment_length.len() != 2 { warn!( - { len = max_fragment_length.len() }, + len = max_fragment_length.len(), "Control point length endpoint returned an unexpected number of bytes", ); return Err(Error::OperationFailed); @@ -102,7 +102,7 @@ impl Connection { for (i, fragment) in fragments.iter().enumerate() { debug!({ fragment = i, len = fragment.len() }, "Sending fragment"); - trace!(?fragment); + trace!(?fragment, "Sending fragment"); self.peripheral .write(&self.services.control_point, fragment, write_type) @@ -173,7 +173,7 @@ impl Connection { }; debug!("Received fragment"); - trace!(?fragment); + trace!(?fragment, "Received fragment"); let status = parser.update(&fragment).or(Err(Error::InvalidFraming))?; match status { @@ -186,7 +186,7 @@ impl Connection { parser.reset(); } BleCommand::Cancel => { - info!("Device canceled operation"); + debug!("Device canceled operation"); return Err(Error::Canceled); } BleCommand::Error => { diff --git a/libwebauthn/src/transport/ble/btleplug/manager.rs b/libwebauthn/src/transport/ble/btleplug/manager.rs index 99ed0c26..5c717526 100644 --- a/libwebauthn/src/transport/ble/btleplug/manager.rs +++ b/libwebauthn/src/transport/ble/btleplug/manager.rs @@ -65,13 +65,13 @@ async fn on_peripheral_service_data( ) -> Option<(Adapter, Peripheral, Vec)> { for uuid in uuids { if let Some(service_data) = service_data.get(uuid) { - trace!(?id, ?service_data, "Found service data"); + trace!({ ?id, ?service_data }, "Found service data"); let Ok(peripheral) = adapter.peripheral(id).await else { warn!(?id, "Could not get peripheral"); return None; }; - debug!({ ?id, ?service_data }, "Found service data for peripheral"); + debug!({ ?id, len = service_data.len() }, "Found service data for peripheral"); return Some((adapter.clone(), peripheral, service_data.to_owned())); } } @@ -143,7 +143,7 @@ async fn discover_properties( .properties() .await .or(Err(Error::ConnectionFailed))?; - trace!({ ?peripheral, ?properties }); + trace!({ ?peripheral, ?properties }, "Discovered peripheral properties"); if let Some(properties) = properties { result.push((peripheral, properties)); } diff --git a/libwebauthn/src/transport/ble/btleplug/pairing.rs b/libwebauthn/src/transport/ble/btleplug/pairing.rs index 59b1a5c5..5f3c6e00 100644 --- a/libwebauthn/src/transport/ble/btleplug/pairing.rs +++ b/libwebauthn/src/transport/ble/btleplug/pairing.rs @@ -30,7 +30,7 @@ pub(crate) async fn check_bonded(peripheral: &Peripheral) -> BondingState { match result { Ok(Ok((paired, bonded))) => { - info!(?address, paired, bonded, "bluez bonding state"); + info!({ ?address, paired, bonded }, "BlueZ bonding state"); if paired && bonded { BondingState::Bonded } else { @@ -38,11 +38,11 @@ pub(crate) async fn check_bonded(peripheral: &Peripheral) -> BondingState { } } Ok(Err(e)) => { - warn!(?address, error = ?e, "Could not query bluez bonding state"); + warn!({ ?address, error = ?e }, "Could not query bluez bonding state"); BondingState::Unknown } Err(e) => { - warn!(error = ?e, "bluez bonding query task panicked"); + warn!(error = ?e, "BlueZ bonding query task panicked"); BondingState::Unknown } } @@ -64,7 +64,7 @@ pub(crate) async fn enforce_bonded(peripheral: &Peripheral) -> Result<(), Error> warn!( "BLE FIDO authenticator is not bonded with LE Secure Connections; \ CTAP 2.2 §11.4 requires bonding. Pair the device via the OS \ - (e.g. `bluetoothctl pair `) before retrying." + (e.g. `bluetoothctl pair `) before retrying" ); Err(Error::ConnectionFailed) } diff --git a/libwebauthn/src/transport/ble/channel.rs b/libwebauthn/src/transport/ble/channel.rs index 2b577f60..34261935 100644 --- a/libwebauthn/src/transport/ble/channel.rs +++ b/libwebauthn/src/transport/ble/channel.rs @@ -94,8 +94,8 @@ impl<'a> Channel for BleChannel<'a> { #[instrument(level = Level::DEBUG, skip_all)] async fn apdu_send(&mut self, request: &ApduRequest, _timeout: Duration) -> Result<(), Error> { - debug!({rev = ?self.revision}, "Sending APDU request"); - trace!(?request); + debug!(rev = ?self.revision, "Sending APDU request"); + trace!(?request, "Sending APDU request"); let request_apdu_packet = request.raw_long().or(Err(TransportError::InvalidFraming))?; let request_frame = BleFrame::new(BleCommand::Msg, &request_apdu_packet); @@ -129,7 +129,7 @@ impl<'a> Channel for BleChannel<'a> { .or(Err(TransportError::InvalidFraming))?; debug!("Received APDU response"); - trace!(?response_apdu); + trace!(?response_apdu, "Received APDU response"); Ok(response_apdu) } @@ -140,7 +140,7 @@ impl<'a> Channel for BleChannel<'a> { _timeout: std::time::Duration, ) -> Result<(), Error> { debug!("Sending CBOR request"); - trace!(?request); + trace!(?request, "Sending CBOR request"); let cbor_request = request .raw_long() @@ -175,7 +175,7 @@ impl<'a> Channel for BleChannel<'a> { .or(Err(TransportError::InvalidFraming))?; debug!("Received CBOR response"); - trace!(?cbor_response); + trace!(?cbor_response, "Received CBOR response"); Ok(cbor_response) } diff --git a/libwebauthn/src/transport/ble/device.rs b/libwebauthn/src/transport/ble/device.rs index cb677f4a..757e6dc5 100644 --- a/libwebauthn/src/transport/ble/device.rs +++ b/libwebauthn/src/transport/ble/device.rs @@ -29,7 +29,7 @@ pub async fn list_devices() -> Result, Error> { .iter() .map(|bluez_device| bluez_device.into()) .collect(); - info!({ count = devices.len() }, "Listing available BLE devices"); + info!(count = devices.len(), "Listing available BLE devices"); Ok(devices) } From 937c1bcfad36acad579239499b6160be75b7d62a Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 06/10] refactor(nfc, ctap1): apply the logging policy NFC/PC-SC transport faults move from error! to warn! and the stray println! becomes a warn!. U2F APDU non-success status words are an expected, polled part of the flow, so they log at debug! rather than error!. Raw APDU buffers stay at trace! with static messages. --- libwebauthn/src/proto/ctap1/protocol.rs | 32 ++++++++++----------- libwebauthn/src/transport/nfc/channel.rs | 10 +++---- libwebauthn/src/transport/nfc/device.rs | 2 +- libwebauthn/src/transport/nfc/libnfc/mod.rs | 18 ++++++------ libwebauthn/src/transport/nfc/pcsc/mod.rs | 6 ++-- 5 files changed, 34 insertions(+), 34 deletions(-) diff --git a/libwebauthn/src/proto/ctap1/protocol.rs b/libwebauthn/src/proto/ctap1/protocol.rs index f4c913b0..d7843786 100644 --- a/libwebauthn/src/proto/ctap1/protocol.rs +++ b/libwebauthn/src/proto/ctap1/protocol.rs @@ -3,7 +3,7 @@ use std::time::Duration; use async_trait::async_trait; use tokio::time::{sleep, timeout as tokio_timeout}; -use tracing::{debug, error, info, instrument, span, trace, warn, Level}; +use tracing::{debug, instrument, span, trace, warn, Level}; use super::apdu::{ApduRequest, ApduResponse, ApduResponseStatus}; use super::{ @@ -41,7 +41,7 @@ where self.apdu_send(&apdu_request, VERSION_TIMEOUT).await?; let apdu_response = self.apdu_recv(VERSION_TIMEOUT).await?; let response: Ctap1VersionResponse = apdu_response.try_into().or(Err(CtapError::Other))?; - debug!({ ?response.version }, "CTAP1 version response"); + debug!(?response.version, "CTAP1 version response"); Ok(response) } @@ -50,25 +50,25 @@ where &mut self, request: &Ctap1RegisterRequest, ) -> Result { - debug!({ %request.require_user_presence }, "CTAP1 register request"); - trace!(?request); + debug!(%request.require_user_presence, "CTAP1 register request"); + trace!(?request, "CTAP1 register request"); self.send_ux_update(UvUpdate::PresenceRequired.into()).await; let (request, preflight_requests) = request.preflight()?; - debug!({ count = preflight_requests.len() }, "Preflight requests"); + debug!(count = preflight_requests.len(), "Preflight requests"); for preflight in preflight_requests.iter() { let span = span!(Level::DEBUG, "preflight"); let _enter = span.enter(); match self.ctap1_sign(preflight).await { Ok(_) => { - info!("Already-registered credential found during preflight request."); + debug!("Already-registered credential found during preflight"); return Err(Error::Ctap(CtapError::CredentialExcluded)); } Err(Error::Ctap(CtapError::NoCredentials)) => { - debug!("Credential doesn't already exist, continuing."); + debug!("Credential doesn't already exist, continuing"); } Err(err) => { - warn!(?err, "Preflight request failed with unexpected error."); + warn!(?err, "Preflight request failed with unexpected error"); } }; } @@ -77,33 +77,33 @@ where let apdu_response = send_apdu_request_wait_uv(self, &apdu_request, request.timeout).await?; let status = apdu_response.status().or(Err(CtapError::Other))?; if status != ApduResponseStatus::NoError { - error!(?status, "APDU response has error code"); + debug!(?status, "APDU response has error code"); return Err(Error::Ctap(CtapError::from(status))); } let response: Ctap1RegisterResponse = apdu_response.try_into().or(Err(CtapError::Other))?; debug!("CTAP1 register response"); - trace!(?response); + trace!(?response, "CTAP1 register response"); Ok(response) } #[instrument(skip_all, fields(preflight = !request.require_user_presence))] async fn ctap1_sign(&mut self, request: &Ctap1SignRequest) -> Result { - debug!({ %request.require_user_presence }, "CTAP1 sign request"); - trace!(?request); + debug!(%request.require_user_presence, "CTAP1 sign request"); + trace!(?request, "CTAP1 sign request"); self.send_ux_update(UvUpdate::PresenceRequired.into()).await; let apdu_request: ApduRequest = request.into(); let apdu_response = send_apdu_request_wait_uv(self, &apdu_request, request.timeout).await?; let status = apdu_response.status().or(Err(CtapError::Other))?; if status != ApduResponseStatus::NoError { - error!(?status, "APDU response has error code"); + debug!(?status, "APDU response has error code"); return Err(Error::Ctap(CtapError::from(status))); } let response: Ctap1SignResponse = apdu_response.try_into().or(Err(CtapError::Other))?; - debug!({ ?response.user_presence_verified }, "CTAP1 sign response received"); - trace!(?response); + debug!(?response.user_presence_verified, "CTAP1 sign response received"); + trace!(?response, "CTAP1 sign response"); Ok(response) } } @@ -126,7 +126,7 @@ async fn send_apdu_request_wait_uv( CtapError::UserPresenceRequired => (), // Sleep some more. _ => return Err(Error::Ctap(ctap_error)), }; - debug!("UP required. Sleeping for {:?}.", UP_SLEEP); + debug!(sleep = ?UP_SLEEP, "User presence required, sleeping"); sleep(UP_SLEEP).await; } }) diff --git a/libwebauthn/src/transport/nfc/channel.rs b/libwebauthn/src/transport/nfc/channel.rs index 3a81fade..f8e9091e 100644 --- a/libwebauthn/src/transport/nfc/channel.rs +++ b/libwebauthn/src/transport/nfc/channel.rs @@ -52,7 +52,7 @@ pub enum NfcError { impl From for Error { fn from(input: NfcError) -> Self { - trace!("{:?}", input); + trace!(?input, "NFC error"); let output = match input { NfcError::Apdu(_apdu_error) => TransportError::InvalidFraming, NfcError::Device(_) => TransportError::ConnectionLost, @@ -236,7 +236,7 @@ where Result::from(Response::from(rapdu.as_slice())) .map(|p| p.to_vec()) .map_err(|e| { - trace!("map_err {:?}", e); + trace!(?e, "APDU error response"); apdu::Error::from(e).into() }) } @@ -270,7 +270,7 @@ where #[instrument(level = Level::DEBUG, skip_all)] async fn apdu_send(&mut self, request: &ApduRequest, _timeout: Duration) -> Result<(), Error> { let resp = self.handle_raw(self.ctx, request)?; - trace!("apdu_send {:?}", resp); + trace!(?resp, "Raw APDU response"); let apdu_response = ApduResponse::try_from(&resp) .or(Err(Error::Transport(TransportError::InvalidFraming)))?; @@ -299,12 +299,12 @@ where rest = remaining; let ctap_msg = command_ctap_msg(true, to_send); let resp = self.handle(self.ctx, ctap_msg)?; - trace!("cbor_send has_more {:?} {:?}", to_send, resp); + trace!({ ?to_send, ?resp }, "CBOR request chunk sent"); } let ctap_msg = command_ctap_msg(false, rest); let resp = self.handle(self.ctx, ctap_msg)?; - trace!("cbor_send {:?} {:?}", rest, resp); + trace!({ ?rest, ?resp }, "CBOR request sent"); // FIXME check for SW_UPDATE? diff --git a/libwebauthn/src/transport/nfc/device.rs b/libwebauthn/src/transport/nfc/device.rs index a7c8596d..223b22e5 100644 --- a/libwebauthn/src/transport/nfc/device.rs +++ b/libwebauthn/src/transport/nfc/device.rs @@ -61,7 +61,7 @@ impl NfcDevice { } async fn channel_sync(&self, settings: ChannelSettings) -> Result, Error> { - trace!("nfc channel {:?}", self); + trace!(?self, "Opening NFC channel"); let mut channel: NfcChannel = match &self.info { #[cfg(feature = "nfc-backend-libnfc")] DeviceInfo::LibNfc(info) => info.channel(settings), diff --git a/libwebauthn/src/transport/nfc/libnfc/mod.rs b/libwebauthn/src/transport/nfc/libnfc/mod.rs index e5a25301..23309690 100644 --- a/libwebauthn/src/transport/nfc/libnfc/mod.rs +++ b/libwebauthn/src/transport/nfc/libnfc/mod.rs @@ -13,7 +13,7 @@ use std::sync::{Arc, Mutex}; use std::thread; use std::time::Duration; #[allow(unused_imports)] -use tracing::{debug, info, instrument, trace}; +use tracing::{debug, info, instrument, trace, warn}; const MAX_DEVICES: usize = 10; const TIMEOUT: Duration = Duration::from_millis(5000); @@ -36,7 +36,7 @@ fn map_error(_err: nfc1::Error) -> Error { impl From for Error { fn from(input: nfc1::Error) -> Self { - trace!("{:?}", input); + trace!(?input, "NFC backend error"); let output = match input { // rs-nfc1 errors nfc1::Error::Malloc => TransportError::TransportUnavailable, @@ -84,11 +84,11 @@ impl Info { device.set_property_bool(nfc1::Property::InfiniteSelect, false)?; let info = device.get_information_about()?; - debug!("Info: {}", info); + debug!(%info, "Device information"); } let target = chan.connect_to_target()?; - debug!("Selected: {:?}", target); + debug!(?target, "Selected target"); let ctx = Context {}; let channel = NfcChannel::new(Box::new(chan), ctx, settings); @@ -131,7 +131,7 @@ impl Channel { } } Err(err) => { - println!("Error: {}", err); + warn!(%err, "Failed to select passive target"); Err(err) } } @@ -159,7 +159,7 @@ impl Channel { if i > 0 { thread::sleep(Duration::from_millis(100)); } - trace!("Poll {:?} {}", modulation, i); + trace!({ ?modulation, attempt = i }, "Polling target"); if let Ok(target) = Channel::initiator_select_passive_target_ex(&mut device, modulation) { if is_one_rate { @@ -169,7 +169,7 @@ impl Channel { for modulation in modulations.iter() { device.initiator_deselect_target()?; device.initiator_init()?; - trace!("Try {:?}", modulation); + trace!(?modulation, "Trying modulation"); if let Ok(target) = Channel::initiator_select_passive_target_ex(&mut device, modulation) { @@ -195,7 +195,7 @@ where ) -> apdu_core::Result { let timeout = nfc1::Timeout::Duration(TIMEOUT); let len = response.len(); - trace!("TX: {:?}", command); + trace!(?command, "Transmitting APDU"); let rapdu = self .device .lock() @@ -203,7 +203,7 @@ where .initiator_transceive_bytes(command, len, timeout) .map_err(|e| HandleError::Nfc(Box::new(e)))?; - trace!("RX: {:?}", rapdu); + trace!(?rapdu, "Received APDU"); if response.len() < rapdu.len() { return Err(HandleError::NotEnoughBuffer(rapdu.len())); diff --git a/libwebauthn/src/transport/nfc/pcsc/mod.rs b/libwebauthn/src/transport/nfc/pcsc/mod.rs index 3b5be6b9..b8bea9e5 100644 --- a/libwebauthn/src/transport/nfc/pcsc/mod.rs +++ b/libwebauthn/src/transport/nfc/pcsc/mod.rs @@ -65,7 +65,7 @@ impl fmt::Display for Info { impl From for Error { fn from(input: pcsc::Error) -> Self { - trace!("{:?}", input); + trace!(?input, "PC/SC error"); let output = match input { pcsc::Error::NoSmartcard => TransportError::ConnectionFailed, _ => TransportError::InvalidFraming, @@ -126,7 +126,7 @@ where command: &[u8], response: &mut [u8], ) -> apdu_core::Result { - trace!("TX: {:?}", command); + trace!(?command, "Transmitting APDU"); let card = self .card @@ -136,7 +136,7 @@ where .transmit(command, response) .map_err(|e| HandleError::Nfc(Box::new(e)))?; - trace!("RX: {:?}", rapdu); + trace!(?rapdu, "Received APDU"); Ok(rapdu.len()) } } From a831f9ee6bf5f7f6d8d3202b0754259120926a79 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 07/10] refactor(ctap2): apply the logging policy Malformed or unknown device responses move from error! to warn!. The preflight credential dumps were logging credential IDs at info!, which is sensitive: keep only a count at debug! and move the full lists to trace!. Replace interpolated messages with structured fields. --- libwebauthn/src/proto/ctap2/cbor/response.rs | 4 +-- libwebauthn/src/proto/ctap2/cose.rs | 9 +++---- .../src/proto/ctap2/model/get_assertion.rs | 2 +- libwebauthn/src/proto/ctap2/model/get_info.rs | 6 ++--- .../src/proto/ctap2/model/make_credential.rs | 4 +-- libwebauthn/src/proto/ctap2/preflight.rs | 25 +++++++++++++------ libwebauthn/src/proto/ctap2/protocol.rs | 11 ++++---- 7 files changed, 34 insertions(+), 27 deletions(-) diff --git a/libwebauthn/src/proto/ctap2/cbor/response.rs b/libwebauthn/src/proto/ctap2/cbor/response.rs index e52970e0..84bb648a 100644 --- a/libwebauthn/src/proto/ctap2/cbor/response.rs +++ b/libwebauthn/src/proto/ctap2/cbor/response.rs @@ -2,7 +2,7 @@ use crate::proto::error::CtapError; use std::convert::{TryFrom, TryInto}; use std::io::{Error as IOError, ErrorKind as IOErrorKind}; -use tracing::error; +use tracing::warn; #[derive(Debug, Clone)] pub struct CborResponse { @@ -33,7 +33,7 @@ impl TryFrom<&Vec> for CborResponse { })?; let Ok(status_code) = (*status_byte).try_into() else { - error!({ code = ?*status_byte }, "Invalid CTAP error code"); + warn!(code = ?*status_byte, "Invalid CTAP error code"); return Err(IOError::new( IOErrorKind::InvalidData, format!("Invalid CTAP error code: {:x}", status_byte), diff --git a/libwebauthn/src/proto/ctap2/cose.rs b/libwebauthn/src/proto/ctap2/cose.rs index 57e68b88..e188d350 100644 --- a/libwebauthn/src/proto/ctap2/cose.rs +++ b/libwebauthn/src/proto/ctap2/cose.rs @@ -74,7 +74,7 @@ type CoseMap = std::collections::BTreeMap; fn parse_cose_map(bytes: &[u8]) -> Result { let value: Value = serde_cbor_2::from_slice(bytes).map_err(|e| { - warn!(%e, "failed to parse COSE_Key as CBOR"); + warn!(%e, "Failed to parse COSE_Key as CBOR"); Error::Platform(PlatformError::InvalidDeviceResponse) })?; match value { @@ -176,7 +176,7 @@ pub fn to_spki(bytes: &[u8]) -> Result>, Error> { fn require_kty(map: &CoseMap, expected: i128) -> Result<(), Error> { let kty = map_integer(map, COSE_KEY_LABEL_KTY)?; if kty != expected { - warn!(expected, got = kty, "COSE_Key kty mismatch"); + warn!({ expected, got = kty }, "COSE_Key kty mismatch"); return Err(Error::Platform(PlatformError::InvalidDeviceResponse)); } Ok(()) @@ -185,7 +185,7 @@ fn require_kty(map: &CoseMap, expected: i128) -> Result<(), Error> { fn require_crv(map: &CoseMap, expected: i128) -> Result<(), Error> { let crv = map_integer(map, COSE_KEY_LABEL_CRV)?; if crv != expected { - warn!(expected, got = crv, "COSE_Key crv mismatch"); + warn!({ expected, got = crv }, "COSE_Key crv mismatch"); return Err(Error::Platform(PlatformError::InvalidDeviceResponse)); } Ok(()) @@ -194,8 +194,7 @@ fn require_crv(map: &CoseMap, expected: i128) -> Result<(), Error> { fn p256_spki(x: &[u8], y: &[u8]) -> Result, Error> { if x.len() != 32 || y.len() != 32 { warn!( - x_len = x.len(), - y_len = y.len(), + { x_len = x.len(), y_len = y.len() }, "P-256 coordinates wrong size" ); return Err(Error::Platform(PlatformError::InvalidDeviceResponse)); diff --git a/libwebauthn/src/proto/ctap2/model/get_assertion.rs b/libwebauthn/src/proto/ctap2/model/get_assertion.rs index 1ab04b37..ddfb830d 100644 --- a/libwebauthn/src/proto/ctap2/model/get_assertion.rs +++ b/libwebauthn/src/proto/ctap2/model/get_assertion.rs @@ -274,7 +274,7 @@ impl Ctap2GetAssertionRequestExtensions { let salt_enc = if let Ok(res) = uv_proto.encrypt(&auth_data.shared_secret, &salts) { ByteBuf::from(res) } else { - error!("Failed to encrypt HMAC salts with shared secret! Skipping HMAC"); + error!("Failed to encrypt HMAC salts"); // TODO: This is a bit of a weird one. Normally, we would just skip HMACs that // fail for whatever reason, so a Result<> was not necessary. // But with the PRF-extension, the spec tells us explicitly to return diff --git a/libwebauthn/src/proto/ctap2/model/get_info.rs b/libwebauthn/src/proto/ctap2/model/get_info.rs index fb0f15ab..8cab810b 100644 --- a/libwebauthn/src/proto/ctap2/model/get_info.rs +++ b/libwebauthn/src/proto/ctap2/model/get_info.rs @@ -229,7 +229,7 @@ impl Ctap2GetInfoResponse { pub fn uv_operation(&self, uv_blocked: bool) -> Option { if self.option_enabled("uv") && !uv_blocked { if self.option_enabled("pinUvAuthToken") { - debug!("getPinUvAuthTokenUsingUvWithPermissions"); + debug!("Selected getPinUvAuthTokenUsingUvWithPermissions"); Some(Ctap2UserVerificationOperation::GetPinUvAuthTokenUsingUvWithPermissions) } else { debug!("Deprecated FIDO 2.0 behaviour: populating 'uv' flag"); @@ -267,11 +267,11 @@ impl Ctap2GetInfoResponse { ); return Some(Ctap2UserVerificationOperation::OnlyForSharedSecret); } - debug!("getPinUvAuthTokenUsingPinWithPermissions"); + debug!("Selected getPinUvAuthTokenUsingPinWithPermissions"); Some(Ctap2UserVerificationOperation::GetPinUvAuthTokenUsingPinWithPermissions) } else if self.option_enabled("clientPin") { // !pinUvAuthToken - debug!("getPinToken"); + debug!("Selected getPinToken"); Some(Ctap2UserVerificationOperation::GetPinToken) } else { debug!("No UV and no PIN (e.g. maybe UV was blocked and no PIN available)"); diff --git a/libwebauthn/src/proto/ctap2/model/make_credential.rs b/libwebauthn/src/proto/ctap2/model/make_credential.rs index f2076d99..4cf5f3c1 100644 --- a/libwebauthn/src/proto/ctap2/model/make_credential.rs +++ b/libwebauthn/src/proto/ctap2/model/make_credential.rs @@ -149,7 +149,7 @@ impl Ctap2MakeCredentialRequest { } Some(ResidentKeyRequirement::Required) => { if !info.option_enabled("rk") { - warn!("This request will potentially fail. Discoverable credential required, but device does not support it."); + warn!("Discoverable credential required but device does not support it"); } // We still send the request to the device and let it sort it out. // We only add a warning for easier debugging. @@ -308,7 +308,7 @@ impl Ctap2MakeCredentialsRequestExtensions { Err(err) => { error!( ?err, - "Failed to encrypt hmac-secret-mc salts; dropping extension" + "Failed to encrypt hmac-secret-mc salts, dropping extension" ); return Ok(()); } diff --git a/libwebauthn/src/proto/ctap2/preflight.rs b/libwebauthn/src/proto/ctap2/preflight.rs index 4ee5393e..0c7fb873 100644 --- a/libwebauthn/src/proto/ctap2/preflight.rs +++ b/libwebauthn/src/proto/ctap2/preflight.rs @@ -1,6 +1,6 @@ use serde_bytes::ByteBuf; use std::time::Duration; -use tracing::{debug, info}; +use tracing::{debug, trace}; use super::{Ctap2GetAssertionRequest, Ctap2PublicKeyCredentialDescriptor}; use crate::{ @@ -39,12 +39,16 @@ pub async fn ctap2_preflight_with_appid( rp: &str, appid_exclude: Option<&str>, ) -> Vec { - info!("Credential list BEFORE preflight: {credentials:?}"); + debug!( + cred_count = credentials.len(), + "Credential list before preflight" + ); + trace!(?credentials, "Credential list before preflight"); let mut filtered_list = Vec::new(); for credential in credentials { // Test against the canonical rpId first. if let Some(matched) = preflight_one(channel, credential, client_data_hash, rp).await { - debug!("Pre-flight: Found already known credential under rpId {credential:?}"); + trace!(?credential, "Found already known credential under rpId"); filtered_list.push(matched); continue; } @@ -56,16 +60,21 @@ pub async fn ctap2_preflight_with_appid( if let Some(appid) = appid_exclude { if let Some(matched) = preflight_one(channel, credential, client_data_hash, appid).await { - debug!( - "Pre-flight: Found already known credential under appidExclude {credential:?}" + trace!( + ?credential, + "Found already known credential under appidExclude" ); filtered_list.push(matched); continue; } } - debug!("Pre-flight: Filtering out {credential:?}"); + trace!(?credential, "Filtering out credential"); } - info!("Credential list AFTER preflight: {filtered_list:?}"); + debug!( + cred_count = filtered_list.len(), + "Credential list after preflight" + ); + trace!(?filtered_list, "Credential list after preflight"); filtered_list } @@ -108,7 +117,7 @@ async fn preflight_one( Some(id) } Err(e) => { - debug!("Pre-flight: Not found under {rp:?}: {e:?}"); + trace!({ rp = %rp, error = ?e }, "Credential not found under rp"); None } } diff --git a/libwebauthn/src/proto/ctap2/protocol.rs b/libwebauthn/src/proto/ctap2/protocol.rs index 73e00dfd..db8e7654 100644 --- a/libwebauthn/src/proto/ctap2/protocol.rs +++ b/libwebauthn/src/proto/ctap2/protocol.rs @@ -24,10 +24,9 @@ macro_rules! parse_cbor { match cbor::from_slice::<$type>($data) { Ok(f) => f, Err(e) => { - tracing::error!( - "Failed to parse {} from CBOR-data provided by the device. Parsing error: {:?}", - stringify!($type), - e + tracing::warn!( + { type_name = stringify!($type), error = ?e }, + "Failed to parse device CBOR response" ); return Err(Error::Platform(PlatformError::InvalidDeviceResponse)); } @@ -115,7 +114,7 @@ where error => return Err(Error::Ctap(error)), }; let data = unwrap_field!(cbor_response.data); - trace!("MakeCredential: {:?}", data); + trace!(?data, "MakeCredential response"); let ctap_response = parse_cbor!(Ctap2MakeCredentialResponse, &data); debug!("CTAP2 MakeCredential successful"); trace!(?ctap_response); @@ -136,7 +135,7 @@ where error => return Err(Error::Ctap(error)), }; let data = unwrap_field!(cbor_response.data); - trace!("GetAssertion: {:?}", data); + trace!(?data, "GetAssertion response"); let ctap_response = parse_cbor!(Ctap2GetAssertionResponse, &data); debug!("CTAP2 GetAssertion successful"); trace!(?ctap_response); From 88af1aac18b74cca171e8151c25e35be1284cb1b Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 08/10] refactor(pin): apply the logging policy Stop logging AES key material and ciphertext: log a length instead. Peer public-key and decrypt failures move from error! to warn!, while genuine crypto invariants (HMAC/HKDF/cipher build on fixed inputs) stay at error!. Replace interpolated messages with structured fields. --- libwebauthn/src/pin/mod.rs | 40 ++++++++++++------------- libwebauthn/src/pin/persistent_token.rs | 18 ++++++----- 2 files changed, 30 insertions(+), 28 deletions(-) diff --git a/libwebauthn/src/pin/mod.rs b/libwebauthn/src/pin/mod.rs index 4fae16bd..5a6d18fb 100644 --- a/libwebauthn/src/pin/mod.rs +++ b/libwebauthn/src/pin/mod.rs @@ -187,23 +187,23 @@ where // Parse peerCoseKey as specified for getPublicKey, below, and produce a P-256 point, Y. // If unsuccessful, or if the resulting point is not on the curve, return error. let cose::PublicKey::EcdhEsHkdf256Key(peer_public_key) = peer_public_key else { - error!( + warn!( ?peer_public_key, - "Unsupported peerCoseKey format. Only EcdhEsHkdf256Key is supported." + "Unsupported peerCoseKey format, only EcdhEsHkdf256Key is supported" ); return Err(Error::Ctap(CtapError::Other)); }; // x and y must be exactly 32 bytes (P-256 field size). `cosey` accepts // any length up to 32; validate before converting to `&FieldBytes`. let x: &[u8; 32] = peer_public_key.x.as_bytes().try_into().map_err(|_| { - error!( + warn!( x_len = peer_public_key.x.as_bytes().len(), "Peer public key x coordinate is not 32 bytes" ); Error::Ctap(CtapError::Other) })?; let y: &[u8; 32] = peer_public_key.y.as_bytes().try_into().map_err(|_| { - error!( + warn!( y_len = peer_public_key.y.as_bytes().len(), "Peer public key y coordinate is not 32 bytes" ); @@ -211,7 +211,7 @@ where })?; let encoded_point = EncodedPoint::from_affine_coordinates(x.into(), y.into(), false); let Some(peer_public_key) = P256PublicKey::from_encoded_point(&encoded_point).into() else { - error!("Failed to parse public key."); + warn!("Failed to parse public key"); return Err(Error::Ctap(CtapError::Other)); }; @@ -270,7 +270,7 @@ impl PinUvAuthProtocol for PinUvAuthProtocolOne { // (No padding is performed as the size of demPlaintext is required to be a multiple of the AES block length.) let iv: &[u8] = &[0; 16]; let Ok(enc) = Aes256CbcEncryptor::new_from_slices(key, iv) else { - error!(?key, "Invalid key for AES-256 encryption"); + error!(key_len = key.len(), "Invalid key for AES-256 encryption"); return Err(Error::Ctap(CtapError::Other)); }; Ok(enc.encrypt_padded_vec_mut::(plaintext)) @@ -295,8 +295,8 @@ impl PinUvAuthProtocol for PinUvAuthProtocolOne { // If the size of demCiphertext is not a multiple of the AES block length, return error. // Otherwise return the AES-256-CBC decryption of demCiphertext using an all-zero IV. if !ciphertext.len().is_multiple_of(16) { - error!( - ?ciphertext, + warn!( + len = ciphertext.len(), "Ciphertext length is not a multiple of AES block length" ); return Err(Error::Ctap(CtapError::Other)); @@ -304,11 +304,11 @@ impl PinUvAuthProtocol for PinUvAuthProtocolOne { let iv: &[u8] = &[0; 16]; let Ok(dec) = Aes256CbcDecryptor::new_from_slices(key, iv) else { - error!(?key, "Invalid key for AES-256 decryption"); + error!(key_len = key.len(), "Invalid key for AES-256 decryption"); return Err(Error::Ctap(CtapError::Other)); }; let Ok(plaintext) = dec.decrypt_padded_vec_mut::(ciphertext) else { - error!("Unpad error while decrypting"); + warn!("Unpad error while decrypting"); return Err(Error::Ctap(CtapError::Other)); }; Ok(plaintext) @@ -390,7 +390,7 @@ impl PinUvAuthProtocol for PinUvAuthProtocolTwo { let key = key.get(32..).ok_or_else(|| { error!( key_len = key.len(), - "key shorter than 32 bytes; cannot select AES-key portion" + "Key shorter than 32 bytes, cannot select AES-key portion" ); Error::Ctap(CtapError::Other) })?; @@ -401,7 +401,7 @@ impl PinUvAuthProtocol for PinUvAuthProtocolTwo { // Let ct be the AES-256-CBC encryption of demPlaintext using key and iv. // (No padding is performed as the size of demPlaintext is required to be a multiple of the AES block length.) let Ok(enc) = Aes256CbcEncryptor::new_from_slices(key, &iv) else { - error!(?key, "Invalid key for AES-256 encryption"); + error!(key_len = key.len(), "Invalid key for AES-256 encryption"); return Err(Error::Ctap(CtapError::Other)); }; let ct = enc.encrypt_padded_vec_mut::(plaintext); @@ -417,14 +417,14 @@ impl PinUvAuthProtocol for PinUvAuthProtocolTwo { let key = key.get(32..).ok_or_else(|| { error!( key_len = key.len(), - "key shorter than 32 bytes; cannot select AES-key portion" + "Key shorter than 32 bytes, cannot select AES-key portion" ); Error::Ctap(CtapError::Other) })?; // If demPlaintext is less than 16 bytes in length, return an error if ciphertext.len() < 16 { - error!({ len = ciphertext.len() }, "Invalid length for ciphertext"); + warn!(len = ciphertext.len(), "Invalid length for ciphertext"); return Err(Error::Ctap(CtapError::Other)); }; @@ -433,11 +433,11 @@ impl PinUvAuthProtocol for PinUvAuthProtocolTwo { // Return the AES-256-CBC decryption of ct using key and iv. let Ok(dec) = Aes256CbcDecryptor::new_from_slices(key, iv) else { - error!(?key, "Invalid key for AES-256 decryption"); + error!(key_len = key.len(), "Invalid key for AES-256 decryption"); return Err(Error::Ctap(CtapError::Other)); }; let Ok(plaintext) = dec.decrypt_padded_vec_mut::(ciphertext) else { - error!("Unpad error while decrypting"); + warn!("Unpad error while decrypting"); return Err(Error::Ctap(CtapError::Other)); }; Ok(plaintext) @@ -449,7 +449,7 @@ impl PinUvAuthProtocol for PinUvAuthProtocolTwo { let key = key.get(..32).ok_or_else(|| { error!( key_len = key.len(), - "key shorter than 32 bytes; cannot select HMAC-key portion" + "Key shorter than 32 bytes, cannot select HMAC-key portion" ); Error::Ctap(CtapError::Other) })?; @@ -470,7 +470,7 @@ pub fn pin_hash(pin: &[u8]) -> Vec { pub fn hmac_sha256(key: &[u8], message: &[u8]) -> Result, Error> { let mut hmac = HmacSha256::new_from_slice(key).map_err(|e| { - error!("HMAC key error: {e}"); + error!(?e, "HMAC key error"); Error::Platform(PlatformError::CryptoError(format!("HMAC key error: {e}"))) })?; hmac.update(message); @@ -481,7 +481,7 @@ pub fn hkdf_sha256(salt: Option<&[u8]>, ikm: &[u8], info: &[u8]) -> Result::new(salt, ikm); let mut okm = [0u8; 32]; // fixed L = 32 hk.expand(info, &mut okm).map_err(|e| { - error!("HKDF expand error: {e}"); + error!(?e, "HKDF expand error"); Error::Platform(PlatformError::CryptoError(format!( "HKDF expand error: {e}" ))) @@ -543,7 +543,7 @@ pub(crate) mod internal { ) .await else { - error!("No supported PIN/UV auth protocols found"); + warn!("No supported PIN/UV auth protocols found"); return Err(Error::Ctap(CtapError::Other)); }; diff --git a/libwebauthn/src/pin/persistent_token.rs b/libwebauthn/src/pin/persistent_token.rs index ba6158d5..a9babc2a 100644 --- a/libwebauthn/src/pin/persistent_token.rs +++ b/libwebauthn/src/pin/persistent_token.rs @@ -114,7 +114,7 @@ impl PersistentTokenStore for MemoryPersistentTokenStore { async fn put(&self, id: &PersistentTokenRecordId, record: &PersistentTokenRecord) { debug!(?id, "Storing persistent token record"); - trace!(?record); + trace!(?record, "Storing persistent token record"); self.records.lock().await.insert(id.clone(), record.clone()); } @@ -131,7 +131,7 @@ fn enc_identifier_key(token: &[u8]) -> Result<[u8; 16], Error> { let mut key = [0u8; 16]; hkdf.expand(ENC_IDENTIFIER_HKDF_INFO, &mut key) .map_err(|e| { - error!("HKDF expand error deriving encIdentifier key: {e}"); + error!(?e, "HKDF expand error deriving encIdentifier key"); Error::Platform(PlatformError::CryptoError(format!( "HKDF expand error: {e}" ))) @@ -146,9 +146,9 @@ pub(crate) fn decrypt_enc_identifier( enc_identifier: &[u8], ) -> Result<[u8; 16], Error> { if enc_identifier.len() != 32 { - error!( + warn!( len = enc_identifier.len(), - "encIdentifier is not a 16-byte IV followed by one 16-byte ciphertext block" + "Invalid encIdentifier, expected 16-byte IV followed by one 16-byte ciphertext block" ); return Err(Error::Ctap(CtapError::Other)); } @@ -159,11 +159,11 @@ pub(crate) fn decrypt_enc_identifier( return Err(Error::Ctap(CtapError::Other)); }; let Ok(plaintext) = decryptor.decrypt_padded_vec_mut::(ciphertext) else { - error!("Decrypt error while recovering device identifier"); + warn!("Decrypt error while recovering device identifier"); return Err(Error::Ctap(CtapError::Other)); }; plaintext.try_into().map_err(|_| { - error!("Recovered device identifier was not 16 bytes"); + warn!("Recovered device identifier was not 16 bytes"); Error::Ctap(CtapError::Other) }) } @@ -208,12 +208,14 @@ pub(crate) async fn store_minted_token( pin_uv_auth_protocol: Ctap2PinUvAuthProtocol, ) -> Result { let Some(enc_identifier) = info.enc_identifier.as_ref() else { - warn!("perCredMgmtRO advertised but no encIdentifier returned; cannot persist token"); + warn!( + "Device advertised perCredMgmtRO but returned no encIdentifier, cannot persist token" + ); return Err(Error::Ctap(CtapError::Other)); }; let device_identifier = decrypt_enc_identifier(token, enc_identifier)?; let aaguid: [u8; 16] = info.aaguid[..].try_into().map_err(|_| { - error!(len = info.aaguid.len(), "AAGUID was not 16 bytes"); + warn!(len = info.aaguid.len(), "AAGUID was not 16 bytes"); Error::Ctap(CtapError::Other) })?; reap_superseded_records(store, &device_identifier).await; From c540f999cabdf658d7022112925efea1eb22df7b Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 09/10] refactor(webauthn): apply the logging policy Malformed Client PIN responses and device faults move from error! to warn!, keeping error! for in-memory invariants. Reduce the pinUvAuthToken and HMAC-secret outputs to lengths, and replace interpolated messages with structured fields. --- libwebauthn/src/fido.rs | 8 ++++-- libwebauthn/src/lib.rs | 6 ++--- libwebauthn/src/management/bio_enrollment.rs | 4 +-- libwebauthn/src/ops/u2f.rs | 13 ++++++---- libwebauthn/src/ops/webauthn/get_assertion.rs | 9 ++++--- libwebauthn/src/ops/webauthn/idl/mod.rs | 4 +-- libwebauthn/src/ops/webauthn/large_blob.rs | 15 ++++------- libwebauthn/src/transport/channel.rs | 2 +- libwebauthn/src/ui.rs | 2 +- libwebauthn/src/webauthn.rs | 10 ++++---- libwebauthn/src/webauthn/pin_uv_auth_token.rs | 25 +++++++++---------- 11 files changed, 51 insertions(+), 47 deletions(-) diff --git a/libwebauthn/src/fido.rs b/libwebauthn/src/fido.rs index bbb5c3c8..b89d5fa7 100644 --- a/libwebauthn/src/fido.rs +++ b/libwebauthn/src/fido.rs @@ -129,7 +129,10 @@ where res.push(self.flags.bits()); res.write_u32::(self.signature_count) .map_err(|e| { - error!("Failed to create AuthenticatorData output vec at signature_count: {e:?}"); + error!( + ?e, + "Failed to create AuthenticatorData output vec at signature_count" + ); Error::Platform(PlatformError::InvalidDeviceResponse) })?; @@ -144,7 +147,8 @@ where res.write_u16::(att_data.credential_id.len() as u16) .map_err(|e| { error!( - "Failed to create AuthenticatorData output vec at attested_credential.credential_id: {e:?}" + ?e, + "Failed to create AuthenticatorData output vec at attested_credential.credential_id" ); Error::Platform(PlatformError::InvalidDeviceResponse) })?; diff --git a/libwebauthn/src/lib.rs b/libwebauthn/src/lib.rs index 6b64e279..1ac77707 100644 --- a/libwebauthn/src/lib.rs +++ b/libwebauthn/src/lib.rs @@ -109,9 +109,9 @@ macro_rules! unwrap_field { if let Some(f) = $field { f } else { - tracing::error!( - "Device response did not contain expected field: {}", - stringify!($field) + tracing::warn!( + field = stringify!($field), + "Device response did not contain expected field" ); return Err(Error::Platform(PlatformError::InvalidDeviceResponse)); } diff --git a/libwebauthn/src/management/bio_enrollment.rs b/libwebauthn/src/management/bio_enrollment.rs index 8df5866f..ca7c8a59 100644 --- a/libwebauthn/src/management/bio_enrollment.rs +++ b/libwebauthn/src/management/bio_enrollment.rs @@ -84,7 +84,7 @@ where match resp.modality { Some(modality) => Ok(modality), None => { - warn!("Channel did not return modality."); + warn!("Channel did not return modality"); Err(Error::Ctap(CtapError::Other)) } } @@ -98,7 +98,7 @@ where // No UV needed let resp = self.ctap2_bio_enrollment(&req, timeout).await?; let Some(fingerprint_kind) = resp.fingerprint_kind else { - warn!("Channel did not return fingerprint_kind in sensor info."); + warn!("Channel did not return fingerprint_kind in sensor info"); return Err(Error::Ctap(CtapError::Other)); }; Ok(Ctap2BioEnrollmentFingerprintSensorInfo { diff --git a/libwebauthn/src/ops/u2f.rs b/libwebauthn/src/ops/u2f.rs index 62e51cae..6be0643b 100644 --- a/libwebauthn/src/ops/u2f.rs +++ b/libwebauthn/src/ops/u2f.rs @@ -3,7 +3,7 @@ use std::time::Duration; use cosey as cose; use serde_bytes::ByteBuf; use sha2::{Digest, Sha256}; -use tracing::{error, trace}; +use tracing::{error, trace, warn}; use x509_parser::nom::AsBytes; use super::webauthn::MakeCredentialRequest; @@ -57,17 +57,20 @@ impl UpgradableResponse for Regis // from ANS X9.62 / Sec-1 v2 uncompressed curve point representation [SEC1V2] // to COSE_Key representation ([RFC8152] Section 7). let Ok(encoded_point) = p256::EncodedPoint::from_bytes(&self.public_key) else { - error!(?self.public_key, "Failed to parse public key as SEC-1 v2 encoded point"); + warn!( + public_key_len = self.public_key.len(), + "Failed to parse public key as SEC-1 v2 encoded point" + ); return Err(Error::Ctap(CtapError::Other)); }; let x_bytes = encoded_point.x().ok_or_else(|| { - error!("Public key is the identity point"); + warn!("Public key is the identity point"); Error::Platform(PlatformError::CryptoError( "public key is the identity point".into(), )) })?; let y_bytes = encoded_point.y().ok_or_else(|| { - error!("Public key is identity or compressed"); + warn!("Public key is identity or compressed"); Error::Platform(PlatformError::CryptoError( "public key is identity or compressed".into(), )) @@ -245,7 +248,7 @@ impl UpgradableResponse for SignResponse { .as_slice() .into(); - trace!(?upgraded_response); + trace!(?upgraded_response, "Upgraded U2F sign response"); Ok(upgraded_response) } } diff --git a/libwebauthn/src/ops/webauthn/get_assertion.rs b/libwebauthn/src/ops/webauthn/get_assertion.rs index e84af098..2cf902a1 100644 --- a/libwebauthn/src/ops/webauthn/get_assertion.rs +++ b/libwebauthn/src/ops/webauthn/get_assertion.rs @@ -3,7 +3,7 @@ use std::{collections::HashMap, time::Duration}; use async_trait::async_trait; use serde::{Deserialize, Serialize}; use sha2::{Digest, Sha256}; -use tracing::{debug, error, trace}; +use tracing::{debug, trace, warn}; use crate::{ fido::AuthenticatorData, @@ -417,7 +417,7 @@ impl Ctap2HMACGetSecretOutput { let output = match uv_proto.decrypt(shared_secret, &self.encrypted_output) { Ok(o) => o, Err(e) => { - error!("Failed to decrypt HMAC Secret output with the shared secret: {e:?}. Skipping HMAC extension"); + warn!(?e, "Failed to decrypt HMAC Secret output with the shared secret, skipping HMAC extension"); return None; } }; @@ -431,7 +431,10 @@ impl Ctap2HMACGetSecretOutput { output2.copy_from_slice(o2); res.output2 = Some(output2); } else { - error!("Failed to split HMAC Secret outputs. Unexpected output length: {}. Skipping HMAC extension", output.len()); + warn!( + output_len = output.len(), + "Failed to split HMAC Secret outputs, skipping HMAC extension" + ); return None; } diff --git a/libwebauthn/src/ops/webauthn/idl/mod.rs b/libwebauthn/src/ops/webauthn/idl/mod.rs index b9625e63..0c339aae 100644 --- a/libwebauthn/src/ops/webauthn/idl/mod.rs +++ b/libwebauthn/src/ops/webauthn/idl/mod.rs @@ -84,7 +84,7 @@ pub(crate) async fn rp_id_authorised( RelatedOrigins::Enabled { source, max_labels } => { match source.allowed_origins(rp_id).await { Err(err) => { - debug!(rp_id = %rp_id.0, %err, "Related-origins resolution failed"); + debug!({ rp_id = %rp_id.0, %err }, "Related-origins resolution failed"); false } Ok(origins) => match validate_related_origins( @@ -95,7 +95,7 @@ pub(crate) async fn rp_id_authorised( ) { Ok(()) => true, Err(err) => { - debug!(rp_id = %rp_id.0, %err, "Related-origins match failed"); + debug!({ rp_id = %rp_id.0, %err }, "Related-origins match failed"); false } }, diff --git a/libwebauthn/src/ops/webauthn/large_blob.rs b/libwebauthn/src/ops/webauthn/large_blob.rs index 14787bf5..cb71402f 100644 --- a/libwebauthn/src/ops/webauthn/large_blob.rs +++ b/libwebauthn/src/ops/webauthn/large_blob.rs @@ -110,9 +110,7 @@ async fn fetch_serialized_array( let chunk_len = chunk.len(); out.extend_from_slice(&chunk); trace!( - offset, - chunk_len, - total = out.len(), + { offset, chunk_len, total = out.len() }, "authenticatorLargeBlobs(get) chunk" ); if chunk_len < max_fragment as usize { @@ -121,8 +119,8 @@ async fn fetch_serialized_array( } if out.len() > LARGE_BLOB_MAX_ARRAY_BYTES { warn!( - total = out.len(), - "largeBlobArray exceeded {LARGE_BLOB_MAX_ARRAY_BYTES}, aborting" + { total = out.len(), cap = LARGE_BLOB_MAX_ARRAY_BYTES }, + "largeBlobArray exceeded platform cap, aborting" ); return Err(LargeBlobError::Corrupted( "serialized array exceeds platform cap".into(), @@ -154,8 +152,7 @@ impl LargeBlobMapEntry { } if self.orig_size > LARGE_BLOB_MAX_ORIG_SIZE { warn!( - orig_size = self.orig_size, - cap = LARGE_BLOB_MAX_ORIG_SIZE, + { orig_size = self.orig_size, cap = LARGE_BLOB_MAX_ORIG_SIZE }, "largeBlob entry origSize exceeds platform cap; skipping" ); return Ok(None); @@ -627,9 +624,7 @@ async fn upload_serialized_array( Ctap2LargeBlobsRequest::new_set_continuation(chunk.to_vec(), offset, chunk_auth) }; trace!( - offset, - chunk_len = chunk.len(), - total, + { offset, chunk_len = chunk.len(), total }, "authenticatorLargeBlobs(set) chunk" ); channel diff --git a/libwebauthn/src/transport/channel.rs b/libwebauthn/src/transport/channel.rs index 2db66c32..ebd32ad4 100644 --- a/libwebauthn/src/transport/channel.rs +++ b/libwebauthn/src/transport/channel.rs @@ -55,7 +55,7 @@ pub trait Channel: Send + Sync + Display + Ctap2AuthTokenStore { match self.get_ux_update_sender().send(state) { Ok(_) => (), Err(_) => { - warn!("No receivers for UX update."); + warn!("No receivers for UX update"); } }; } diff --git a/libwebauthn/src/ui.rs b/libwebauthn/src/ui.rs index 235f2809..1348c680 100644 --- a/libwebauthn/src/ui.rs +++ b/libwebauthn/src/ui.rs @@ -120,7 +120,7 @@ impl<'conn> NotificationPortalUI<'conn> { self.dbus_proxy.match_signal( move |h: NotificationAction, _: &Connection, _: &Message| { - debug!("Received signal: {:?}", h); + debug!(?h, "Received signal"); match h.action.as_str() { _ => callback(CancellationResponse::UserCancel), }; diff --git a/libwebauthn/src/webauthn.rs b/libwebauthn/src/webauthn.rs index 75f18a03..44f5f36c 100644 --- a/libwebauthn/src/webauthn.rs +++ b/libwebauthn/src/webauthn.rs @@ -17,7 +17,7 @@ pub mod error; pub mod pin_uv_auth_token; use async_trait::async_trait; -use tracing::{debug, error, info, instrument, trace, warn}; +use tracing::{debug, info, instrument, trace, warn}; use crate::fido::FidoProtocol; use crate::ops::u2f::{RegisterRequest, SignRequest, UpgradableResponse}; @@ -341,7 +341,7 @@ async fn get_assertion_fido2( let count = response.credentials_count.unwrap_or(1); let mut ctap_responses = vec![response]; for i in 1..count { - debug!({ i }, "Fetching additional credential"); + debug!(i, "Fetching additional credential"); // GetNextAssertion doesn't use PinUVAuthToken, so we don't need to check uv_auth_used here ctap_responses.push(channel.ctap2_get_next_assertion(op.timeout).await?); } @@ -585,9 +585,9 @@ async fn get_assertion_u2f( debug!("No credentials found, trying with the next."); } Err(err) => { - error!( + warn!( ?err, - "Unexpected error whilst trying each credential in allowList." + "Unexpected error whilst trying each credential in allowList" ); return Err(err); } @@ -622,7 +622,7 @@ async fn negotiate_protocol( if fido_protocol == FidoProtocol::U2F { warn!("Negotiated protocol downgrade from FIDO2 to FIDO U2F"); } else { - debug!("Selected protocol: {:?}", fido_protocol); + debug!(?fido_protocol, "Selected protocol"); } Ok(fido_protocol) } diff --git a/libwebauthn/src/webauthn/pin_uv_auth_token.rs b/libwebauthn/src/webauthn/pin_uv_auth_token.rs index 4f63fbf0..b1f9266b 100644 --- a/libwebauthn/src/webauthn/pin_uv_auth_token.rs +++ b/libwebauthn/src/webauthn/pin_uv_auth_token.rs @@ -1,7 +1,7 @@ use std::sync::Arc; use std::time::Duration; -use tracing::{debug, error, info, instrument, warn}; +use tracing::{debug, info, instrument, warn}; use cosey::PublicKey; @@ -143,11 +143,11 @@ where // If it is not discouraged and either RP or device requires it. let uv = !rp_uv_discouraged && (rp_uv_preferred || dev_uv_protected); - debug!(%rp_uv_preferred, %rp_uv_discouraged, %dev_uv_protected, %uv, %needs_shared_secret, %can_establish_shared_secret, "Checking if user verification is required"); + debug!({ %rp_uv_preferred, %rp_uv_discouraged, %dev_uv_protected, %uv, %needs_shared_secret, %can_establish_shared_secret }, "Checking if user verification is required"); // Enforce required UV even on the shared-secret path. A shared-secret-only result performs no UV. if user_verification.is_required() && !dev_uv_protected { - error!( - "Request requires user verification, but device user verification is not available. Try letting the user set a PIN." + debug!( + "Request requires user verification, but device user verification is not available. Trying to set a PIN" ); // Lets try setting a PIN. Either we succeed in some fashion, or we return the resulting error here instead. try_to_set_pin( @@ -230,7 +230,7 @@ where ) .await else { - error!("No supported PIN/UV auth protocols found"); + warn!("No supported PIN/UV auth protocols found"); return Err(Error::Ctap(CtapError::Other)); }; @@ -287,7 +287,7 @@ where &uv_proto.encrypt( &shared_secret, &pin_hash(&pin.ok_or_else(|| { - error!("PIN expected but not available"); + warn!("PIN expected but not available"); Error::Ctap(CtapError::PINRequired) })?), )?, @@ -300,7 +300,7 @@ where &uv_proto.encrypt( &shared_secret, &pin_hash(&pin.ok_or_else(|| { - error!("PIN expected but not available"); + warn!("PIN expected but not available"); Error::Ctap(CtapError::PINRequired) })?), )?, @@ -387,11 +387,11 @@ where | Ctap2UserVerificationOperation::GetPinToken => { { let token_response = token_response.ok_or_else(|| { - error!("Expected token response but got None"); + warn!("Expected token response but got None"); Error::Ctap(CtapError::Other) })?; let Some(encrypted_pin_uv_auth_token) = token_response.pin_uv_auth_token else { - error!("Client PIN response did not include a PIN UV auth token"); + warn!("Client PIN response did not include a PIN UV auth token"); return Err(Error::Ctap(CtapError::Other)); }; @@ -400,9 +400,8 @@ where // Reject a spec-invalid token length before it is used as a key downstream. if !pin_uv_auth_token_len_valid(uv_proto.version(), uv_auth_token.len()) { - error!( - protocol = ?uv_proto.version(), - token_len = uv_auth_token.len(), + warn!( + { protocol = ?uv_proto.version(), token_len = uv_auth_token.len() }, "Decrypted pinUvAuthToken has an invalid length" ); return Err(Error::Ctap(CtapError::Other)); @@ -467,7 +466,7 @@ where .ctap2_client_pin(&client_pin_request, timeout) .await?; let Some(public_key) = client_pin_response.key_agreement else { - error!("Missing public key from Client PIN response"); + warn!("Missing public key from Client PIN response"); return Err(Error::Ctap(CtapError::Other)); }; pin_proto.encapsulate(&public_key) From 67baeb16854d88644640d3ec3b20c90cff13929f Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 10/10] refactor(tests): static log messages in the virtual authenticator Replace interpolated messages with structured fields so the virt test harness satisfies the logging lints. --- libwebauthn-tests/src/virt/device.rs | 2 +- libwebauthn-tests/src/virt/pipe.rs | 9 ++++----- 2 files changed, 5 insertions(+), 6 deletions(-) diff --git a/libwebauthn-tests/src/virt/device.rs b/libwebauthn-tests/src/virt/device.rs index c4214e1d..1c83e701 100644 --- a/libwebauthn-tests/src/virt/device.rs +++ b/libwebauthn-tests/src/virt/device.rs @@ -170,7 +170,7 @@ impl HidDevice for Device<'_> { if let Some(response) = self.0.borrow_mut().pop() { return if buffer.len() >= response.len() { - info!("received response: {} bytes", response.len()); + info!(len = response.len(), "Received response"); buffer[..response.len()].copy_from_slice(&response); Ok(&buffer[..response.len()]) } else { diff --git a/libwebauthn-tests/src/virt/pipe.rs b/libwebauthn-tests/src/virt/pipe.rs index 8e0082e0..961ee40e 100644 --- a/libwebauthn-tests/src/virt/pipe.rs +++ b/libwebauthn-tests/src/virt/pipe.rs @@ -401,15 +401,14 @@ impl<'a, const N: usize> Pipe<'a, N> { Ok(message) => { if message.len() > self.buffer.len() { error!( - "Message is longer than buffer ({} > {})", - message.len(), - self.buffer.len(), + { message_len = message.len(), buffer_len = self.buffer.len() }, + "Message is longer than buffer" ); self.start_sending_error(request, CtapError::InvalidLength); } else { info!( - "Got {} bytes response from authenticator, starting send", - message.len() + len = message.len(), + "Got response from authenticator, starting send" ); let response = Response::from_request_and_size(request, message.len()); self.buffer[..message.len()].copy_from_slice(message);