From 02a66e0cc3e22b62fce26fb793a2b06b3c1d7b3c Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 17:26:49 +0100 Subject: [PATCH 01/12] 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 64ac30746cc20cf8020022cc6874563715df5820 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:19:15 +0100 Subject: [PATCH 02/12] 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 a67f654147be91a47f8545dbf40ac342f799f2eb Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 03/12] 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 | 14 ++-- 9 files changed, 77 insertions(+), 89 deletions(-) diff --git a/libwebauthn/src/transport/cable/advertisement.rs b/libwebauthn/src/transport/cable/advertisement.rs index 25e0a30b..62eb846d 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 5bc1cacb..ec2a5e8a 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::{ @@ -149,12 +149,12 @@ impl Channel for CableChannel { _request: &ApduRequest, _timeout: Duration, ) -> Result<(), CableError> { - error!("APDU send not supported in caBLE transport"); + warn!("APDU send not supported in caBLE transport"); Err(CableError::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(CableError::TransportUnavailable) } @@ -170,11 +170,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(CableError::TransportUnavailable) } Err(elapsed) => { - error!({ %elapsed, ?timeout }, "CBOR request send timeout"); + warn!({ %elapsed, ?timeout }, "CBOR request send timeout"); Err(CableError::Timeout) } } @@ -189,7 +189,7 @@ impl Channel for CableChannel { Ok(Some(response)) => Ok(response), Ok(None) => Err(CableError::TransportUnavailable), Err(elapsed) => { - error!({ %elapsed, ?timeout }, "CBOR response recv timeout"); + warn!({ %elapsed, ?timeout }, "CBOR response recv timeout"); Err(CableError::Timeout) } } diff --git a/libwebauthn/src/transport/cable/connection_stages.rs b/libwebauthn/src/transport/cable/connection_stages.rs index 740c64bc..b5dc0c20 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}; @@ -252,7 +252,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"); } } @@ -289,7 +289,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)) @@ -391,7 +391,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"); CableError::InvalidFraming }) } diff --git a/libwebauthn/src/transport/cable/crypto.rs b/libwebauthn/src/transport/cable/crypto.rs index b0b721f8..c90d962a 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::cable::error::CableError; @@ -31,17 +31,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; } @@ -51,8 +51,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; } @@ -62,7 +62,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 a2ac9c96..39fcd398 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::cable::error::CableError; @@ -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) => CableError::from(io), _ => CableError::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(CableError::ConnectionFailed); } Some(Err(Error::Io(e))) => { - error!(?e, "Failed to read WebSocket message"); + warn!(?e, "Failed to read WebSocket message"); return Err(CableError::from(e)); } Some(Err(e)) => { - error!(?e, "Failed to read WebSocket message"); + warn!(?e, "Failed to read WebSocket message"); return Err(CableError::ConnectionFailed); } } diff --git a/libwebauthn/src/transport/cable/known_devices.rs b/libwebauthn/src/transport/cable/known_devices.rs index 01d42cdc..b13b0c1f 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()); } @@ -196,7 +196,7 @@ impl<'d> Device<'d, Cable, CableChannel> for CableKnownDevice { &'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 f9459e93..956b712a 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::cable::error::CableError; @@ -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"); CableError::from(e) })?; @@ -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<(), CableError> { self.stream.write_all(message).await.map_err(|e| { - error!(?e, "Failed to write L2CAP message"); + warn!(?e, "Failed to write L2CAP message"); CableError::from(e) })?; self.stream.write_all(&EOM).await.map_err(|e| { - error!(?e, "Failed to write L2CAP EOM"); + warn!(?e, "Failed to write L2CAP EOM"); CableError::from(e) })?; 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(CableError::from(e)); } }; @@ -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(CableError::ConnectionLost); } self.read_buf @@ -154,7 +154,7 @@ fn bdaddr_to_bluer( addr_type: Option, ) -> Result<(bluer::Address, bluer::AddressType), CableError> { 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"); CableError::InvalidEndpoint })?; let addr_type = match addr_type { diff --git a/libwebauthn/src/transport/cable/protocol.rs b/libwebauthn/src/transport/cable/protocol.rs index 73f68bb8..2b464acc 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(CableError::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(CableError::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(CableError::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(CableError::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(CableError::ConnectionFailed); } @@ -280,20 +271,23 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), C 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(CableError::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<(), C 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<(), C 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<(), C 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(CableError::ConnectionFailed); } } @@ -350,7 +344,7 @@ pub(crate) async fn connection(mut input: TunnelConnectionInput) -> Result<(), C ) .await { - error!(?e, "Fatal error sending CBOR request"); + warn!(?e, "Fatal error sending CBOR request"); return Err(e); } } @@ -370,13 +364,13 @@ async fn connection_send( let cbor_request = request.raw_long().map_err(CableError::from)?; if cbor_request.len() > MAX_CBOR_SIZE { - error!( + warn!( cbor_request_len = cbor_request.len(), "CBOR request too large" ); return Err(CableError::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; @@ -419,7 +413,7 @@ fn strip_frame_padding(mut decrypted_frame: Vec) -> Result, CableErr 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(CableError::InvalidFraming); } }; @@ -427,9 +421,9 @@ fn strip_frame_padding(mut decrypted_frame: Vec) -> Result, CableErr .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" ); CableError::InvalidFraming })?; @@ -452,15 +446,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(CableError::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" ); @@ -476,7 +469,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(CableError::InvalidFraming); } }; @@ -484,7 +477,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(CableError::InvalidFraming); } }; @@ -499,7 +492,7 @@ async fn connection_recv_update(message: &[u8]) -> Result = 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(CableError::InvalidFraming); } }; @@ -566,7 +559,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 { @@ -667,7 +660,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(CableError::InvalidKey); }; @@ -684,8 +677,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(CableError::InvalidSignature); } diff --git a/libwebauthn/src/transport/cable/tunnel.rs b/libwebauthn/src/transport/cable/tunnel.rs index 528bcc66..7c158514 100644 --- a/libwebauthn/src/transport/cable/tunnel.rs +++ b/libwebauthn/src/transport/cable/tunnel.rs @@ -5,7 +5,7 @@ use tokio_tungstenite::tungstenite::handshake::client::Request; use tokio_tungstenite::tungstenite::http::{header::LOCATION, StatusCode}; use tokio_tungstenite::tungstenite::Error as TungsteniteError; use tokio_tungstenite::{connect_async, MaybeTlsStream, WebSocketStream}; -use tracing::{debug, error, trace}; +use tracing::{debug, trace, warn}; use tungstenite::client::IntoClientRequest; use url::Url; @@ -137,13 +137,13 @@ pub(crate) async fn connect( for _ in 0..=MAX_TUNNEL_REDIRECTS { debug!(?connect_url, "Connecting to tunnel server"); let request = build_tunnel_request(&connect_url, connection_type)?; - trace!(?request); + trace!(?request, "Tunnel server request"); let error = match connect_async(request).await { Ok((ws_stream, response)) => { 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(CableError::ConnectionFailed); } debug!("Tunnel server returned success"); @@ -155,7 +155,7 @@ pub(crate) async fn connect( let response = match error { TungsteniteError::Http(response) => response, error => { - error!(?error, "Failed to connect to tunnel server"); + warn!(?error, "Failed to connect to tunnel server"); return Err(CableError::from(error)); } }; @@ -167,7 +167,7 @@ pub(crate) async fn connect( .get(LOCATION) .and_then(|value| value.to_str().ok()) else { - error!(?status, "Tunnel redirect missing a usable Location header"); + warn!(?status, "Tunnel redirect missing a usable Location header"); return Err(CableError::ConnectionFailed); }; connect_url = resolve_redirect_target(&connect_url, location)?; @@ -175,11 +175,11 @@ pub(crate) async fn connect( continue; } - error!(?status, "Tunnel server rejected the connection"); + warn!(?status, "Tunnel server rejected the connection"); return Err(tunnel_status_error(status)); } - error!("Exceeded the maximum number of tunnel redirects"); + warn!("Exceeded the maximum number of tunnel redirects"); Err(CableTunnelError::TooManyRedirects.into()) } From 9f0481f62f4eca9eee9ab86005ad2d7ef71aac85 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 04/12] 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 10925441..9bb99bf1 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}; @@ -163,7 +163,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(_) @@ -174,7 +174,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(_) @@ -203,10 +203,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(HidError::InvalidInit); } @@ -215,7 +212,7 @@ impl<'d> HidChannel<'d> { .get(..INIT_NONCE_LEN) .ok_or(HidError::InvalidInit)?; if payload_nonce != nonce.as_slice() { - warn!("INIT nonce mismatch. Terminating."); + warn!("INIT nonce mismatch"); return Err(HidError::InvalidInit); } @@ -443,7 +440,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).map_err(HidError::FrameParse)? @@ -512,7 +509,7 @@ impl Channel for HidChannel<'_> { _timeout: std::time::Duration, ) -> Result<(), HidError> { let cid = self.init.cid; - debug!({ cid }, "Sending APDU request"); + debug!(cid, "Sending APDU request"); trace!(?request); let apdu_raw = request.raw_long().map_err(HidError::PacketEncode)?; self.hid_send(&HidMessage::new(cid, HidCommand::Msg, &apdu_raw)) @@ -535,7 +532,7 @@ impl Channel for HidChannel<'_> { _timeout: Duration, ) -> Result<(), HidError> { let cid = self.init.cid; - debug!({ cid }, "Sending CBOR request"); + debug!(cid, "Sending CBOR request"); trace!(?request); self.hid_send(&HidMessage::new( cid, @@ -550,10 +547,7 @@ impl Channel for HidChannel<'_> { let hid_response = self.hid_recv(timeout).await?; let cbor_response = CborResponse::try_from(&hid_response.payload).map_err(HidError::ResponseDecode)?; - 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 add60b6a..2c9bb58f 100644 --- a/libwebauthn/src/transport/hid/device.rs +++ b/libwebauthn/src/transport/hid/device.rs @@ -80,7 +80,7 @@ pub async fn list_devices() -> Result, HidError> { .filter(|device| device.usage() == 0x0001) .map(|device| device.into()) .collect(); - debug!({ count = devices.len() }, "Listing available HID devices"); + debug!(count = devices.len(), "Listing available HID devices"); trace!(?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 be0102de9ecf47a5afc85ca8aa3f143c72c938bb Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 05/12] 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 24ae6983..b48f692f 100644 --- a/libwebauthn/src/transport/ble/btleplug/pairing.rs +++ b/libwebauthn/src/transport/ble/btleplug/pairing.rs @@ -29,7 +29,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 { @@ -37,11 +37,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 } } @@ -60,7 +60,7 @@ fn bonded_or_refused(state: BondingState) -> Result<(), Error> { ?state, "BLE FIDO authenticator link is not confirmed 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 3befa876..c53828b9 100644 --- a/libwebauthn/src/transport/ble/channel.rs +++ b/libwebauthn/src/transport/ble/channel.rs @@ -105,8 +105,8 @@ impl<'a> Channel for BleChannel<'a> { request: &ApduRequest, _timeout: Duration, ) -> Result<(), BleError> { - 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()?; let request_frame = BleFrame::new(BleCommand::Msg, &request_apdu_packet); @@ -128,7 +128,7 @@ impl<'a> Channel for BleChannel<'a> { let response_apdu: ApduResponse = response_apdu_packet.try_into()?; debug!("Received APDU response"); - trace!(?response_apdu); + trace!(?response_apdu, "Received APDU response"); Ok(response_apdu) } @@ -139,7 +139,7 @@ impl<'a> Channel for BleChannel<'a> { _timeout: std::time::Duration, ) -> Result<(), BleError> { debug!("Sending CBOR request"); - trace!(?request); + trace!(?request, "Sending CBOR request"); let cbor_request = request.raw_long()?; let request_frame = BleFrame::new(BleCommand::Msg, &cbor_request); @@ -160,7 +160,7 @@ impl<'a> Channel for BleChannel<'a> { let cbor_response: CborResponse = cbor_response_packet.try_into()?; 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 e37e82b2..95872b91 100644 --- a/libwebauthn/src/transport/ble/device.rs +++ b/libwebauthn/src/transport/ble/device.rs @@ -28,7 +28,7 @@ pub async fn list_devices() -> Result, BleError> { .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 120ba8735381895eb3c7d34da64db99513b5e14b Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:58:59 +0100 Subject: [PATCH 06/12] 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 | 8 +++--- libwebauthn/src/transport/nfc/device.rs | 2 +- libwebauthn/src/transport/nfc/libnfc/mod.rs | 16 +++++------ libwebauthn/src/transport/nfc/pcsc/mod.rs | 4 +-- 5 files changed, 31 insertions(+), 31 deletions(-) diff --git a/libwebauthn/src/proto/ctap1/protocol.rs b/libwebauthn/src/proto/ctap1/protocol.rs index ee621d7d..b02c3679 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::{ @@ -53,7 +53,7 @@ where .await .map_err(WebAuthnError::Transport)?; 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) } @@ -62,25 +62,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(WebAuthnError::Ctap(CtapError::CredentialExcluded)); } Err(WebAuthnError::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"); } }; } @@ -89,13 +89,13 @@ 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(WebAuthnError::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) } @@ -104,21 +104,21 @@ where &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(WebAuthnError::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) } } @@ -147,7 +147,7 @@ async fn send_apdu_request_wait_uv( CtapError::UserPresenceRequired => (), // Sleep some more. _ => return Err(WebAuthnError::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 3f88ab71..6ed2d131 100644 --- a/libwebauthn/src/transport/nfc/channel.rs +++ b/libwebauthn/src/transport/nfc/channel.rs @@ -208,7 +208,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() }) } @@ -251,7 +251,7 @@ where _timeout: Duration, ) -> Result<(), NfcError> { let resp = self.handle_raw(self.ctx, request)?; - trace!("apdu_send {:?}", resp); + trace!(?resp, "Raw APDU response"); let apdu_response = ApduResponse::try_from(&resp).map_err(NfcError::ResponseDecode)?; self.apdu_response = Some(apdu_response); @@ -277,12 +277,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 f5622a0d..cf3cfb89 100644 --- a/libwebauthn/src/transport/nfc/device.rs +++ b/libwebauthn/src/transport/nfc/device.rs @@ -77,7 +77,7 @@ impl NfcDevice { &self, settings: ChannelSettings, ) -> Result, WebAuthnError> { - 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 832ef8ef..46046e2a 100644 --- a/libwebauthn/src/transport/nfc/libnfc/mod.rs +++ b/libwebauthn/src/transport/nfc/libnfc/mod.rs @@ -10,7 +10,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); @@ -45,11 +45,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); @@ -92,7 +92,7 @@ impl Channel { } } Err(err) => { - println!("Error: {}", err); + warn!(%err, "Failed to select passive target"); Err(err) } } @@ -115,7 +115,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 { @@ -125,7 +125,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) { @@ -151,7 +151,7 @@ where ) -> Result { let timeout = nfc1::Timeout::Duration(TIMEOUT); let len = response.len(); - trace!("TX: {:?}", command); + trace!(?command, "Transmitting APDU"); let rapdu = self .device .lock() @@ -159,7 +159,7 @@ where .initiator_transceive_bytes(command, len, timeout) .map_err(NfcError::LibNfc)?; - trace!("RX: {:?}", rapdu); + trace!(?rapdu, "Received APDU"); if response.len() < rapdu.len() { return Err(NfcError::BufferOverflow(rapdu.len())); diff --git a/libwebauthn/src/transport/nfc/pcsc/mod.rs b/libwebauthn/src/transport/nfc/pcsc/mod.rs index b050d390..61b031e7 100644 --- a/libwebauthn/src/transport/nfc/pcsc/mod.rs +++ b/libwebauthn/src/transport/nfc/pcsc/mod.rs @@ -140,12 +140,12 @@ where command: &[u8], response: &mut [u8], ) -> Result { - trace!("TX: {:?}", command); + trace!(?command, "Transmitting APDU"); let card = self.card.lock().map_err(|_| NfcError::MutexPoisoned)?; let rapdu = card.transmit(command, response).map_err(NfcError::Pcsc)?; - trace!("RX: {:?}", rapdu); + trace!(?rapdu, "Received APDU"); Ok(rapdu.len()) } } From 4c0783ca081ef2202312569b0d31c8871275ef1b Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 07/12] 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/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 | 27 ++++++++++++------- libwebauthn/src/proto/ctap2/protocol.rs | 11 ++++---- 6 files changed, 33 insertions(+), 26 deletions(-) diff --git a/libwebauthn/src/proto/ctap2/cose.rs b/libwebauthn/src/proto/ctap2/cose.rs index f86c5605..43282f38 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"); PlatformError::InvalidDeviceResponse })?; match value { @@ -176,7 +176,7 @@ pub fn to_spki(bytes: &[u8]) -> Result>, PlatformError> { fn require_kty(map: &CoseMap, expected: i128) -> Result<(), PlatformError> { 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(PlatformError::InvalidDeviceResponse); } Ok(()) @@ -185,7 +185,7 @@ fn require_kty(map: &CoseMap, expected: i128) -> Result<(), PlatformError> { fn require_crv(map: &CoseMap, expected: i128) -> Result<(), PlatformError> { 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(PlatformError::InvalidDeviceResponse); } Ok(()) @@ -194,8 +194,7 @@ fn require_crv(map: &CoseMap, expected: i128) -> Result<(), PlatformError> { fn p256_spki(x: &[u8], y: &[u8]) -> Result, PlatformError> { 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(PlatformError::InvalidDeviceResponse); diff --git a/libwebauthn/src/proto/ctap2/model/get_assertion.rs b/libwebauthn/src/proto/ctap2/model/get_assertion.rs index 1da4ee06..e087502a 100644 --- a/libwebauthn/src/proto/ctap2/model/get_assertion.rs +++ b/libwebauthn/src/proto/ctap2/model/get_assertion.rs @@ -335,7 +335,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 1c4aeff0..9292298e 100644 --- a/libwebauthn/src/proto/ctap2/model/get_info.rs +++ b/libwebauthn/src/proto/ctap2/model/get_info.rs @@ -252,7 +252,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"); @@ -290,11 +290,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 ce07de30..32eccd64 100644 --- a/libwebauthn/src/proto/ctap2/model/make_credential.rs +++ b/libwebauthn/src/proto/ctap2/model/make_credential.rs @@ -151,7 +151,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. @@ -342,7 +342,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 c8d62bda..006be7f6 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::{ @@ -40,12 +40,16 @@ pub async fn ctap2_preflight_with_appid( rp: &str, appid_exclude: Option<&str>, ) -> Result, WebAuthnError> { - 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; } @@ -58,16 +62,21 @@ pub async fn ctap2_preflight_with_appid( 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"); Ok(filtered_list) } @@ -111,12 +120,12 @@ async fn preflight_one( } // Only CTAP2_ERR_NO_CREDENTIALS proves the credential is absent. Err(WebAuthnError::Ctap(CtapError::NoCredentials)) => { - debug!("Pre-flight: Not found under {rp:?}"); + debug!(rp = %rp, "Credential not found under rp"); Ok(None) } // Any other error is transient or unexpected, not absence: propagate it. Err(e) => { - debug!("Pre-flight: Error testing under {rp:?}: {e:?}"); + debug!({ rp = %rp, error = ?e }, "Preflight request failed under rp"); Err(e) } } diff --git a/libwebauthn/src/proto/ctap2/protocol.rs b/libwebauthn/src/proto/ctap2/protocol.rs index 8cf44368..412f1c90 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(WebAuthnError::Platform( PlatformError::InvalidDeviceResponse, @@ -138,7 +137,7 @@ where error => return Err(WebAuthnError::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); @@ -164,7 +163,7 @@ where error => return Err(WebAuthnError::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 28357a1b56cc806bcb3198fe51143298bf30afe3 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 08/12] 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 e3c93d42..7e6aebc2 100644 --- a/libwebauthn/src/pin/mod.rs +++ b/libwebauthn/src/pin/mod.rs @@ -190,9 +190,9 @@ 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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", @@ -201,14 +201,14 @@ where // 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" ); PlatformError::CryptoError(String::from("pin/uv crypto operation failed")) })?; 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" ); @@ -216,7 +216,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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -265,7 +265,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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -290,8 +290,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(PlatformError::CryptoError(String::from( @@ -301,13 +301,13 @@ 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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); }; let Ok(plaintext) = dec.decrypt_padded_vec_mut::(ciphertext) else { - error!("Unpad error while decrypting"); + warn!("Unpad error while decrypting"); return Err(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -391,7 +391,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" ); PlatformError::CryptoError(String::from("pin/uv crypto operation failed")) })?; @@ -402,7 +402,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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -420,14 +420,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" ); PlatformError::CryptoError(String::from("pin/uv crypto operation failed")) })?; // 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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -438,13 +438,13 @@ 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(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); }; let Ok(plaintext) = dec.decrypt_padded_vec_mut::(ciphertext) else { - error!("Unpad error while decrypting"); + warn!("Unpad error while decrypting"); return Err(PlatformError::CryptoError(String::from( "pin/uv crypto operation failed", ))); @@ -458,7 +458,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" ); PlatformError::CryptoError(String::from("pin/uv crypto operation failed")) })?; @@ -479,7 +479,7 @@ pub fn pin_hash(pin: &[u8]) -> Vec { pub fn hmac_sha256(key: &[u8], message: &[u8]) -> Result, PlatformError> { let mut hmac = HmacSha256::new_from_slice(key).map_err(|e| { - error!("HMAC key error: {e}"); + error!(?e, "HMAC key error"); PlatformError::CryptoError(format!("HMAC key error: {e}")) })?; hmac.update(message); @@ -490,7 +490,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"); PlatformError::CryptoError(format!("HKDF expand error: {e}")) })?; Ok(Vec::from(okm)) @@ -555,7 +555,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(WebAuthnError::Ctap(CtapError::Other)); }; diff --git a/libwebauthn/src/pin/persistent_token.rs b/libwebauthn/src/pin/persistent_token.rs index d5bf2d2a..243a54da 100644 --- a/libwebauthn/src/pin/persistent_token.rs +++ b/libwebauthn/src/pin/persistent_token.rs @@ -113,7 +113,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()); } @@ -130,7 +130,7 @@ fn enc_identifier_key(token: &[u8]) -> Result<[u8; 16], PlatformError> { 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"); PlatformError::CryptoError(format!("HKDF expand error: {e}")) })?; Ok(key) @@ -143,9 +143,9 @@ pub(crate) fn decrypt_enc_identifier( enc_identifier: &[u8], ) -> Result<[u8; 16], PlatformError> { 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(PlatformError::InvalidDeviceResponse); } @@ -156,11 +156,11 @@ pub(crate) fn decrypt_enc_identifier( return Err(PlatformError::InvalidDeviceResponse); }; 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(PlatformError::InvalidDeviceResponse); }; plaintext.try_into().map_err(|_| { - error!("Recovered device identifier was not 16 bytes"); + warn!("Recovered device identifier was not 16 bytes"); PlatformError::InvalidDeviceResponse }) } @@ -205,12 +205,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(PlatformError::InvalidDeviceResponse); }; 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"); PlatformError::InvalidDeviceResponse })?; reap_superseded_records(store, &device_identifier).await; From 674806db7de87c396361fd4eafb11185f77bb9fe Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 09/12] 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 | 27 +++++++++---------- 11 files changed, 52 insertions(+), 48 deletions(-) diff --git a/libwebauthn/src/fido.rs b/libwebauthn/src/fido.rs index d5f5c575..90664a40 100644 --- a/libwebauthn/src/fido.rs +++ b/libwebauthn/src/fido.rs @@ -142,7 +142,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" + ); PlatformError::InvalidDeviceResponse })?; @@ -157,7 +160,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" ); PlatformError::InvalidDeviceResponse })?; diff --git a/libwebauthn/src/lib.rs b/libwebauthn/src/lib.rs index 0d2c6c49..8dfacec1 100644 --- a/libwebauthn/src/lib.rs +++ b/libwebauthn/src/lib.rs @@ -125,9 +125,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($crate::webauthn::error::PlatformError::InvalidDeviceResponse.into()); } diff --git a/libwebauthn/src/management/bio_enrollment.rs b/libwebauthn/src/management/bio_enrollment.rs index e2c66cd8..2086b39f 100644 --- a/libwebauthn/src/management/bio_enrollment.rs +++ b/libwebauthn/src/management/bio_enrollment.rs @@ -87,7 +87,7 @@ where match resp.modality { Some(modality) => Ok(modality), None => { - warn!("Channel did not return modality."); + warn!("Channel did not return modality"); Err(WebAuthnError::Ctap(CtapError::Other)) } } @@ -101,7 +101,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(WebAuthnError::Ctap(CtapError::Other)); }; Ok(Ctap2BioEnrollmentFingerprintSensorInfo { diff --git a/libwebauthn/src/ops/u2f.rs b/libwebauthn/src/ops/u2f.rs index e51cc472..aae2b1ce 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(WebAuthnError::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"); WebAuthnError::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"); WebAuthnError::Platform(PlatformError::CryptoError( "public key is identity or compressed".into(), )) @@ -250,7 +253,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 593e8e81..b2a2bf92 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, @@ -421,7 +421,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; } }; @@ -435,7 +435,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 3209c8a0..c4edb068 100644 --- a/libwebauthn/src/ops/webauthn/idl/mod.rs +++ b/libwebauthn/src/ops/webauthn/idl/mod.rs @@ -131,7 +131,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( @@ -142,7 +142,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 009cfc31..145fdd75 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 461db570..8a7a5266 100644 --- a/libwebauthn/src/transport/channel.rs +++ b/libwebauthn/src/transport/channel.rs @@ -62,7 +62,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 9d715daa..dc196995 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}; @@ -434,7 +434,7 @@ async fn get_assertion_fido2( let count = (response.credentials_count.unwrap_or(1) as usize).min(max_count); 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 let next = channel.ctap2_get_next_assertion(op.timeout).await?; validate_rp_id_hash(&next)?; @@ -682,9 +682,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); } @@ -719,7 +719,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 b6fd76a4..e6e59aeb 100644 --- a/libwebauthn/src/webauthn/pin_uv_auth_token.rs +++ b/libwebauthn/src/webauthn/pin_uv_auth_token.rs @@ -2,7 +2,7 @@ use std::sync::Arc; use std::time::Duration; use icu_normalizer::ComposingNormalizerBorrowed; -use tracing::{debug, error, info, instrument, warn}; +use tracing::{debug, info, instrument, warn}; use cosey::PublicKey; @@ -88,7 +88,7 @@ fn enforce_no_mc_ga_with_client_pin( if get_info_response.option_enabled("uv") && !uv_unavailable { Ok(Ctap2UserVerificationOperation::GetPinUvAuthTokenUsingUvWithPermissions) } else { - error!("noMcGaPermissionsWithClientPin is set but built-in UV is unavailable for mc/ga"); + warn!("noMcGaPermissionsWithClientPin is set but built-in UV is unavailable for mc/ga"); Err(PlatformError::NoUvAvailable) } } @@ -174,11 +174,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( @@ -289,7 +289,7 @@ where ) .await else { - error!("No supported PIN/UV auth protocols found"); + warn!("No supported PIN/UV auth protocols found"); return Err(WebAuthnError::Ctap(CtapError::Other)); }; @@ -346,7 +346,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"); WebAuthnError::Ctap(CtapError::PINRequired) })?), )?, @@ -359,7 +359,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"); WebAuthnError::Ctap(CtapError::PINRequired) })?), )?, @@ -446,11 +446,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"); WebAuthnError::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(WebAuthnError::Ctap(CtapError::Other)); }; @@ -459,9 +459,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(WebAuthnError::Ctap(CtapError::Other)); @@ -526,7 +525,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(WebAuthnError::Ctap(CtapError::Other)); }; Ok(pin_proto.encapsulate(&public_key)?) From ba6f6e29f5ef03c2ff041eaed0ae715f662a1717 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 7 Jun 2026 21:59:12 +0100 Subject: [PATCH 10/12] 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 0cd7ece4..02813a6e 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); From 67a620cd19a4367f1f78116fd4665e491bfca987 Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 13 Sep 2026 19:35:07 +0100 Subject: [PATCH 11/12] refactor: apply the logging policy to code added since 0.7.0 --- libwebauthn/src/proto/ctap2/preflight.rs | 2 +- libwebauthn/src/webauthn.rs | 7 ++----- 2 files changed, 3 insertions(+), 6 deletions(-) diff --git a/libwebauthn/src/proto/ctap2/preflight.rs b/libwebauthn/src/proto/ctap2/preflight.rs index 006be7f6..f78f61a7 100644 --- a/libwebauthn/src/proto/ctap2/preflight.rs +++ b/libwebauthn/src/proto/ctap2/preflight.rs @@ -120,7 +120,7 @@ async fn preflight_one( } // Only CTAP2_ERR_NO_CREDENTIALS proves the credential is absent. Err(WebAuthnError::Ctap(CtapError::NoCredentials)) => { - debug!(rp = %rp, "Credential not found under rp"); + trace!(rp = %rp, "Credential not found under rp"); Ok(None) } // Any other error is transient or unexpected, not absence: propagate it. diff --git a/libwebauthn/src/webauthn.rs b/libwebauthn/src/webauthn.rs index dc196995..7ed5abe1 100644 --- a/libwebauthn/src/webauthn.rs +++ b/libwebauthn/src/webauthn.rs @@ -60,10 +60,7 @@ fn filter_oversized_credentials( fn ensure_credential_count(count: usize, info: &Ctap2GetInfoResponse) -> Result<(), PlatformError> { if let Some(max) = info.max_credential_count_in_list() { if count > max { - warn!( - count, - max, "credential list exceeds maxCredentialCountInList" - ); + warn!({ count, max }, "credential list exceeds maxCredentialCountInList"); return Err(PlatformError::RequestTooLarge); } } @@ -77,7 +74,7 @@ fn ensure_msg_size( let size = request.ctap_hid_data().len(); let max = info.max_msg_size(); if size > max { - warn!(size, max, "serialized request exceeds maxMsgSize"); + warn!({ size, max }, "serialized request exceeds maxMsgSize"); return Err(PlatformError::RequestTooLarge); } Ok(()) From 95f13ef77ee80d786852dae6c368113214ea37fa Mon Sep 17 00:00:00 2001 From: Alfie Fresta Date: Sun, 13 Sep 2026 19:35:12 +0100 Subject: [PATCH 12/12] docs: align device enumeration levels with the polled discovery change --- docs/logging.md | 7 ++++--- libwebauthn/src/transport/ble/device.rs | 4 ++-- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/docs/logging.md b/docs/logging.md index e262b7cd..9ffc32c7 100644 --- a/docs/logging.md +++ b/docs/logging.md @@ -39,9 +39,10 @@ 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. +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. Device enumeration is polled by callers, so it logs the +count at `debug!` and the device list at `trace!`. ### `debug!` diff --git a/libwebauthn/src/transport/ble/device.rs b/libwebauthn/src/transport/ble/device.rs index 95872b91..6c39013a 100644 --- a/libwebauthn/src/transport/ble/device.rs +++ b/libwebauthn/src/transport/ble/device.rs @@ -3,7 +3,7 @@ use std::fmt; use ::btleplug::api::Peripheral; use async_trait::async_trait; use hex::ToHex; -use tracing::{info, instrument}; +use tracing::{debug, instrument}; use crate::transport::ble::error::BleError; use crate::transport::device::Device; @@ -28,7 +28,7 @@ pub async fn list_devices() -> Result, BleError> { .iter() .map(|bluez_device| bluez_device.into()) .collect(); - info!(count = devices.len(), "Listing available BLE devices"); + debug!(count = devices.len(), "Listing available BLE devices"); Ok(devices) }