[INFO] fetching crate wordval-web 1.0.6...
[INFO] testing wordval-web-1.0.6 against 1.100.0-beta.1+cargoflags=--release for beta-release-1.100-2
[INFO] extracting crate wordval-web 1.0.6 into /workspace/builds/worker-3-tc2/source
[INFO] started tweaking crates.io crate wordval-web 1.0.6
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate wordval-web 1.0.6
[INFO] tweaked toml for crates.io crate wordval-web 1.0.6 written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate wordval-web 1.0.6 on toolchain 1.100.0-beta.1
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.100.0-beta.1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wordval-web 1.0.6 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.100.0-beta.1" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-m" "1610612736" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:77db811e55d90add9212f6832c23229e3de5f1c1f9905e8cb07319ea15df73ac" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a
[INFO] running `Command { std: "docker" "start" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-w" "/opt/rustwide/workdir" "--user" "0:0" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling typenum v1.20.1
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling generic-array v0.14.7
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling log v0.4.30
[INFO] [stderr]    Compiling tracing-core v0.1.36
[INFO] [stderr]    Compiling zerocopy v0.8.50
[INFO] [stderr]    Compiling http v1.4.1
[INFO] [stderr]    Compiling spin v0.9.8
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling tokio-macros v2.7.0
[INFO] [stderr]    Compiling hashbrown v0.17.1
[INFO] [stderr]    Compiling base64ct v1.8.3
[INFO] [stderr]    Compiling libm v0.2.16
[INFO] [stderr]    Compiling serde_json v1.0.150
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling regex-syntax v0.8.10
[INFO] [stderr]    Compiling futures-util v0.3.32
[INFO] [stderr]    Compiling lazy_static v1.5.0
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling pem-rfc7468 v0.7.0
[INFO] [stderr]    Compiling crc32fast v1.5.0
[INFO] [stderr]    Compiling fnv v1.0.7
[INFO] [stderr]    Compiling icu_normalizer v2.2.0
[INFO] [stderr]    Compiling darling_core v0.20.11
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling der v0.7.10
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling tokio v1.52.3
[INFO] [stderr]    Compiling indexmap v2.14.0
[INFO] [stderr]    Compiling futures-channel v0.3.32
[INFO] [stderr]    Compiling http-body v1.0.1
[INFO] [stderr]    Compiling multer v3.1.0
[INFO] [stderr]    Compiling data-encoding v2.11.0
[INFO] [stderr]    Compiling http-body-util v0.1.3
[INFO] [stderr]    Compiling adler2 v2.0.1
[INFO] [stderr]    Compiling simd-adler32 v0.3.9
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling idna_adapter v1.2.2
[INFO] [stderr]    Compiling crypto-common v0.1.7
[INFO] [stderr]    Compiling block-buffer v0.10.4
[INFO] [stderr]    Compiling inout v0.1.4
[INFO] [stderr]    Compiling digest v0.10.7
[INFO] [stderr]    Compiling cipher v0.4.4
[INFO] [stderr]    Compiling spki v0.7.3
[INFO] [stderr]    Compiling sha1 v0.10.6
[INFO] [stderr]    Compiling universal-hash v0.5.1
[INFO] [stderr]    Compiling num-integer v0.1.46
[INFO] [stderr]    Compiling opaque-debug v0.3.1
[INFO] [stderr]    Compiling powerfmt v0.2.0
[INFO] [stderr]    Compiling num-bigint-dig v0.8.6
[INFO] [stderr]    Compiling unicase v2.9.0
[INFO] [stderr]    Compiling anyhow v1.0.104
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling deranged v0.5.8
[INFO] [stderr]    Compiling mime_guess v2.0.5
[INFO] [stderr]    Compiling flate2 v1.1.9
[INFO] [stderr]    Compiling polyval v0.6.2
[INFO] [stderr]    Compiling num-iter v0.1.46
[INFO] [stderr]    Compiling pkcs8 v0.10.2
[INFO] [stderr]    Compiling idna v1.1.0
[INFO] [stderr]    Compiling axum-core v0.5.6
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling sharded-slab v0.1.7
[INFO] [stderr]    Compiling axum-macros v0.5.1
[INFO] [stderr]    Compiling ahash v0.8.12
[INFO] [stderr]    Compiling thread_local v1.1.9
[INFO] [stderr]    Compiling toml_write v0.1.2
[INFO] [stderr]    Compiling nu-ansi-term v0.50.3
[INFO] [stderr]    Compiling serde_path_to_error v0.1.20
[INFO] [stderr]    Compiling once_cell v1.21.4
[INFO] [stderr]    Compiling time-core v0.1.8
[INFO] [stderr]    Compiling compression-core v0.4.32
[INFO] [stderr]    Compiling num-conv v0.2.2
[INFO] [stderr]    Compiling linkme-impl v0.3.36
[INFO] [stderr]    Compiling matchit v0.8.4
[INFO] [stderr]    Compiling winnow v0.7.15
[INFO] [stderr]    Compiling time v0.3.47
[INFO] [stderr]    Compiling darling_macro v0.20.11
[INFO] [stderr]    Compiling compression-codecs v0.4.38
[INFO] [stderr]    Compiling darling v0.20.11
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling toml_datetime v0.6.11
[INFO] [stderr]    Compiling serde_urlencoded v0.7.1
[INFO] [stderr]    Compiling serde_spanned v0.6.9
[INFO] [stderr]    Compiling validator_derive v0.20.0
[INFO] [stderr]    Compiling pkcs1 v0.7.5
[INFO] [stderr]    Compiling url v2.5.8
[INFO] [stderr]    Compiling ghash v0.5.1
[INFO] [stderr]    Compiling crossbeam-channel v0.5.15
[INFO] [stderr]    Compiling aes v0.8.4
[INFO] [stderr]    Compiling ctr v0.9.2
[INFO] [stderr]    Compiling blake2 v0.10.6
[INFO] [stderr]    Compiling sha2 v0.10.9
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling signature v2.2.0
[INFO] [stderr]    Compiling aead v0.5.2
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling rand_chacha v0.3.1
[INFO] [stderr]    Compiling password-hash v0.5.0
[INFO] [stderr]    Compiling rand v0.8.6
[INFO] [stderr]    Compiling rand v0.9.4
[INFO] [stderr]    Compiling csv-core v0.1.13
[INFO] [stderr]    Compiling toml_edit v0.22.27
[INFO] [stderr]    Compiling symlink v0.1.0
[INFO] [stderr]    Compiling linkme v0.3.36
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling csv v1.4.0
[INFO] [stderr]    Compiling dashmap v6.2.1
[INFO] [stderr]    Compiling argon2 v0.5.3
[INFO] [stderr]    Compiling aes-gcm v0.10.3
[INFO] [stderr]    Compiling arc-swap v1.9.1
[INFO] [stderr]    Compiling hmac v0.12.1
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling regex v1.12.3
[INFO] [stderr]    Compiling http-range-header v0.4.2
[INFO] [stderr]    Compiling tungstenite v0.29.0
[INFO] [stderr]    Compiling bitflags v2.11.1
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling toml v0.8.23
[INFO] [stderr]    Compiling validator v0.20.0
[INFO] [stderr]    Compiling async-compression v0.4.42
[INFO] [stderr]    Compiling wordval-macros v1.0.5
[INFO] [stderr]    Compiling tokio-tungstenite v0.29.0
[INFO] [stderr]    Compiling h2 v0.4.14
[INFO] [stderr]    Compiling rsa v0.9.10
[INFO] [stderr]    Compiling tower-http v0.6.11
[INFO] [stderr]    Compiling tracing-appender v0.2.5
[INFO] [stderr]    Compiling wordval-config v1.0.6
[INFO] [stderr]    Compiling hyper v1.10.1
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling axum v0.8.9
[INFO] [stderr]    Compiling wordval-core v1.0.5
[INFO] [stderr]    Compiling wordval-utils v1.0.5
[INFO] [stderr]    Compiling wordval-web v1.0.6 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 1m 46s
[INFO] [stderr] warning: the following packages contain code that will be rejected by a future version of Rust: proc-macro-error2 v2.0.1
[INFO] [stderr] note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1`
[INFO] running `Command { std: "docker" "inspect" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling wordval-web v1.0.6 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 26.61s
[INFO] [stderr] warning: the following packages contain code that will be rejected by a future version of Rust: proc-macro-error2 v2.0.1
[INFO] [stderr] note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1`
[INFO] running `Command { std: "docker" "inspect" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.31s
[INFO] [stderr] warning: the following packages contain code that will be rejected by a future version of Rust: proc-macro-error2 v2.0.1
[INFO] [stderr] note: to see what the problems were, use the option `--future-incompat-report`, or run `cargo report future-incompatibilities --id 1`
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/build/wordval-web/505279d6dbd99c5f/out/wordval_web-505279d6dbd99c5f)
[INFO] [stdout] 
[INFO] [stdout] running 51 tests
[INFO] [stdout] [2m2026-10-18T20:14:53.549226Z[0m [31mERROR[0m [2mwordval_web::router[0m[2m:[0m 不支持的路由方法 'FOO'，路由 /bad 未注册
[INFO] [stdout] [2m2026-10-18T20:14:53.549264Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m ========== 已注册路由列表 (9 条) ==========
[INFO] [stdout] [2m2026-10-18T20:14:53.549270Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /g
[INFO] [stdout] [2m2026-10-18T20:14:53.549274Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] POST    /p
[INFO] [stdout] [2m2026-10-18T20:14:53.549277Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] PUT     /u
[INFO] [stdout] [2m2026-10-18T20:14:53.549280Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] DELETE  /d
[INFO] [stdout] [2m2026-10-18T20:14:53.549283Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] PATCH   /pa
[INFO] [stdout] [2m2026-10-18T20:14:53.549298Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /api/v2/users
[INFO] [stdout] [2m2026-10-18T20:14:53.549301Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /m/sub
[INFO] [stdout] [2m2026-10-18T20:14:53.549304Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /admin
[INFO] [stdout] [2m2026-10-18T20:14:53.549307Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /roles
[INFO] [stdout] [2m2026-10-18T20:14:53.549311Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m ============================================
[INFO] [stdout] [2m2026-10-18T20:14:53.549346Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> tenant_context(80) -> permission_check(100)
[INFO] [stdout] [2m2026-10-18T20:14:53.549434Z[0m [33m WARN[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m923a930e4d71452a [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/admin[1m}[0m[2m:[0m [2mwordval_web::middleware::permission_check[0m[2m:[0m 权限检查: path=/api/admin, required=admin:access, CurrentUser 未注入 (auth 中间件未执行)
[INFO] [stdout] [2m2026-10-18T20:14:53.549450Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> rate_limit(60) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.549458Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> tenant_context(80) -> require_auth(90)
[INFO] [stdout] [2m2026-10-18T20:14:53.549476Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m923a930e4d71452a [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/admin[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/admin -> 403 (0ms) [3mrequest_id[0m[2m=[0m923a930e4d71452a [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-18T20:14:53.549511Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0mf53cba33a02e40eb [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/probe -> 404 (0ms) [3mrequest_id[0m[2m=[0mf53cba33a02e40eb [3mip[0m[2m=[0m1.1.1.1
[INFO] [stdout] [2m2026-10-18T20:14:53.549513Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0mefe0cdf1b6df4448 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/protected[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/protected -> 401 (0ms) [3mrequest_id[0m[2m=[0mefe0cdf1b6df4448 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-18T20:14:53.549542Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0ma9f430b0da7c493f [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/probe -> 404 (0ms) [3mrequest_id[0m[2m=[0ma9f430b0da7c493f [3mip[0m[2m=[0m2.2.2.2
[INFO] [stdout] [2m2026-10-18T20:14:53.549578Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m3ff9ba447f8d4807 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/probe -> 429 (0ms) [3mrequest_id[0m[2m=[0m3ff9ba447f8d4807 [3mip[0m[2m=[0m1.1.1.1
[INFO] [stdout] [2m2026-10-18T20:14:53.549727Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> tenant_context(80) -> require_auth(90)
[INFO] [stdout] test app::tests::parse_addr_variants ... ok
[INFO] [stdout] test app::tests::resolve_display_addr_variants ... ok
[INFO] [stdout] test app::tests::builder_route_group_merge_and_unknown_method ... ok
[INFO] [stdout] test app::tests::short_circuit_403_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::short_circuit_401_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::rate_limit_uses_resolved_client_ip_from_trusted_proxy ... ok
[INFO] [stdout] test app::tests::short_circuit_401_is_recorded_in_access_log ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.550156Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> security_headers(30) -> cors(40) -> tenant_context(80) -> custom_outer(150) -> custom_inner(250)
[INFO] [stdout] [2m2026-10-18T20:14:53.549230Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.550269Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0md97ac4a3c5c4493f [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/no/such/route[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /no/such/route -> 404 (0ms) [3mrequest_id[0m[2m=[0md97ac4a3c5c4493f [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-18T20:14:53.552196Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> tenant_context(80)
[INFO] [stdout] test app::tests::custom_middleware_inserted_by_priority ... ok
[INFO] [stdout] test app::tests::not_found_404_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::access_log_uses_resolved_client_ip ... ok
[INFO] [stdout] test app::tests::build_cors_layer_mirror_and_any_headers ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.552675Z[0m [32m INFO[0m [2mwordval_config[0m[2m:[0m 默认配置文件已生成到 /tmp/wv_gen_cfg_app_2775/config.toml
[INFO] [stdout] test app::tests::start_gen_config_only_writes_default_file ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.553063Z[0m [33m WARN[0m [2mwordval_web::audit[0m[2m:[0m 审计写入器: 写入器已关闭，丢弃审计记录（累计 1 条）
[INFO] [stdout] [2m2026-10-18T20:14:53.553818Z[0m [33m WARN[0m [2mwordval_web::audit[0m[2m:[0m 审计写入器: 队列已满，丢弃审计记录（累计 1 条）
[INFO] [stdout] [2m2026-10-18T20:14:53.554022Z[0m [33m WARN[0m [2mwordval_web::audit[0m[2m:[0m 审计写入器: sink 落盘失败，丢弃 5 条（累计失败批数 1）: 服务器错误: db down
[INFO] [stdout] [2m2026-10-18T20:14:53.554132Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> rate_limit(60) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.554189Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m68f61174e27d4ec4 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/probe -> 404 (0ms) [3mrequest_id[0m[2m=[0m68f61174e27d4ec4 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] test app::tests::validate_middleware_config_auth_branch ... ok[2m2026-10-18T20:14:53.554228Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0ma2deb8f508b14800 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m GET /api/probe -> 429 (0ms) [3mrequest_id[0m[2m=[0ma2deb8f508b14800 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] 
[INFO] [stdout] test audit::tests::test_write_after_shutdown_counts_dropped ... ok
[INFO] [stdout] test app::tests::validate_middleware_config_cors_rejects_and_accepts ... ok
[INFO] [stdout] test audit::tests::test_batch_respects_max_batch ... ok
[INFO] [stdout] test audit::tests::test_close_drains_all_pending ... ok
[INFO] [stdout] test audit::tests::test_config_validation ... ok
[INFO] [stdout] test audit::tests::test_record_serializes ... ok
[INFO] [stdout] test audit::tests::test_sink_failure_counts_flush_errors ... ok
[INFO] [stdout] test chain::tests::chain_applies_smaller_priority_outermost ... ok
[INFO] [stdout] test app::tests::short_circuit_429_has_request_id_and_security_headers ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.555501Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> compression(50) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.555717Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 上传目录就绪 path=/tmp/wv_app_serve_2775/up max_size_mb=10
[INFO] [stdout] test chain::tests::same_priority_keeps_registration_order ... ok
[INFO] [stdout] test middleware::auth::tests::join_route_path_normalizes_prefix_and_path ... ok[2m2026-10-18T20:14:53.555795Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 下载目录就绪 path=/tmp/wv_app_serve_2775/dn
[INFO] [stdout] 
[INFO] [stdout] [2m2026-10-18T20:14:53.555811Z[0m [32m INFO[0m [2mwordval_core::plugin[0m[2m:[0m 启动插件: dummy
[INFO] [stdout] test middleware::auth::tests::match_path_exact_and_single_param_segment ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.555845Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 全局路由前缀已启用: /v9
[INFO] [stdout] [2m2026-10-18T20:14:53.555854Z[0m [32m INFO[0m [2mwordval_web::policy[0m[2m:[0m 路由策略表: 已注册 1 条（公开 1 / 需登录 0）
[INFO] [stdout] test middleware::auth::tests::match_path_tail_wildcard ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.555880Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> security_headers(30) -> compression(50) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.555888Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m Wordval 启动 -> http://127.0.0.1:46181
[INFO] [stdout] [2m2026-10-18T20:14:53.555892Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   profile=dev, request_id=true log=false cors=false compression=true rate_limit=false auth=false security_headers=true permission=false nonce=false static_files=false not_found=true
[INFO] [stdout] [2m2026-10-18T20:14:53.555898Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m Wordval 启动完成, 耗时 0ms
[INFO] [stdout] test middleware::permission_check::tests::method_binding_respected ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.556111Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 中间件链（外 -> 内）: request_id(0) -> client_identity(10) -> request_log(20) -> security_headers(30) -> cors(40) -> tenant_context(80)
[INFO] [stdout] [2m2026-10-18T20:14:53.556159Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m10264cda8a1648e5 [3mmethod[0m[2m=[0mOPTIONS [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_web::middleware::request_log[0m[2m:[0m OPTIONS /api/probe -> 200 (0ms) [3mrequest_id[0m[2m=[0m10264cda8a1648e5 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] test middleware::permission_check::tests::macro_rule_wins_over_config_rule ... ok
[INFO] [stdout] test middleware::permission_check::tests::prefix_joined_rules_match_final_path ... ok
[INFO] [stdout] test middleware::permission_check::tests::macro_rules_not_disabled_by_config_switch ... ok
[INFO] [stdout] test middleware::permission_check::tests::most_specific_rule_wins_within_same_source ... ok
[INFO] [stdout] test middleware::auth::tests::match_path_normalizes_dot_segments ... ok
[INFO] [stdout] test app::tests::compression_enabled_and_request_log_excludes_path ... ok
[INFO] [stdout] test policy::tests::classify_auth_disabled_all_public ... ok
[INFO] [stdout] test policy::tests::classify_counts_macro_and_ignore_as_public ... ok
[INFO] [stdout] test policy::tests::classify_page_paths_outside_api_prefixes_are_public ... ok
[INFO] [stdout] test app::tests::cors_preflight_has_request_id_and_security_headers ... ok
[INFO] [stdout] test policy::tests::classify_pattern_rules_match_wildcard_paths ... ok
[INFO] [stdout] test policy::tests::config_rules_and_ignore_paths_included ... ok
[INFO] [stdout] test policy::tests::distinct_routes_do_not_conflict ... ok
[INFO] [stdout] test policy::tests::no_auth_all_methods_overlaps_method_permission ... ok
[INFO] [stdout] test policy::tests::no_auth_and_permission_same_route_conflicts ... ok
[INFO] [stdout] test policy::tests::same_route_same_permission_is_fine ... ok
[INFO] [stdout] test policy::tests::dormant_config_ignored_when_disabled ... ok
[INFO] [stdout] test policy::tests::duplicate_permission_with_different_perm_conflicts ... ok
[INFO] [stdout] test policy::tests::global_prefix_joined_into_policy_path ... ok
[INFO] [stdout] test policy::tests::method_specific_no_auth_does_not_weaken_other_method ... ok
[INFO] [stdout] test app::tests::build_cors_layer_list_credentials_max_age ... ok
[INFO] [stdout] [2m2026-10-18T20:14:53.654472Z[0m [33m WARN[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m66c4ce8830de49df [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/v9/nope[1m}[0m[2m:[0m [2mwordval_web::app[0m[2m:[0m 请求404 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/v9/nope [3mstatus[0m[2m=[0m404
[INFO] [stdout] test app::tests::serve_full_pipeline_with_prefix_and_not_found ... ok
[INFO] [stdout] test audit::tests::test_interval_flush_without_full_batch ... ok
[INFO] [stdout] test audit::tests::test_overflow_drops_and_counts ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 51 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.31s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/middleware_contract.rs (/opt/rustwide/target/release/build/wordval-web/b33528ef2fa564ab/out/middleware_contract-b33528ef2fa564ab)
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test is_authorized_accepts_exact_permission ... ok
[INFO] [stdout] test is_authorized_accepts_wildcard_permission ... ok
[INFO] [stdout] test is_admin_user_detects_flag_and_wildcards ... ok
[INFO] [stdout] test is_authorized_accepts_admin_flag ... ok
[INFO] [stdout] test unknown_route_method_is_not_silently_registered ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/middleware_layers.rs (/opt/rustwide/target/release/build/wordval-web/c4d680af83dce973/out/middleware_layers-c4d680af83dce973)
[INFO] [stdout] 
[INFO] [stdout] running 13 tests
[INFO] [stdout] test rate_limit_blocks_over_quota_per_ip ... ok
[INFO] [stdout] test request_id_regenerates_invalid_or_missing ... ok
[INFO] [stdout] test security_headers_defaults_inject_all ... ok
[INFO] [stdout] test request_id_reuses_valid_inbound_header ... ok
[INFO] [stdout] test security_headers_respects_switches_and_bad_values ... ok
[INFO] [stdout] test client_identity_with_trusted_reads_xff ... ok
[INFO] [stdout] test client_identity_without_trusted_ignores_proxy_headers ... ok
[INFO] [stdout] test request_log_passthrough_and_debug_mode_preserves_body ... ok
[INFO] [stdout] test request_log_debug_mode_rejects_oversized_unknown_length_body ... ok
[INFO] [stdout] test request_log_debug_mode_oversized_unknown_response_body_stays_usable ... ok
[INFO] [stdout] test request_log_debug_mode_passes_through_oversized_declared_body ... ok
[INFO] [stdout] test rate_limit_window_resets_and_default_ip ... ok
[INFO] [stdout] test rate_limit_cleanup_task_removes_expired ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 13 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.41s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/web_units.rs (/opt/rustwide/target/release/build/wordval-web/e377797abd629c37/out/web_units-e377797abd629c37)
[INFO] [stdout] 
[INFO] [stdout] running 15 tests
[INFO] [stdout] test validated_validation_rules ... ok
[INFO] [stdout] test tenant_task_local_scope ... ok
[INFO] [stdout] test resolve_tenant_rules ... ok
[INFO] [stdout] test html_handler_serves_page ... ok
[INFO] [stdout] test upload_download_path_singletons ... ok
[INFO] [stdout] test user_extractors_with_and_without_session ... ok
[INFO] [stdout] test router_default_and_unknown_method ... ok
[INFO] [stdout] test router_merge_nests_subroutes ... ok
[INFO] [stdout] test tenant_context_layer_end_to_end ... ok
[INFO] [stdout] test router_all_methods ... ok
[INFO] [stdout] test file_sender_blocks_traversal_and_missing ... ok
[INFO] [stdout] test validated_json_accepts_good_body ... ok
[INFO] [stdout] test validated_json_rejects_bad_json ... ok
[INFO] [stdout] test tenant_header_config ... ok
[INFO] [stdout] test file_sender_streams_file ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 15 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests wordval_web
[INFO] [stdout] 
[INFO] [stdout] running 14 tests
[INFO] [stdout] test src/app.rs - app::App (line 59) ... ignored
[INFO] [stdout] test src/app.rs - app::App::group (line 241) ... ignored
[INFO] [stdout] test src/app.rs - app::App::middleware (line 448) ... ignored
[INFO] [stdout] test src/app.rs - app::App::new (line 93) ... ignored
[INFO] [stdout] test src/app.rs - app::App::on_startup (line 399) ... ignored
[INFO] [stdout] test src/app.rs - app::App::print_routes (line 299) ... ignored
[INFO] [stdout] test src/app.rs - app::App::route (line 220) ... ignored
[INFO] [stdout] test src/app.rs - app::App::scan (line 277) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_middleware_hook (line 423) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_permission (line 329) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_role (line 362) ... ignored
[INFO] [stdout] test src/audit.rs - audit (line 17) ... ignored
[INFO] [stdout] test src/lib.rs - (line 17) ... ignored
[INFO] [stdout] test src/resources.rs - resources (line 7) ... ignored
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 14 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a", kill_on_drop: false }`
[INFO] [stdout] a89c295598034156ecfd8fbae9caf52b75c7aabed3d51253a27917710c25ce9a
