[INFO] fetching crate wordval-web 1.0.4...
[INFO] testing wordval-web-1.0.4 against 1.99.0-beta.8 for beta-1.100-2
[INFO] extracting crate wordval-web 1.0.4 into /workspace/builds/worker-5-tc1/source
[INFO] started tweaking crates.io crate wordval-web 1.0.4
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate wordval-web 1.0.4
[INFO] tweaked toml for crates.io crate wordval-web 1.0.4 written to /workspace/builds/worker-5-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate wordval-web 1.0.4 on toolchain 1.99.0-beta.8
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wordval-web 1.0.4 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.99.0-beta.8" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded wordval-core v1.0.3
[INFO] [stderr]   Downloaded tungstenite v0.29.0
[INFO] [stderr]   Downloaded tokio-tungstenite v0.29.0
[INFO] [stderr]   Downloaded validator v0.20.0
[INFO] [stderr]   Downloaded validator_derive v0.20.0
[INFO] [stderr]   Downloaded wordval-utils v1.0.3
[INFO] [stderr]   Downloaded argon2 v0.5.3
[INFO] [stderr]   Downloaded wordval-macros v1.0.3
[INFO] [stderr]   Downloaded wordval-config v1.0.4
[INFO] [stderr]   Downloaded wordval-fs v1.0.3
[INFO] [stderr]   Downloaded http-range-header v0.4.2
[INFO] [stderr]   Downloaded async-compression v0.4.42
[INFO] [stderr]   Downloaded openssl v0.10.80
[INFO] [stderr]   Downloaded aws-sigv4 v1.5.1
[INFO] [stderr]   Downloaded aws-smithy-async v1.3.0
[INFO] [stderr]   Downloaded aws-smithy-types v1.6.1
[INFO] [stderr]   Downloaded aws-smithy-runtime-api-macros v1.1.0
[INFO] [stderr]   Downloaded aws-smithy-runtime-api v1.13.0
[INFO] [stderr]   Downloaded wordval-db v1.0.4
[INFO] [stderr]   Downloaded sqlx-sqlite v0.9.0
[INFO] [stderr]   Downloaded aws-credential-types v1.3.0
[INFO] [stderr]   Downloaded uuid v1.23.2
[INFO] [stderr]   Downloaded aws-smithy-http v0.64.0
[INFO] [stderr]   Downloaded sqlx v0.9.0
[INFO] [stderr]   Downloaded sqlx-macros v0.9.0
[INFO] [stderr]   Downloaded event-listener v5.4.1
[INFO] [stderr]   Downloaded toml_edit v0.25.12+spec-1.1.0
[INFO] [stderr]   Downloaded hashlink v0.11.0
[INFO] [stderr]   Downloaded sqlx-macros-core v0.9.0
[INFO] [stderr]   Downloaded flume v0.12.0
[INFO] [stderr]   Downloaded sqlx-core v0.9.0
[INFO] [stderr]   Downloaded redis v0.29.5
[INFO] [stderr]   Downloaded sqlx-mysql v0.9.0
[INFO] [stderr]   Downloaded ignore v0.4.25
[INFO] [stderr]   Downloaded sqlx-postgres v0.9.0
[INFO] [stderr]   Downloaded wordval-cache v1.0.3
[INFO] [stderr]   Downloaded libsqlite3-sys v0.37.0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/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:3111399a4047eeb3a02b7a90e478d715f38a8c6669b5c4b49d30a17385265909" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae
[INFO] running `Command { std: "docker" "start" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", 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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", 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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling const-oid v0.9.6
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling log v0.4.30
[INFO] [stderr]    Compiling memchr v2.8.1
[INFO] [stderr]    Compiling zerocopy v0.8.50
[INFO] [stderr]    Compiling http v1.4.1
[INFO] [stderr]    Compiling tokio-macros v2.7.0
[INFO] [stderr]    Compiling displaydoc v0.2.6
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling zerofrom v0.1.8
[INFO] [stderr]    Compiling errno v0.3.14
[INFO] [stderr]    Compiling spin v0.9.8
[INFO] [stderr]    Compiling crypto-common v0.1.7
[INFO] [stderr]    Compiling serde_json v1.0.150
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling yoke v0.8.2
[INFO] [stderr]    Compiling signal-hook-registry v1.4.8
[INFO] [stderr]    Compiling digest v0.10.7
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling futures-util v0.3.32
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling lazy_static v1.5.0
[INFO] [stderr]    Compiling zerovec v0.11.6
[INFO] [stderr]    Compiling darling_core v0.20.11
[INFO] [stderr]    Compiling der v0.7.10
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling sha1 v0.10.6
[INFO] [stderr]    Compiling inout v0.1.4
[INFO] [stderr]    Compiling multer v3.1.0
[INFO] [stderr]    Compiling sync_wrapper v1.0.2
[INFO] [stderr]    Compiling simd-adler32 v0.3.9
[INFO] [stderr]    Compiling data-encoding v2.11.0
[INFO] [stderr]    Compiling cipher v0.4.4
[INFO] [stderr]    Compiling zerotrie v0.2.4
[INFO] [stderr]    Compiling tokio v1.52.3
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling tinystr v0.8.3
[INFO] [stderr]    Compiling potential_utf v0.1.5
[INFO] [stderr]    Compiling icu_collections v2.2.0
[INFO] [stderr]    Compiling universal-hash v0.5.1
[INFO] [stderr]    Compiling icu_locale_core v2.2.0
[INFO] [stderr]    Compiling encoding_rs v0.8.35
[INFO] [stderr]    Compiling proc-macro-error-attr2 v2.0.0
[INFO] [stderr]    Compiling http-body v1.0.1
[INFO] [stderr]    Compiling num-integer v0.1.46
[INFO] [stderr]    Compiling http-body-util v0.1.3
[INFO] [stderr]    Compiling num-bigint-dig v0.8.6
[INFO] [stderr]    Compiling unicase v2.9.0
[INFO] [stderr]    Compiling opaque-debug v0.3.1
[INFO] [stderr]    Compiling polyval v0.6.2
[INFO] [stderr]    Compiling axum-core v0.5.6
[INFO] [stderr]    Compiling mime_guess v2.0.5
[INFO] [stderr]    Compiling num-iter v0.1.46
[INFO] [stderr]    Compiling spki v0.7.3
[INFO] [stderr]    Compiling proc-macro-error2 v2.0.1
[INFO] [stderr]    Compiling flate2 v1.1.9
[INFO] [stderr]    Compiling icu_provider v2.2.0
[INFO] [stderr]    Compiling pkcs8 v0.10.2
[INFO] [stderr]    Compiling sharded-slab v0.1.7
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling axum-macros v0.5.1
[INFO] [stderr]    Compiling compression-core v0.4.32
[INFO] [stderr]    Compiling winnow v0.7.15
[INFO] [stderr]    Compiling icu_properties v2.2.0
[INFO] [stderr]    Compiling icu_normalizer v2.2.0
[INFO] [stderr]    Compiling toml_write v0.1.2
[INFO] [stderr]    Compiling linkme-impl v0.3.36
[INFO] [stderr]    Compiling matchit v0.8.4
[INFO] [stderr]    Compiling serde_path_to_error v0.1.20
[INFO] [stderr]    Compiling time v0.3.47
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling regex v1.12.3
[INFO] [stderr]    Compiling compression-codecs v0.4.38
[INFO] [stderr]    Compiling pkcs1 v0.7.5
[INFO] [stderr]    Compiling toml_datetime v0.6.11
[INFO] [stderr]    Compiling serde_spanned v0.6.9
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling serde_urlencoded v0.7.1
[INFO] [stderr]    Compiling ghash v0.5.1
[INFO] [stderr]    Compiling crossbeam-channel v0.5.15
[INFO] [stderr]    Compiling ctr v0.9.2
[INFO] [stderr]    Compiling aes v0.8.4
[INFO] [stderr]    Compiling csv-core v0.1.13
[INFO] [stderr]    Compiling signature v2.2.0
[INFO] [stderr]    Compiling blake2 v0.10.6
[INFO] [stderr]    Compiling sha2 v0.10.9
[INFO] [stderr]    Compiling aead v0.5.2
[INFO] [stderr]    Compiling password-hash v0.5.0
[INFO] [stderr]    Compiling async-trait v0.1.89
[INFO] [stderr]    Compiling darling_macro v0.20.11
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling symlink v0.1.0
[INFO] [stderr]    Compiling linkme v0.3.36
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling dashmap v6.2.1
[INFO] [stderr]    Compiling darling v0.20.11
[INFO] [stderr]    Compiling validator_derive v0.20.0
[INFO] [stderr]    Compiling toml_edit v0.22.27
[INFO] [stderr]    Compiling aes-gcm v0.10.3
[INFO] [stderr]    Compiling argon2 v0.5.3
[INFO] [stderr]    Compiling csv v1.4.0
[INFO] [stderr]    Compiling idna_adapter v1.2.2
[INFO] [stderr]    Compiling idna v1.1.0
[INFO] [stderr]    Compiling hmac v0.12.1
[INFO] [stderr]    Compiling http-range-header v0.4.2
[INFO] [stderr]    Compiling wordval-macros v1.0.3
[INFO] [stderr]    Compiling url v2.5.8
[INFO] [stderr]    Compiling tracing-appender v0.2.5
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling rand_chacha v0.3.1
[INFO] [stderr]    Compiling validator v0.20.0
[INFO] [stderr]    Compiling rand v0.9.4
[INFO] [stderr]    Compiling rand v0.8.6
[INFO] [stderr]    Compiling tungstenite v0.29.0
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling async-compression v0.4.42
[INFO] [stderr]    Compiling toml v0.8.23
[INFO] [stderr]    Compiling tokio-tungstenite v0.29.0
[INFO] [stderr]    Compiling h2 v0.4.14
[INFO] [stderr]    Compiling tower-http v0.6.11
[INFO] [stderr]    Compiling wordval-config v1.0.4
[INFO] [stderr]    Compiling rsa v0.9.10
[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.3
[INFO] [stderr]    Compiling wordval-utils v1.0.3
[INFO] [stderr]    Compiling wordval-web v1.0.4 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 34.75s
[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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", 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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling wordval-web v1.0.4 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 8.02s
[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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", 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" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.26s
[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/debug/deps/wordval_web-106e7ff45091fd2f)
[INFO] [stdout] 
[INFO] [stdout] running 43 tests
[INFO] [stdout] [2m2026-10-06T21:13:14.794552Z[0m [31mERROR[0m [2mwordval_web::router[0m[2m:[0m 不支持的路由方法 'FOO'，路由 /bad 未注册
[INFO] [stdout] [2m2026-10-06T21:13:14.794752Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m ========== 已注册路由列表 (9 条) ==========
[INFO] [stdout] [2m2026-10-06T21:13:14.795160Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /g
[INFO] [stdout] [2m2026-10-06T21:13:14.795251Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] POST    /p
[INFO] [stdout] [2m2026-10-06T21:13:14.794827Z[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-06T21:13:14.795285Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] PUT     /u
[INFO] [stdout] [2m2026-10-06T21:13:14.795355Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] DELETE  /d
[INFO] [stdout] [2m2026-10-06T21:13:14.795366Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] PATCH   /pa
[INFO] [stdout] [2m2026-10-06T21:13:14.795375Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /api/v2/users
[INFO] [stdout] [2m2026-10-06T21:13:14.795384Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /m/sub
[INFO] [stdout] [2m2026-10-06T21:13:14.795436Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /admin
[INFO] [stdout] [2m2026-10-06T21:13:14.795491Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m   [路由] GET     /roles
[INFO] [stdout] [2m2026-10-06T21:13:14.795525Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m ============================================
[INFO] [stdout] [2m2026-10-06T21:13:14.795171Z[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-06T21:13:14.796503Z[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-06T21:13:14.798407Z[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-06T21:13:14.798496Z[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-06T21:13:14.801091Z[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-06T21:13:14.801356Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m3742b23881ee4608 [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=[0m3742b23881ee4608 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-06T21:13:14.799371Z[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-06T21:13:14.802251Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m3417604c86f94925 [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=[0m3417604c86f94925 [3mip[0m[2m=[0m1.1.1.1
[INFO] [stdout] [2m2026-10-06T21:13:14.802506Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m41d5f03b0c6d4a2e [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=[0m41d5f03b0c6d4a2e [3mip[0m[2m=[0m2.2.2.2
[INFO] [stdout] [2m2026-10-06T21:13:14.802718Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m2ad959e80cd9461a [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_biz_error[0m[2m:[0m 业务错误 [3mlocation[0m[2m=[0msrc/middleware/rate_limit.rs:168 [3mcode[0m[2m=[0m429 [3mmsg[0m[2m=[0m请求过于频繁，请稍后再试
[INFO] [stdout] [2m2026-10-06T21:13:14.802810Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m2ad959e80cd9461a [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=[0m2ad959e80cd9461a [3mip[0m[2m=[0m1.1.1.1
[INFO] [stdout] [2m2026-10-06T21:13:14.799486Z[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-06T21:13:14.803177Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m4ca62b2b290d4153 [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/protected[1m}[0m[2m:[0m [2mwordval_biz_error[0m[2m:[0m 业务错误 [3mlocation[0m[2m=[0msrc/middleware/auth.rs:315 [3mcode[0m[2m=[0m401 [3mmsg[0m[2m=[0m未授权访问，请先登录
[INFO] [stdout] [2m2026-10-06T21:13:14.803277Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m4ca62b2b290d4153 [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=[0m4ca62b2b290d4153 [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-06T21:13:14.799849Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 上传目录就绪 path=/tmp/wv_app_serve_1963/up max_size_mb=10
[INFO] [stdout] [2m2026-10-06T21:13:14.800005Z[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-06T21:13:14.804041Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 下载目录就绪 path=/tmp/wv_app_serve_1963/dn
[INFO] [stdout] [2m2026-10-06T21:13:14.804100Z[0m [32m INFO[0m [2mwordval_core::plugin[0m[2m:[0m 启动插件: dummy
[INFO] [stdout] [2m2026-10-06T21:13:14.804243Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m 全局路由前缀已启用: /v9
[INFO] [stdout] [2m2026-10-06T21:13:14.804281Z[0m [32m INFO[0m [2mwordval_web::policy[0m[2m:[0m 路由策略表: 已注册 1 条（公开 1 / 需登录 0）
[INFO] [stdout] [2m2026-10-06T21:13:14.804265Z[0m [33m WARN[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m236768170c224cdb [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-06T21:13:14.804308Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m236768170c224cdb [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/admin[1m}[0m[2m:[0m [2mwordval_biz_error[0m[2m:[0m 业务错误 [3mlocation[0m[2m=[0msrc/middleware/permission_check.rs:256 [3mcode[0m[2m=[0m403 [3mmsg[0m[2m=[0m无权限访问
[INFO] [stdout] [2m2026-10-06T21:13:14.804397Z[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-06T21:13:14.804388Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m236768170c224cdb [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=[0m236768170c224cdb [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-06T21:13:14.804434Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m Wordval 启动 -> http://127.0.0.1:36435
[INFO] [stdout] [2m2026-10-06T21:13:14.804450Z[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-06T21:13:14.804475Z[0m [32m INFO[0m [2mwordval_web::app[0m[2m:[0m Wordval 启动完成, 耗时 5ms
[INFO] [stdout] [2m2026-10-06T21:13:14.800462Z[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-06T21:13:14.801431Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m6ba27e3d5454400a [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=[0m6ba27e3d5454400a [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] [2m2026-10-06T21:13:14.806182Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0mde9380af09574f4d [3mmethod[0m[2m=[0mGET [3mpath[0m[2m=[0m/api/probe[1m}[0m[2m:[0m [2mwordval_biz_error[0m[2m:[0m 业务错误 [3mlocation[0m[2m=[0msrc/middleware/rate_limit.rs:168 [3mcode[0m[2m=[0m429 [3mmsg[0m[2m=[0m请求过于频繁，请稍后再试
[INFO] [stdout] [2m2026-10-06T21:13:14.806402Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0mde9380af09574f4d [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=[0mde9380af09574f4d [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] test app::tests::build_cors_layer_mirror_and_any_headers ... ok
[INFO] [stdout] [2m2026-10-06T21:13:14.801658Z[0m [32m INFO[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0m606d39f14aee4d0e [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=[0m606d39f14aee4d0e [3mip[0m[2m=[0m0.0.0.0
[INFO] [stdout] test app::tests::access_log_uses_resolved_client_ip ... ok
[INFO] [stdout] test app::tests::builder_route_group_merge_and_unknown_method ... ok
[INFO] [stdout] test app::tests::custom_middleware_inserted_by_priority ... ok
[INFO] [stdout] test app::tests::compression_enabled_and_request_log_excludes_path ... ok
[INFO] [stdout] test app::tests::build_cors_layer_list_credentials_max_age ... ok
[INFO] [stdout] test app::tests::parse_addr_variants ... ok
[INFO] [stdout] test app::tests::cors_preflight_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::resolve_display_addr_variants ... ok
[INFO] [stdout] test app::tests::rate_limit_uses_resolved_client_ip_from_trusted_proxy ... ok
[INFO] [stdout] test app::tests::short_circuit_401_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::short_circuit_403_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::short_circuit_401_is_recorded_in_access_log ... ok
[INFO] [stdout] test app::tests::short_circuit_429_has_request_id_and_security_headers ... ok
[INFO] [stdout] test app::tests::not_found_404_has_request_id_and_security_headers ... ok
[INFO] [stdout] test middleware::auth::tests::join_route_path_normalizes_prefix_and_path ... ok
[INFO] [stdout] test middleware::permission_check::tests::macro_rules_not_disabled_by_config_switch ... ok
[INFO] [stdout] test middleware::auth::tests::match_path_tail_wildcard ... ok
[INFO] [stdout] test middleware::permission_check::tests::prefix_joined_rules_match_final_path ... ok
[INFO] [stdout] test middleware::permission_check::tests::method_binding_respected ... ok
[INFO] [stdout] test middleware::permission_check::tests::macro_rule_wins_over_config_rule ... 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 middleware::auth::tests::match_path_normalizes_dot_segments ... ok
[INFO] [stdout] test app::tests::validate_middleware_config_auth_branch ... ok
[INFO] [stdout] [2m2026-10-06T21:13:14.809199Z[0m [32m INFO[0m [2mwordval_config[0m[2m:[0m 默认配置文件已生成到 /tmp/wv_gen_cfg_app_1963/config.toml
[INFO] [stdout] test policy::tests::distinct_routes_do_not_conflict ... ok
[INFO] [stdout] test chain::tests::same_priority_keeps_registration_order ... ok
[INFO] [stdout] test policy::tests::classify_auth_disabled_all_public ... ok
[INFO] [stdout] test middleware::auth::tests::match_path_exact_and_single_param_segment ... ok
[INFO] [stdout] test policy::tests::global_prefix_joined_into_policy_path ... ok
[INFO] [stdout] test policy::tests::same_route_same_permission_is_fine ... ok
[INFO] [stdout] test app::tests::start_gen_config_only_writes_default_file ... ok
[INFO] [stdout] test middleware::permission_check::tests::most_specific_rule_wins_within_same_source ... ok
[INFO] [stdout] test chain::tests::chain_applies_smaller_priority_outermost ... ok
[INFO] [stdout] test policy::tests::classify_pattern_rules_match_wildcard_paths ... ok
[INFO] [stdout] test policy::tests::no_auth_all_methods_overlaps_method_permission ... ok
[INFO] [stdout] test policy::tests::method_specific_no_auth_does_not_weaken_other_method ... ok
[INFO] [stdout] test policy::tests::duplicate_permission_with_different_perm_conflicts ... ok
[INFO] [stdout] test policy::tests::no_auth_and_permission_same_route_conflicts ... ok
[INFO] [stdout] test app::tests::validate_middleware_config_cors_rejects_and_accepts ... ok
[INFO] [stdout] test policy::tests::dormant_config_ignored_when_disabled ... ok
[INFO] [stdout] test policy::tests::config_rules_and_ignore_paths_included ... ok
[INFO] [stdout] [2m2026-10-06T21:13:14.901858Z[0m [33m WARN[0m [1mhttp_request[0m[1m{[0m[3mrequest_id[0m[2m=[0mf2998f4f14784369 [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] 
[INFO] [stdout] test result: ok. 43 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.11s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/middleware_contract.rs (/opt/rustwide/target/debug/deps/middleware_contract-aeb2c1e7772dc13a)
[INFO] [stderr]      Running tests/middleware_layers.rs (/opt/rustwide/target/debug/deps/middleware_layers-016e71886f3c6531)
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test is_admin_user_detects_flag_and_wildcards ... ok
[INFO] [stdout] test is_authorized_accepts_wildcard_permission ... ok
[INFO] [stdout] test is_authorized_accepts_exact_permission ... 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] [stdout] 
[INFO] [stdout] running 10 tests
[INFO] [stdout] test security_headers_respects_switches_and_bad_values ... ok
[INFO] [stdout] test request_id_regenerates_invalid_or_missing ... ok
[INFO] [stdout] test client_identity_without_trusted_ignores_proxy_headers ... ok
[INFO] [stdout] test rate_limit_blocks_over_quota_per_ip ... ok
[INFO] [stdout] test request_id_reuses_valid_inbound_header ... ok
[INFO] [stdout] test security_headers_defaults_inject_all ... ok
[INFO] [stdout] test client_identity_with_trusted_reads_xff ... ok
[INFO] [stdout] test request_log_passthrough_and_debug_mode_preserves_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. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.40s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/web_units.rs (/opt/rustwide/target/debug/deps/web_units-5e059c4d6b0c38fc)
[INFO] [stdout] 
[INFO] [stdout] running 15 tests
[INFO] [stdout] test tenant_header_config ... ok
[INFO] [stdout] test tenant_task_local_scope ... ok
[INFO] [stdout] test upload_download_path_singletons ... ok
[INFO] [stdout] test html_handler_serves_page ... ok
[INFO] [stdout] test router_all_methods ... ok
[INFO] [stdout] test validated_json_rejects_bad_json ... ok
[INFO] [stdout] test validated_validation_rules ... ok
[INFO] [stdout] test router_merge_nests_subroutes ... ok
[INFO] [stdout] test file_sender_blocks_traversal_and_missing ... ok
[INFO] [stdout] test router_default_and_unknown_method ... ok
[INFO] [stdout] test user_extractors_with_and_without_session ... ok
[INFO] [stdout] test resolve_tenant_rules ... ok
[INFO] [stdout] test tenant_context_layer_end_to_end ... ok
[INFO] [stdout] test validated_json_accepts_good_body ... ok
[INFO] [stdout] test file_sender_streams_file ... ok
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests wordval_web
[INFO] [stdout] test result: ok. 15 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 13 tests
[INFO] [stdout] test src/app.rs - app::App (line 52) ... ignored
[INFO] [stdout] test src/app.rs - app::App::group (line 236) ... ignored
[INFO] [stdout] test src/app.rs - app::App::middleware (line 443) ... ignored
[INFO] [stdout] test src/app.rs - app::App::new (line 88) ... ignored
[INFO] [stdout] test src/app.rs - app::App::on_startup (line 394) ... ignored
[INFO] [stdout] test src/app.rs - app::App::print_routes (line 294) ... ignored
[INFO] [stdout] test src/app.rs - app::App::route (line 215) ... ignored
[INFO] [stdout] test src/app.rs - app::App::scan (line 272) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_middleware_hook (line 418) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_permission (line 324) ... ignored
[INFO] [stdout] test src/app.rs - app::App::with_role (line 357) ... 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; 13 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae", kill_on_drop: false }`
[INFO] [stdout] 2dc4c0c0334ebcd4950c86cec4edbfad37c741c6c61327cfa9c55170054f71ae
