[INFO] fetching crate opcda-bridge-gateway 0.6.3...
[INFO] testing opcda-bridge-gateway-0.6.3 against 1.100.0-beta.1+cargoflags=--release for beta-release-1.100-2
[INFO] extracting crate opcda-bridge-gateway 0.6.3 into /workspace/builds/worker-4-tc2/source
[INFO] started tweaking crates.io crate opcda-bridge-gateway 0.6.3
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate opcda-bridge-gateway 0.6.3
[INFO] tweaked toml for crates.io crate opcda-bridge-gateway 0.6.3 written to /workspace/builds/worker-4-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate opcda-bridge-gateway 0.6.3 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 opcda-bridge-gateway 0.6.3 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] [stderr] warning: `package.homepage` is redundant with `package.repository`
[INFO] [stderr]    --> Cargo.toml:133:12
[INFO] [stderr]     |
[INFO] [stderr] 133 | homepage = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] ...
[INFO] [stderr] 138 | repository = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |              ------------------------------------------------
[INFO] [stderr]     |
[INFO] [stderr]     = note: `cargo::redundant_homepage` is set to `warn` by default
[INFO] [stderr] help: consider removing `package.homepage`
[INFO] [stderr] warning: `opcda-bridge-gateway` (manifest) generated 1 warning
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-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] 60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d
[INFO] running `Command { std: "docker" "start" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", 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" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d" "/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" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", 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" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr] warning: `package.homepage` is redundant with `package.repository`
[INFO] [stderr]    --> Cargo.toml:133:12
[INFO] [stderr]     |
[INFO] [stderr] 133 | homepage = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] ...
[INFO] [stderr] 138 | repository = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |              ------------------------------------------------
[INFO] [stderr]     |
[INFO] [stderr]     = note: `cargo::redundant_homepage` is set to `warn` by default
[INFO] [stderr] help: consider removing `package.homepage`
[INFO] [stderr] warning: `opcda-bridge-gateway` (manifest) generated 1 warning
[INFO] [stderr]    Compiling futures-core v0.3.33
[INFO] [stderr]    Compiling syn v2.0.119
[INFO] [stderr]    Compiling syn v3.0.3
[INFO] [stderr]    Compiling serde_core v1.0.229
[INFO] [stderr]    Compiling anyhow v1.0.104
[INFO] [stderr]    Compiling either v1.17.0
[INFO] [stderr]    Compiling mio v1.2.2
[INFO] [stderr]    Compiling futures-sink v0.3.33
[INFO] [stderr]    Compiling indexmap v2.14.0
[INFO] [stderr]    Compiling smallvec v1.15.2
[INFO] [stderr]    Compiling itertools v0.14.0
[INFO] [stderr]    Compiling bitflags v2.13.1
[INFO] [stderr]    Compiling libc v0.2.189
[INFO] [stderr]    Compiling pulldown-cmark v0.13.4
[INFO] [stderr]    Compiling prettyplease v0.2.37
[INFO] [stderr]    Compiling futures-task v0.3.33
[INFO] [stderr]    Compiling futures-util v0.3.33
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling getrandom v0.4.3
[INFO] [stderr]    Compiling foldhash v0.1.5
[INFO] [stderr]    Compiling memchr v2.8.3
[INFO] [stderr]    Compiling unicase v2.9.0
[INFO] [stderr]    Compiling regex-syntax v0.8.11
[INFO] [stderr]    Compiling cfg-if v1.0.4
[INFO] [stderr]    Compiling linux-raw-sys v0.12.1
[INFO] [stderr]    Compiling bytes v1.12.1
[INFO] [stderr]    Compiling hashbrown v0.15.5
[INFO] [stderr]    Compiling regex-automata v0.4.16
[INFO] [stderr]    Compiling futures-channel v0.3.33
[INFO] [stderr]    Compiling fastrand v2.5.0
[INFO] [stderr]    Compiling fixedbitset v0.5.7
[INFO] [stderr]    Compiling once_cell v1.21.4
[INFO] [stderr]    Compiling petgraph v0.8.3
[INFO] [stderr]    Compiling pulldown-cmark-to-cmark v22.0.0
[INFO] [stderr]    Compiling http-body-util v0.1.4
[INFO] [stderr]    Compiling multimap v0.10.1
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling log v0.4.33
[INFO] [stderr]    Compiling winnow v1.0.4
[INFO] [stderr]    Compiling cc v1.4.0
[INFO] [stderr]    Compiling tonic-build v0.14.6
[INFO] [stderr]    Compiling tokio-macros v2.7.2
[INFO] [stderr]    Compiling regex v1.13.1
[INFO] [stderr]    Compiling toml_parser v1.1.3+spec-1.1.0
[INFO] [stderr]    Compiling tokio v1.53.1
[INFO] [stderr]    Compiling serde_spanned v1.1.1
[INFO] [stderr]    Compiling toml_datetime v1.1.1+spec-1.1.0
[INFO] [stderr]    Compiling serde_derive v1.0.229
[INFO] [stderr]    Compiling axum-core v0.5.6
[INFO] [stderr]    Compiling crossbeam-utils v0.8.22
[INFO] [stderr]    Compiling toml_writer v1.1.2+spec-1.1.0
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling tracing-attributes v0.1.31
[INFO] [stderr]    Compiling prost-derive v0.14.4
[INFO] [stderr]    Compiling pin-project-internal v1.1.13
[INFO] [stderr]    Compiling libsqlite3-sys v0.35.0
[INFO] [stderr]    Compiling toml v1.1.4+spec-1.1.0
[INFO] [stderr]    Compiling pin-project v1.1.13
[INFO] [stderr]    Compiling async-trait v0.1.91
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling colorchoice v1.0.5
[INFO] [stderr]    Compiling thiserror v2.0.19
[INFO] [stderr]    Compiling prost v0.14.4
[INFO] [stderr]    Compiling anstream v1.0.0
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling prost-types v0.14.4
[INFO] [stderr]    Compiling serde_json v1.0.151
[INFO] [stderr]    Compiling thiserror-impl v2.0.19
[INFO] [stderr]    Compiling serde v1.0.229
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling thread_local v1.1.10
[INFO] [stderr]    Compiling prost-build v0.14.4
[INFO] [stderr]    Compiling clap_lex v1.1.0
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling time v0.3.54
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling tokio-util v0.7.19
[INFO] [stderr]    Compiling tonic-prost-build v0.14.6
[INFO] [stderr]    Compiling tokio-stream v0.1.19
[INFO] [stderr]    Compiling opcda-bridge-proto v0.6.0
[INFO] [stderr]    Compiling h2 v0.4.16
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling clap_builder v4.6.2
[INFO] [stderr]    Compiling axum v0.8.9
[INFO] [stderr]    Compiling crossbeam-channel v0.5.16
[INFO] [stderr]    Compiling hyper v1.11.0
[INFO] [stderr]    Compiling hashlink v0.10.0
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling clap_derive v4.6.4
[INFO] [stderr]    Compiling hyper-timeout v0.5.2
[INFO] [stderr]    Compiling tonic v0.14.6
[INFO] [stderr]    Compiling fallible-iterator v0.3.0
[INFO] [stderr]    Compiling fallible-streaming-iterator v0.1.9
[INFO] [stderr]    Compiling symlink v0.1.0
[INFO] [stderr]    Compiling tracing-appender v0.2.5
[INFO] [stderr]    Compiling chrono v0.4.45
[INFO] [stderr]    Compiling clap v4.6.4
[INFO] [stderr]    Compiling uuid v1.25.0
[INFO] [stderr]    Compiling tonic-prost v0.14.6
[INFO] [stderr]    Compiling rusqlite v0.37.0
[INFO] [stderr]    Compiling opcda-bridge-gateway v0.6.3 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 3m 28s
[INFO] running `Command { std: "docker" "inspect" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", 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" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d" "/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] warning: `package.homepage` is redundant with `package.repository`
[INFO] [stderr]    --> Cargo.toml:133:12
[INFO] [stderr]     |
[INFO] [stderr] 133 | homepage = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] ...
[INFO] [stderr] 138 | repository = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |              ------------------------------------------------
[INFO] [stderr]     |
[INFO] [stderr]     = note: `cargo::redundant_homepage` is set to `warn` by default
[INFO] [stderr] help: consider removing `package.homepage`
[INFO] [stderr] warning: `opcda-bridge-gateway` (manifest) generated 1 warning
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling regex-automata v0.4.16
[INFO] [stderr]    Compiling zerocopy v0.8.55
[INFO] [stderr]    Compiling rusqlite v0.37.0
[INFO] [stderr]    Compiling chrono v0.4.45
[INFO] [stderr]    Compiling wait-timeout v0.2.1
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling rusty-fork v0.3.1
[INFO] [stderr]    Compiling rand v0.9.5
[INFO] [stderr]    Compiling rand_xorshift v0.4.0
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling tracing-appender v0.2.5
[INFO] [stderr]    Compiling opcda-bridge-gateway v0.6.3 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling proptest v1.11.0
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 2m 15s
[INFO] running `Command { std: "docker" "inspect" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", 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" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr] warning: `package.homepage` is redundant with `package.repository`
[INFO] [stderr]    --> Cargo.toml:133:12
[INFO] [stderr]     |
[INFO] [stderr] 133 | homepage = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr] ...
[INFO] [stderr] 138 | repository = "https://github.com/bytehound-labs/opcda-bridge"
[INFO] [stderr]     |              ------------------------------------------------
[INFO] [stderr]     |
[INFO] [stderr]     = note: `cargo::redundant_homepage` is set to `warn` by default
[INFO] [stderr] help: consider removing `package.homepage`
[INFO] [stderr] warning: `opcda-bridge-gateway` (manifest) generated 1 warning
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.21s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/build/opcda-bridge-gateway/10a931d7e6218a14/out/opcda_bridge_gateway-10a931d7e6218a14)
[INFO] [stdout] 
[INFO] [stdout] running 389 tests
[INFO] [stdout] test browse::tests::explicit_close_releases_native_session ... ok
[INFO] [stdout] test browse::tests::expired_sessions_are_closed_before_the_next_request ... ok
[INFO] [stdout] test browse::tests::close_error_still_removes_gateway_session ... ok
[INFO] [stdout] test browse::tests::cache_hit_does_not_open_another_native_session ... ok
[INFO] [stdout] test browse::tests::local_mock_covers_all_opc_operations ... ok
[INFO] [stdout] test browse::tests::normalize_page_size_defaults_and_rejects_large_values ... ok
[INFO] [stdout] test browse::tests::expired_close_errors_are_logged_and_poisoned_sessions_are_safe ... ok
[INFO] [stdout] test browse::tests::opens_browse_session_and_translates_opaque_values ... ok
[INFO] [stdout] test browse::tests::page_token_is_bound_to_parent_and_page_size ... ok
[INFO] [stdout] test browse::tests::refresh_forces_a_new_native_page ... ok
[INFO] [stdout] test browse::tests::rejects_native_open_and_active_session_limit ... ok
[INFO] [stdout] test browse::tests::rejects_refresh_with_page_token_and_wrong_server_or_token ... ok
[INFO] [stdout] test browse::tests::temporary_browse_error_closes_its_session ... ok
[INFO] [stdout] test browse::tests::concurrent_close_reports_already_removed_session ... ok
[INFO] [stdout] test browse::tests::session_cache_and_bindings_evict_old_entries ... ok
[INFO] [stdout] test browse::tests::temporary_browse_error_logs_close_failure ... ok
[INFO] [stdout] test config::tests::test_cli_parses_config_flag ... ok
[INFO] [stdout] test config::tests::test_cli_flags_before_subcommand_apply_to_install ... ok
[INFO] [stdout] test config::tests::test_cli_defaults_to_none ... ok
[INFO] [stdout] test config::tests::test_cli_parses_log_flags ... ok
[INFO] [stdout] test config::tests::test_cli_rejects_unknown_subcommand ... ok
[INFO] [stdout] test config::tests::test_cli_version_flag ... ok
[INFO] [stdout] test config::tests::test_cli_parses_service_subcommands ... ok
[INFO] [stdout] test config::tests::test_config_path_from_exe_no_parent ... ok
[INFO] [stdout] test config::tests::test_config_path_from_exe_with_parent ... ok
[INFO] [stdout] test browse::tests::concurrent_identical_pages_share_the_in_flight_result ... ok
[INFO] [stdout] test config::tests::test_index_config_toml_round_trip ... ok
[INFO] [stdout] test config::tests::test_index_path_discovery_covers_platform_precedence ... ok
[INFO] [stdout] test config::tests::test_load_config_explicit_path_missing_errors ... ok
[INFO] [stdout] test config::tests::test_load_config_file_empty_is_all_defaults ... ok
[INFO] [stdout] test browse::tests::capacity_race_closes_the_extra_native_session ... ok
[INFO] [stdout] test config::tests::prop_malformed_gateway_toml_never_panics ... ok
[INFO] [stdout] test config::tests::test_cli_parses_port_flag ... ok
[INFO] [stdout] test config::tests::test_load_config_default_discovery ... ok
[INFO] [stdout] test config::tests::test_load_config_explicit_path ... ok
[INFO] [stdout] test config::tests::test_load_config_file_missing_not_error ... ok
[INFO] [stdout] test config::tests::test_load_config_file_generic_io_error ... ok
[INFO] [stdout] test config::tests::test_load_config_file_valid ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_applies_defaults_and_safe_bounds ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_clamps_commit_batch_and_interval_to_one ... ok
[INFO] [stdout] test config::tests::test_load_config_file_malformed ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_keeps_adaptive_thresholds_above_soft_limit ... ok
[INFO] [stdout] test config::tests::test_previous_gateway_config_fixture_remains_compatible ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_uses_weekly_safe_scheduler_defaults ... ok
[INFO] [stdout] test config::tests::test_resolve_port_cli_wins ... ok
[INFO] [stdout] test config::tests::test_load_config_file_missing_is_error ... ok
[INFO] [stdout] test config::tests::test_retired_index_switches_are_rejected ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_uses_legacy_batch_size_for_commit_batching ... ok
[INFO] [stdout] test controller::tests::clamps_native_batch_limits_to_the_upstream_ceiling ... ok
[INFO] [stdout] test controller::tests::foreground_latency_uses_explicit_soft_and_hard_limits ... ok
[INFO] [stdout] test controller::tests::foreground_work_pauses_without_consuming_health_backoff ... ok
[INFO] [stdout] test config::tests::test_resolve_port_default ... ok
[INFO] [stdout] test config::tests::test_unrelated_unknown_config_keys_remain_ignored ... ok
[INFO] [stdout] test config::tests::test_resolve_index_config_clamps_native_batch_sizes ... ok
[INFO] [stdout] test controller::tests::hard_and_soft_guardrails_map_to_typed_reasons ... ok
[INFO] [stdout] test config::tests::test_resolve_port_config_wins_over_default ... ok
[INFO] [stdout] test controller::tests::hard_guardrails_have_typed_priority_and_unavailable_metrics_are_ignored ... ok
[INFO] [stdout] test controller::tests::hard_pressure_pauses_and_recovers_at_canary ... ok
[INFO] [stdout] test controller::tests::hard_pressure_remains_paused_until_recovery_deadline ... ok
[INFO] [stdout] test controller::tests::normalizes_invalid_limits_without_panicking ... ok
[INFO] [stdout] test config::tests::prop_gateway_config_toml_round_trip ... ok
[INFO] [stdout] test controller::tests::database_pause_recovers_when_commit_pressure_clears ... ok
[INFO] [stdout] test controller::tests::preserves_unlimited_item_rate_when_adaptive_control_is_enabled ... ok
[INFO] [stdout] test controller::tests::soft_pressure_halves_limits_and_holds_them ... ok
[INFO] [stdout] test controller::tests::pause_reason_names_are_stable ... ok
[INFO] [stdout] test controller::tests::starts_at_the_canary_profile_and_increases_after_healthy_window ... ok
[INFO] [stdout] test controller::tests::reaching_the_ceiling_enters_the_steady_state ... ok
[INFO] [stdout] test controller::tests::unavailable_host_metrics_are_explicit ... ok
[INFO] [stdout] test index::tests::lifecycle::all_lifecycle_controls_reject_a_server_marked_for_deletion ... ok
[INFO] [stdout] test index::tests::lifecycle::an_automatic_probe_rechecks_opt_out_without_invalidating_the_cache ... ok
[INFO] [stdout] test index::tests::lifecycle::cancellation_persistence_failure_is_explicit_and_does_not_resume_automatic_work ... ok
[INFO] [stdout] test index::tests::lifecycle::cancellation_before_attachment_survives_obsolete_owner_completion ... ok
[INFO] [stdout] test index::tests::lifecycle::deletion_during_a_scheduler_probe_prevents_reenrollment ... ok
[INFO] [stdout] test browse::tests::rejects_inconsistent_native_pages_and_node_limit ... ok
[INFO] [stdout] test index::tests::lifecycle::disabling_auto_refresh_does_not_cancel_an_active_build ... ok
[INFO] [stdout] test index::tests::lifecycle::background_indexing_never_starts_an_unenrolled_server ... ok
[INFO] [stdout] test index::tests::lifecycle::genuine_failure_after_operator_cancel_preserves_the_later_deadline ... ok
[INFO] [stdout] test index::tests::lifecycle::idle_cancel_does_not_defer_a_completed_index ... ok
[INFO] [stdout] test index::tests::lifecycle::index_operation_errors_have_stable_messages_and_sources ... ok
[INFO] [stdout] test index::tests::lifecycle::cancellation_and_deletion_wait_helpers_cover_active_builds ... ok
[INFO] [stdout] test index::tests::lifecycle::malformed_cancellation_deadline_fails_closed ... ok
[INFO] [stdout] test index::tests::lifecycle::a_manual_first_build_stays_unscheduled ... ok
[INFO] [stdout] test index::tests::lifecycle::delete_index_reports_shutdown_when_background_task_cannot_start ... ok
[INFO] [stdout] test index::tests::lifecycle::lifecycle_controls_reject_unenrolled_servers ... ok
[INFO] [stdout] test index::tests::lifecycle::missing_index_cannot_be_opted_in_implicitly ... ok
[INFO] [stdout] test index::tests::lifecycle::auto_refresh_toggle_survives_restart_without_resetting_the_cache ... ok
[INFO] [stdout] test index::tests::lifecycle::new_index_auto_refresh_requires_explicit_opt_in ... ok
[INFO] [stdout] test index::tests::lifecycle::operator_cancel_rejects_an_overflowing_interval_before_cancelling ... ok
[INFO] [stdout] test index::tests::lifecycle::operator_cancellation_preserves_the_searchable_generation ... ok
[INFO] [stdout] test index::tests::lifecycle::profile_invalidation_preserves_a_newer_completed_generation ... ok
[INFO] [stdout] test index::tests::lifecycle::profile_rebuild_cannot_clear_another_owned_builds_active_cache ... ok
[INFO] [stdout] test index::tests::lifecycle::profile_rebuild_respects_server_preference_capacity_and_shutdown ... ok
[INFO] [stdout] test index::tests::lifecycle::refresh_rejects_a_server_marked_for_deletion ... ok
[INFO] [stdout] test index::tests::lifecycle::retry_state_snapshot_remains_locked_until_persisted ... ok
[INFO] [stdout] test index::tests::lifecycle::scheduler_recheck_fails_closed_when_a_persisted_deadline_becomes_invalid ... ok
[INFO] [stdout] test index::tests::lifecycle::split_delete_lock_returns_unheld_acquisition_errors ... ok
[INFO] [stdout] test index::tests::lifecycle::split_enrollment_guards_reject_conflicts_and_lock_errors ... ok
[INFO] [stdout] test index::tests::lifecycle::manager_reports_unenrolled_servers_without_scanning ... ok
[INFO] [stdout] test index::tests::lifecycle::duplicate_delete_is_rejected_while_cleanup_is_in_progress ... ok
[INFO] [stdout] test index::tests::lifecycle::stale_scheduler_work_cannot_reenroll_a_deleted_index ... ok
[INFO] [stdout] test index::tests::lifecycle::deletion_waits_for_an_external_build_lock ... ok
[INFO] [stdout] test index::tests::lifecycle::stale_profile_probe_does_not_rebuild_a_recreated_generation ... ok
[INFO] [stdout] test index::tests::lifecycle::manual_refresh_enrolls_only_listed_servers ... ok
[INFO] [stdout] test index::tests::query::indexed_query_normalization_is_idempotent ... ok
[INFO] [stdout] test index::tests::query::indexed_record_storage_round_trips_fields_and_breadcrumbs ... ok
[INFO] [stdout] test index::tests::query::exact_search_uses_ranked_equality_matches_without_duplicates ... ok
[INFO] [stdout] test index::tests::query::full_text_search_ranks_bounded_candidates_without_join_sort ... ok
[INFO] [stdout] test index::tests::lifecycle::automatic_refresh_runs_only_after_explicit_opt_in ... ok
[INFO] [stdout] test index::tests::query::memory_database_search_uses_primary_connection ... ok
[INFO] [stdout] test index::tests::query::normalization_and_timestamp_helpers_are_safe ... ok
[INFO] [stdout] test index::tests::query::poisoned_guards_and_empty_promoting_search_fail_safely ... ok
[INFO] [stdout] test index::tests::lifecycle::operator_cancel_defers_automatic_work_and_manual_refresh_overrides_it ... ok
[INFO] [stdout] test index::tests::query::indexed_search_during_promotion_does_not_wait_for_database_mutex ... ok
[INFO] [stdout] test index::tests::query::query_cache_evicts_oldest_and_clears_by_server ... ok
[INFO] [stdout] test index::tests::query::full_text_search_reports_missing_tables ... ok
[INFO] [stdout] test index::tests::query::indexed_search_preserves_match_tier_order ... ok
[INFO] [stdout] test index::tests::lifecycle::manual_refresh_preserves_the_explicit_auto_refresh_choice ... ok
[INFO] [stdout] test index::tests::query::manager_search_uses_cache_and_refresh_clears_it ... ok
[INFO] [stdout] test index::tests::query::prefix_search_uses_indexed_ranges_and_preserves_ranking ... ok
[INFO] [stdout] test index::tests::query::split_query_rejects_malformed_rows_and_handles_maximum_prefix ... ok
[INFO] [stdout] test index::tests::query::search_clamps_limit_and_reports_more_matches ... ok
[INFO] [stdout] test index::tests::query::profile_change_invalidates_persisted_generation_and_cached_search ... ok
[INFO] [stdout] test index::tests::query::search_discards_matches_if_deletion_starts_during_query ... ok
[INFO] [stdout] test index::tests::query::search_does_not_hold_database_lock_during_read_only_query ... ok
[INFO] [stdout] test index::tests::scheduler::background_indexing_starts_idempotently ... ok
[INFO] [stdout] test index::tests::query::search_does_not_return_stale_matches_while_deletion_is_active ... ok
[INFO] [stdout] test index::tests::query::stale_maintenance_delay_and_promotion_search_are_bounded ... ok
[INFO] [stdout] test index::tests::scheduler::background_indexing_continues_after_a_scheduled_server_query_failure ... ok
[INFO] [stdout] test index::tests::scheduler::auto_refresh_control_remains_available_during_cleanup_candidate_discovery ... ok
[INFO] [stdout] test index::tests::scheduler::background_indexing_does_not_start_first_build ... ok
[INFO] [stdout] test index::tests::scheduler::background_task_registry_rejects_work_when_its_state_lock_is_poisoned ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_is_exclusive_and_reusable ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_preserves_owner_details_for_open_conflicts ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_propagates_non_conflict_probe_errors ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_reports_initialization_and_cleanup_errors ... ok
[INFO] [stdout] test index::tests::query::exact_search_bounds_common_display_name_matches_with_equality_indexes ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_treats_open_conflicts_as_held ... ok
[INFO] [stdout] test index::tests::scheduler::background_refresh_delay_uses_persisted_state ... ok
[INFO] [stdout] test index::tests::scheduler::build_file_lock_reports_owner_and_probe_errors ... ok
[INFO] [stdout] test index::tests::scheduler::background_refresh_skips_a_fresh_persisted_generation ... ok
[INFO] [stdout] test index::tests::scheduler::background_task_registry_is_idempotent_and_rejects_new_work_after_shutdown ... ok
[INFO] [stdout] test index::tests::scheduler::build_reservation_hook_blocks_once_and_then_becomes_inert ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_checkpoint_defers_for_builds_and_tolerates_poisoned_locks ... ok
[INFO] [stdout] test index::tests::scheduler::background_refresh_rebuilds_a_stale_persisted_generation ... ok
[INFO] [stdout] test index::tests::scheduler::build_loop_records_inventory_shutdown_failure ... ok
[INFO] [stdout] test index::tests::scheduler::build_loop_keeps_build_failure_when_shutdown_also_fails ... ok
[INFO] [stdout] test index::tests::scheduler::build_ownership_is_held_until_inventory_stream_cleanup_finishes ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_deferral_log_fields_are_evaluated_when_enabled ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_error_paths_tolerate_database_and_registry_failures ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_notification_registration_closes_the_lost_wakeup_window ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_and_build_share_the_writer_gate_across_servers ... ok
[INFO] [stdout] test index::tests::scheduler::automatic_refresh_logs_reachable_invalidation_and_refresh_failures ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_first_build_waits_for_the_shared_writer_gate ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_on_one_manager_resumes_after_a_build_on_another_manager_finishes ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_rechecks_build_state_after_waiting_for_the_writer_gate ... ok
[INFO] [stdout] test index::tests::scheduler::database_coordination_key_handles_relative_and_unresolvable_paths ... ok
[INFO] [stdout] test index::tests::scheduler::database_coordination_reuses_the_same_identity_for_path_aliases ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_rechecks_obsolete_data_after_waiting_for_the_writer_gate ... ok
[INFO] [stdout] test index::tests::scheduler::deferred_cleanup_returns_when_no_build_is_active ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_stops_before_writing_when_shutdown_is_requested ... ok
[INFO] [stdout] test index::tests::scheduler::gateway_shutdown_interruption_preserves_retry_state_without_opening_circuit ... ok
[INFO] [stdout] test index::tests::scheduler::finish_build_handles_a_poisoned_build_owner_registry ... ok
[INFO] [stdout] test index::tests::scheduler::in_memory_databases_do_not_share_coordination ... ok
[INFO] [stdout] test index::tests::scheduler::maintenance_windows_parse_and_match_day_boundaries ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_stays_pending_while_any_build_is_active_and_resumes_after_termination ... ok
[INFO] [stdout] test index::tests::scheduler::deferred_cleanup_exits_when_shutdown_precedes_notification_subscription ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_stops_when_obsolete_data_disappears_before_batch_delete ... ok
[INFO] [stdout] test index::tests::scheduler::helper_edge_cases_cover_window_time_and_retry_rollback ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_retries_transient_failures ... ok
[INFO] [stdout] test index::tests::scheduler::refresh_rechecks_the_concurrency_limit_after_reservation ... ok
[INFO] [stdout] test index::tests::scheduler::refresh_cancels_inventory_when_shutdown_is_requested_after_start ... ok
[INFO] [stdout] test index::tests::scheduler::scheduled_cleanup_stops_cleanly_during_shutdown ... ok
[INFO] [stdout] test index::tests::scheduler::scheduled_refresh_jitter_is_deterministic_and_bounded ... ok
[INFO] [stdout] test index::tests::scheduler::refresh_cleans_up_when_background_spawn_is_rejected ... ok
[INFO] [stdout] test index::tests::scheduler::refresh_rejects_a_build_owner_registered_during_reservation ... ok
[INFO] [stdout] test index::tests::scheduler::retry_state_round_trips_through_index_meta ... ok
[INFO] [stdout] test index::tests::scheduler::refresh_start_failure_backs_off_until_forced_retry ... ok
[INFO] [stdout] test index::tests::scheduler::shutdown_drains_background_scheduler_and_build_tasks ... ok
[INFO] [stdout] test index::tests::scheduler::split_scheduler_shutdown_and_cleanup_short_circuits_are_safe ... ok
[INFO] [stdout] test index::tests::scheduler::scheduler_delay_covers_retry_terminal_and_maintenance_states ... ok
[INFO] [stdout] test index::tests::status::background_delay_and_refresh_handle_partial_status_errors_and_unconfigured_servers ... ok
[INFO] [stdout] test index::tests::status::controller_observation_expires_stale_commit_latency ... ok
[INFO] [stdout] test index::tests::status::controller_observation_includes_recent_bad_quality ... ok
[INFO] [stdout] test index::tests::scheduler::stale_and_adaptive_cancellation_scheduler_paths_are_covered ... ok
[INFO] [stdout] test index::tests::scheduler::scheduler_shutdown_quiet_resume_and_batch_commit_complete ... ok
[INFO] [stdout] test index::tests::status::foreground_bad_quality_expires_without_a_follow_up_operation ... ok
[INFO] [stdout] test index::tests::status::foreground_cleanup_without_a_runtime_build_is_safe ... ok
[INFO] [stdout] test index::tests::status::foreground_guard_resumes_synchronously_without_a_tokio_runtime ... ok
[INFO] [stdout] test index::tests::status::foreground_health_failures_expire_without_a_follow_up_operation ... ok
[INFO] [stdout] test index::tests::status::foreground_metrics_keep_rolling_latency_percentiles ... ok
[INFO] [stdout] test index::tests::scheduler::background_indexing_wakes_for_the_next_refresh_check ... ok
[INFO] [stdout] test index::tests::status::controls_foreground_quiet_period_and_concurrency_coordinate_builds ... ok
[INFO] [stdout] test index::tests::status::failed_background_delete_is_recorded_in_status ... ok
[INFO] [stdout] test index::tests::status::public_metric_and_invalid_maintenance_helpers_are_exercised ... ok
[INFO] [stdout] test index::tests::status::manager_status_covers_partial_stale_refreshing_and_runtime_errors ... ok
[INFO] [stdout] test index::tests::scheduler::cleanup_uses_a_separate_connection_without_blocking_primary_reads ... ok
[INFO] [stdout] test index::tests::status::pause_overlays_compose_and_are_visible_in_runtime_status ... ok
[INFO] [stdout] test index::tests::status::older_failed_generations_do_not_poison_active_status ... ok
[INFO] [stdout] test index::tests::status::refresh_pauses_for_existing_foreground_work_and_control_without_build_is_a_noop ... ok
[INFO] [stdout] test index::tests::status::reserving_a_new_build_clears_previous_commit_latency_timestamp ... ok
[INFO] [stdout] test index::tests::status::read_only_status_and_search_remain_responsive_while_writer_gate_is_held ... ok
[INFO] [stdout] test index::tests::scheduler::scheduled_cleanup_retries_after_worker_panic ... ok
[INFO] [stdout] test index::tests::status::split_status_reports_unenrolled_deletion_and_promotion_read_errors ... ok
[INFO] [stdout] test index::tests::status::storage_diagnostics_include_sqlite_sidecars ... ok
[INFO] [stdout] test index::tests::status::status_during_promotion_does_not_wait_for_database_mutex ... ok
[INFO] [stdout] test index::tests::status::restart_during_refresh_keeps_active_status_ready ... ok
[INFO] [stdout] test index::tests::status::status_promotion_read_failure_and_health_variants_are_safe ... ok
[INFO] [stdout] test index::tests::store::cleanup_precheck_avoids_a_write_when_no_obsolete_generation_exists ... ok
[INFO] [stdout] test index::tests::status::build_terminal_error_and_cancellation_paths_preserve_consistent_status ... ok
[INFO] [stdout] test index::tests::store::completed_inventory_profile_replaces_startup_capabilities ... ok
[INFO] [stdout] test index::tests::store::delete_index_removes_enrollment_generations_and_retry_metadata ... ok
[INFO] [stdout] test index::tests::store::existing_schema_four_defaults_do_not_opt_in_new_servers ... ok
[INFO] [stdout] test index::tests::store::active_profile_check_handles_missing_invalid_and_unavailable_data ... ok
[INFO] [stdout] test index::tests::store::failed_activation_keeps_the_previous_generation_active ... ok
[INFO] [stdout] test index::tests::scheduler::stalled_inventory_event_is_cancelled_and_releases_the_scheduler ... ok
[INFO] [stdout] test index::tests::store::generation_start_failure_is_recorded_and_reported ... ok
[INFO] [stdout] test index::tests::store::large_synthetic_generation_promotes_without_a_validation_scan ... ignored, production-scale regression: one million rows exercises activation without scans or cleanup
[INFO] [stdout] test index::tests::store::failed_attempt_and_enrollment_state_persist_through_index_db ... ok
[INFO] [stdout] test index::tests::store::first_database_write_schedules_cleanup_for_obsolete_generations ... ok
[INFO] [stdout] test index::tests::store::only_corrupt_or_incompatible_index_errors_are_quarantinable ... ok
[INFO] [stdout] test index::tests::store::abandoning_a_first_generation_preserves_its_failure_for_manual_retry ... ok
[INFO] [stdout] test index::tests::store::profile_compatibility_preserves_negotiated_da2_fallbacks ... ok
[INFO] [stdout] test index::tests::store::quarantine_errors_restore_moved_files_and_report_rollback_failures ... ok
[INFO] [stdout] test index::tests::store::genuine_da2_profile_triggers_da3_invalidation ... ok
[INFO] [stdout] test index::tests::store::negotiated_da2_profile_does_not_trigger_profile_invalidation ... ok
[INFO] [stdout] test index::tests::store::manager_promotes_success_and_rolls_back_failed_refresh ... ok
[INFO] [stdout] test index::tests::store::persisted_retry_circuit_state_blocks_restart_until_forced_refresh ... ok
[INFO] [stdout] test index::tests::store::cleanup_errors_do_not_change_a_successfully_activated_generation ... ok
[INFO] [stdout] test index::tests::store::refresh_discards_generation_when_runtime_build_disappears ... ok
[INFO] [stdout] test index::tests::store::refresh_discards_generation_when_shutdown_is_requested_before_spawn ... ok
[INFO] [stdout] test index::tests::store::activation_defers_superseded_data_to_bounded_cleanup ... ok
[INFO] [stdout] test index::tests::store::runtime_pacing_failure_fails_the_active_generation ... ok
[INFO] [stdout] test index::tests::store::schema_migration_rejects_an_invalid_server_value ... ok
[INFO] [stdout] test index::tests::store::restart_recovery_surfaces_staging_update_errors ... ok
[INFO] [stdout] test index::tests::store::sqlite_quarantine_preserves_database_and_sidecars_as_one_bundle ... ok
[INFO] [stdout] test index::tests::store::sqlite_sidecars_append_to_custom_database_names ... ok
[INFO] [stdout] test index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds ... FAILED
[INFO] [stdout] test index::tests::store::sqlite_generations_search_and_restart_cleanup_work ... ok
[INFO] [stdout] test index::tests::store::sqlite_migrates_schema_3_and_preserves_indexed_data ... ok
[INFO] [stdout] test index::tests::store::store_quarantine_logger_handles_no_files_to_move ... ok
[INFO] [stdout] test index::tests::traversal::accumulate_inventory_progress_handles_zero_active_time ... ok
[INFO] [stdout] test index::tests::store::active_profile_check_times_out_a_stalled_capability_probe ... ok
[INFO] [stdout] test index::tests::traversal::adaptive_limits_translate_to_native_operation_pacing ... ok
[INFO] [stdout] test index::tests::traversal::aggregate_inventory_progress_handles_zero_active_time ... ok
[INFO] [stdout] test index::tests::store::sqlite_open_preserves_staging_owned_by_a_live_build_lock ... ok
[INFO] [stdout] test index::tests::traversal::build_finalization_log_keeps_the_index_module_target_and_fields ... ok
[INFO] [stdout] test index::tests::store::sqlite_validation_failure_discard_and_clear_paths_work ... ok
[INFO] [stdout] test index::tests::store::sqlite_quarantines_inconsistent_full_text_data ... ok
[INFO] [stdout] test index::tests::traversal::build_readiness_failure_stops_the_loop_and_cancels_control ... ok
[INFO] [stdout] test index::tests::store::start_generation_stops_when_a_cancelled_control_loses_its_build ... ok
[INFO] [stdout] test index::tests::traversal::build_telemetry_aggregates_slices_entries_and_commits ... ok
[INFO] [stdout] test index::tests::traversal::build_telemetry_keeps_only_the_latest_commit_latency_samples ... ok
[INFO] [stdout] test index::tests::traversal::build_readiness_reports_controller_recovery_cancellation ... ok
[INFO] [stdout] test index::tests::store::store_open_reports_fts_corruption_and_preserves_a_live_staging_generation ... ok
[INFO] [stdout] test index::tests::traversal::attach_control_handles_pending_cancel_after_build_disappears ... ok
[INFO] [stdout] test index::tests::traversal::completion_event_shape_is_typed ... ok
[INFO] [stdout] test index::tests::traversal::commit_batching_flushes_thresholds_and_final_pending_entries ... ok
[INFO] [stdout] test index::tests::traversal::completed_inventory_warning_keeps_generation_active_and_searchable ... ok
[INFO] [stdout] test index::tests::traversal::configured_inventory_root_uses_root_scoped_start ... ok
[INFO] [stdout] test index::tests::traversal::configured_inventory_root_failure_is_cleanly_cancelled_when_pending ... ok
[INFO] [stdout] test index::tests::traversal::capability_cancellation_cleans_up_generation_start_boundaries ... ok
[INFO] [stdout] test index::tests::traversal::control_action_helpers_reconcile_resume_and_queue_cancel ... ok
[INFO] [stdout] test index::tests::traversal::configured_inventory_root_failure_is_fatal ... ok
[INFO] [stdout] test index::tests::traversal::build_stops_when_maintenance_health_or_rate_limit_control_is_cancelled ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_channel_close_reports_worker_failure_or_completion ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_control_handles_registration_and_pacing_edges ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_cancellation_stops_active_workers_and_joins_them ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_cancels_after_outer_entry_send_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_deduplicates_roots_and_aggregates_progress ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_detects_worker_task_panic ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_falls_back_when_root_page_has_too_few_workers ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_falls_back_without_safe_roots ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_forwards_control_to_all_root_workers ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_handles_closed_coordinator_senders ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_rejects_root_continuation_pages ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_reports_incomplete_worker_termination ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_reports_root_browse_close_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_reports_root_worker_start_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_reports_worker_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_reports_worker_registration_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_shutdown_panic_is_reported ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_inventory_suppresses_registration_error_after_stop_request ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_start_failure_falls_back_to_full_root_inventory ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_start_falls_back_when_partitioning_is_not_safe ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_stream_shutdown_reports_coordinator_join_failure ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_worker_handles_closed_event_senders ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_worker_handles_registration_cancellation_and_failures ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_worker_reports_a_poisoned_root_queue ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_worker_sender_failures_stop_and_clean_up_the_worker ... ok
[INFO] [stdout] test index::tests::traversal::coordinated_worker_stops_after_cancelled_root_start_failure ... ok
[INFO] [stdout] test index::tests::traversal::control_reports_a_poisoned_runtime_lock ... ok
[INFO] [stdout] test index::tests::traversal::eof_classification_fails_closed_when_runtime_lock_is_poisoned ... ok
[INFO] [stdout] test index::tests::traversal::controller_recovery_returns_false_for_an_already_cancelled_control ... ok
[INFO] [stdout] test index::tests::traversal::finish_build_checks_control_identity_without_an_ownership_token ... ok
[INFO] [stdout] test index::tests::traversal::finish_build_for_control_handles_current_obsolete_and_poisoned_runtime ... ok
[INFO] [stdout] test index::tests::traversal::build_reports_batch_progress_and_promotion_database_failures ... ok
[INFO] [stdout] test index::tests::traversal::in_memory_build_locks_are_not_file_backed ... ok
[INFO] [stdout] test index::tests::traversal::disk_guard_and_sentinel_health_paths_are_reported ... ok
[INFO] [stdout] test index::tests::traversal::lifecycle_client_reports_missing_root_inventory_fixture ... ok
[INFO] [stdout] test index::tests::traversal::health_wait_rechecks_after_a_delayed_probe_becomes_due ... ok
[INFO] [stdout] test index::tests::traversal::operator_cancelled_stream_eof_preserves_search_without_counting_failure ... ok
[INFO] [stdout] test index::tests::traversal::health_and_recovery_cancellation_edges_are_bounded ... ok
[INFO] [stdout] test index::tests::traversal::initial_pacing_failure_is_returned_and_recorded ... ok
[INFO] [stdout] test index::tests::traversal::paused_health_wait_and_runtime_poisoning_fail_closed ... ok
[INFO] [stdout] test index::tests::traversal::reconcile_pause_state_handles_a_build_without_a_control ... ok
[INFO] [stdout] test index::tests::traversal::promotion_uses_inventory_metadata_without_scanning_entries ... ok
[INFO] [stdout] test index::tests::traversal::rate_limiter_and_wait_helpers_honor_cancellation ... ok
[INFO] [stdout] test index::tests::traversal::adaptive_hard_pause_recovers_without_waiting_for_an_inventory_slice ... ok
[INFO] [stdout] test index::tests::traversal::refresh_capability_failure_cancels_inventory_and_records_error ... ok
[INFO] [stdout] test index::tests::traversal::refresh_database_failure_cancels_inventory_and_records_error ... ok
[INFO] [stdout] test index::tests::traversal::refresh_cancellation_covers_startup_failure_boundaries ... ok
[INFO] [stdout] test index::tests::traversal::refresh_honors_cancel_during_inventory_startup ... ok
[INFO] [stdout] test index::tests::traversal::refresh_rejects_a_duplicate_in_process_build_lock ... ok
[INFO] [stdout] test index::tests::traversal::slice_observations_feed_adaptive_controller_health_state ... ok
[INFO] [stdout] test index::tests::traversal::split_store_propagates_database_errors ... ok
[INFO] [stdout] test index::tests::traversal::split_traversal_handles_paused_state_and_missing_runtime ... ok
[INFO] [stdout] test index::tests::traversal::refresh_treats_cancelled_inventory_start_failure_as_noop ... ok
[INFO] [stdout] test index::tests::traversal::terminal_counts_distinguish_progress_snapshot_from_persisted_rows ... ok
[INFO] [stdout] test index::tests::traversal::terminal_counts_reconcile_entries_drained_before_stream_termination ... ok
[INFO] [stdout] test index::tests::traversal::sentinel_read_errors_are_reported_as_unhealthy ... ok
[INFO] [stdout] test index::tests::traversal::unexpected_stream_eof_preserves_search_and_counts_failure ... ok
[INFO] [stdout] test index::tests::traversal::startup_grace_and_manual_policy_prevent_automatic_first_builds ... ok
[INFO] [stdout] test logging::tests::test_build_env_filter_explicit_level ... ok
[INFO] [stdout] test logging::tests::test_build_env_filter_invalid_falls_back_to_info ... ok
[INFO] [stdout] test logging::tests::test_build_env_filter_none_defaults_to_info ... ok
[INFO] [stdout] test logging::tests::test_file_appender_daily_filename ... ok
[INFO] [stdout] test logging::tests::test_file_appender_hourly_filename ... ok
[INFO] [stdout] test logging::tests::test_file_appender_never_filename ... ok
[INFO] [stdout] test index::tests::store::sqlite_corruption_errors_propagate_from_each_persistence_operation ... ok
[INFO] [stdout] test logging::tests::test_init_tracing_with_stdout_covers_json_and_pretty_layers ... ok
[INFO] [stdout] test logging::tests::test_log_dir_from_exe_no_parent ... ok
[INFO] [stdout] test logging::tests::test_log_dir_from_exe_with_parent ... ok
[INFO] [stdout] test logging::tests::test_parse_log_format_json ... ok
[INFO] [stdout] test logging::tests::test_parse_log_format_none_defaults_to_pretty ... ok
[INFO] [stdout] test logging::tests::test_init_tracing_wrapper_detects_terminal ... ok
[INFO] [stdout] test logging::tests::test_parse_log_format_unknown_defaults_to_pretty ... ok
[INFO] [stdout] test logging::tests::test_parse_log_format_pretty ... ok
[INFO] [stdout] test logging::tests::test_parse_rotation_daily ... ok
[INFO] [stdout] test logging::tests::test_parse_rotation_hourly ... ok
[INFO] [stdout] test logging::tests::test_parse_rotation_never ... ok
[INFO] [stdout] test logging::tests::test_parse_rotation_unknown_defaults_to_daily ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.876009Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m skipped namespace index cleanup because no obsolete generations exist [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpypHkmO/unwind.sqlite3 [3mserver[0m[2m=[0m"S"
[INFO] [stdout] test logging::tests::test_parse_rotation_none_defaults_to_daily ... ok
[INFO] [stdout] test logging::tests::test_resolve_log_settings_cli_wins ... ok
[INFO] [stdout] test logging::tests::test_resolve_log_settings_defaults ... ok
[INFO] [stdout] test logging::tests::test_resolve_log_settings_config_wins_over_default ... ok
[INFO] [stdout] test opc::tests::inventory_control_is_not_cancelled_by_default ... ok
[INFO] [stdout] test opc::tests::opc_client_default_root_inventory_is_unsupported ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.883191Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.883253Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connecting to 127.0.0.1:39999
[INFO] [stdout] [2m2026-10-18T13:02:54.883397Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connected to 127.0.0.1:39999
[INFO] [stdout] [2m2026-10-18T13:02:54.883467Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m binding client connection
[INFO] [stdout] [2m2026-10-18T13:02:54.883545Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.883992Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m client connection bound
[INFO] [stdout] [2m2026-10-18T13:02:54.883992Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connecting to 127.0.0.1:33887
[INFO] [stdout] [2m2026-10-18T13:02:54.884008Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884081Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connected to 127.0.0.1:33887
[INFO] [stdout] [2m2026-10-18T13:02:54.884092Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m binding client connection
[INFO] [stdout] [2m2026-10-18T13:02:54.884118Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m client connection bound
[INFO] [stdout] [2m2026-10-18T13:02:54.884116Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884127Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884154Z[0m [34mDEBUG[0m [2mtower::buffer::worker[0m[2m:[0m [3mservice.ready[0m[2m=[0mtrue processing request
[INFO] [stdout] [2m2026-10-18T13:02:54.884172Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884186Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884212Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884222Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884232Z[0m [34mDEBUG[0m [2mtower::buffer::worker[0m[2m:[0m [3mservice.ready[0m[2m=[0mtrue processing request
[INFO] [stdout] [2m2026-10-18T13:02:54.884260Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884268Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884282Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884296Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884307Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884348Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884354Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884361Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884364Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884372Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884374Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884396Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884396Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884414Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884414Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884443Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884443Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884455Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884455Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884536Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884547Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884548Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884560Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884562Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884571Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884573Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884584Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884612Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884612Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884623Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884624Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884633Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884644Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884652Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884657Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884663Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884672Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884678Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884685Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884690Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884698Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884702Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884728Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884740Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884748Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884759Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.884778Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884778Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884790Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884820Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884831Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884842Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884865Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884879Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::proto::connection[0m[2m:[0m Connection::poll; connection error [3merror[0m[2m=[0mGoAway(b"", NO_ERROR, Library)
[INFO] [stdout] [2m2026-10-18T13:02:54.884958Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.884971Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.884982Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[INFO] [stdout] test run::tests::test_serve_accepts_requests_before_shutdown ... ok
[INFO] [stdout] test index::tests::traversal::unexpected_build_unwind_releases_ownership_and_resumes_cleanup ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.885473Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.885535Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connecting to 127.0.0.1:37485
[INFO] [stdout] test run::tests::test_serve_stops_accepting_new_connections_after_shutdown ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.885774Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::browse_rejects_invalid_page_size ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.886162Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.886198Z[0m [32m INFO[0m [1mbrowse[0m[2m:[0m [2mopcda_bridge_gateway::server::service[0m[2m:[0m browsed OPC DA page [3mserver[0m[2m=[0mS [3msession[0m[2m=[0md44b6a00-f9f5-495d-8f89-b3fbddde319c [3mcount[0m[2m=[0m0 [3mcomplete[0m[2m=[0mtrue
[INFO] [stdout] [2m2026-10-18T13:02:54.886225Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::browse_rejects_unknown_parent ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.886298Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.886384Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connecting to 127.0.0.1:34753
[INFO] [stdout] [2m2026-10-18T13:02:54.886401Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.886442Z[0m [32m INFO[0m [1mbrowse[0m[2m:[0m [2mopcda_bridge_gateway::server::service[0m[2m:[0m browsed OPC DA page [3mserver[0m[2m=[0mS [3msession[0m[2m=[0m689e2795-ae53-43c6-b1ba-51a3a3671b14 [3mcount[0m[2m=[0m0 [3mcomplete[0m[2m=[0mtrue
[INFO] [stdout] [2m2026-10-18T13:02:54.886466Z[0m [34mDEBUG[0m [2mhyper_util::client::legacy::connect::http[0m[2m:[0m connected to 127.0.0.1:34753
[INFO] [stdout] [2m2026-10-18T13:02:54.886482Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m binding client connection
[INFO] [stdout] [2m2026-10-18T13:02:54.886509Z[0m [34mDEBUG[0m [2mh2::client[0m[2m:[0m client connection bound
[INFO] [stdout] test server::service::tests::browse_returns_session_page_and_metadata ... ok[2m2026-10-18T13:02:54.886520Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] 
[INFO] [stdout] [2m2026-10-18T13:02:54.886583Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.886618Z[0m [34mDEBUG[0m [2mtower::buffer::worker[0m[2m:[0m [3mservice.ready[0m[2m=[0mtrue processing request
[INFO] [stdout] [2m2026-10-18T13:02:54.886637Z[0m [34mDEBUG[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.886666Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886711Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886724Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886807Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.886823Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886836Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[INFO] [stdout] [2m2026-10-18T13:02:54.886854Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886869Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886883Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886894Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.886971Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.886992Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887005Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887048Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.887063Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887074Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887086Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.887099Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mWindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
[INFO] [stdout] [2m2026-10-18T13:02:54.887115Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887129Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887145Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887201Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mSettings { flags: (0x1: ACK) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887218Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::proto::settings[0m[2m:[0m received settings ACK; applying Settings { flags: (0x0), initial_window_size: 1048576, max_frame_size: 16384, max_header_list_size: 16384 }
[INFO] [stdout] [2m2026-10-18T13:02:54.887240Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887254Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.887291Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(2147483647) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887307Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: false, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.887319Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.887345Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887361Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::proto::connection[0m[2m:[0m Connection::poll; connection error [3merror[0m[2m=[0mGoAway(b"", NO_ERROR, Library)
[INFO] [stdout] [2m2026-10-18T13:02:54.887449Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mPing { ack: true, payload: [11, 123, 162, 240, 139, 155, 254, 84] }
[INFO] [stdout] [2m2026-10-18T13:02:54.887466Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887478Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mGoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
[INFO] [stdout] [2m2026-10-18T13:02:54.887510Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.887543Z[0m [34mDEBUG[0m [1mget_capabilities[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3
[INFO] [stdout] test run::tests::test_serve_with_ready_signals_before_accepting_requests ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.887852Z[0m [32m INFO[0m [1mget_capabilities[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.888275Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.888304Z[0m [32m INFO[0m [1mbrowse[0m[2m:[0m [2mopcda_bridge_gateway::server::service[0m[2m:[0m browsed OPC DA page [3mserver[0m[2m=[0mS [3msession[0m[2m=[0mbfb77bf3-5c4e-4715-b1c2-c823c92d3ecb [3mcount[0m[2m=[0m0 [3mcomplete[0m[2m=[0mtrue
[INFO] [stdout] test server::service::tests::close_session_and_read_write_paths_work ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.888555Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::gateway_info_reports_generated_protocol_contract ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.889543Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.910488Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.911070Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m skipped namespace index cleanup because no obsolete generations exist [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-commit.sqlite3 [3mserver[0m[2m=[0m"S"
[INFO] [stdout] [2m2026-10-18T13:02:54.921500Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m committed namespace index entries [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mbatch_size[0m[2m=[0m1 [3minserted_count[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.921554Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build telemetry [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3moutcome[0m[2m=[0m"completed" [3merror[0m[2m=[0mNone [3mduration_ms[0m[2m=[0m10 [3mterminal_event_ms[0m[2m=[0mSome(10) [3mlast_progress_entries_seen[0m[2m=[0m0 [3mlast_progress_unique_items[0m[2m=[0m0 [3mpersisted_items[0m[2m=[0m1 [3mdrained_events[0m[2m=[0m3 [3mreceived_entry_events[0m[2m=[0m1 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mactive_time_ms[0m[2m=[0m0 [3mpaused_time_ms[0m[2m=[0m0 [3mprogress_events[0m[2m=[0m0 [3mslice_count[0m[2m=[0m1 [3mslice_nodes_returned[0m[2m=[0m1 [3mslice_native_operations[0m[2m=[0m1 [3mslice_elapsed_ms[0m[2m=[0m1 [3mslice_elapsed_max_ms[0m[2m=[0m1 [3mslice_entries_delta[0m[2m=[0m1 [3mslice_entries_delta_max[0m[2m=[0m1 [3mslice_unique_items_delta[0m[2m=[0m1 [3mda2_slices[0m[2m=[0m1 [3mda3_slices[0m[2m=[0m0 [3mitem_entries[0m[2m=[0m1 [3mbranch_and_item_entries[0m[2m=[0m0 [3mcommit_attempts[0m[2m=[0m1 [3mcommit_failures[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m1 [3mcommit_elapsed_ms[0m[2m=[0m6 [3mcommit_elapsed_max_ms[0m[2m=[0m6 [3mcommit_latency_p50_ms[0m[2m=[0mSome(6) [3mcommit_latency_p95_ms[0m[2m=[0mSome(6)
[INFO] [stdout] [2m2026-10-18T13:02:54.926732Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m activated namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mentry_count[0m[2m=[0m1 [3munique_item_count[0m[2m=[0m1 [3meffective_organization[0m[2m=[0m"hierarchical" [3meffective_source[0m[2m=[0m"da2" [3mwarning[0m[2m=[0m"" [3mactivation_duration_ms[0m[2m=[0m5
[INFO] [stdout] [2m2026-10-18T13:02:54.926765Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index generation promotion finished [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mpromotion_duration_ms[0m[2m=[0m5 [3msuccess[0m[2m=[0mtrue
[INFO] [stdout] [2m2026-10-18T13:02:54.926789Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build completed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/periodic-success.sqlite3 [3mserver[0m[2m=[0mS [3mgeneration[0m[2m=[0m1 [3mduration_ms[0m[2m=[0m16 [3mlast_progress_entries_seen[0m[2m=[0m0 [3mlast_progress_unique_items[0m[2m=[0m0 [3mpersisted_items[0m[2m=[0m1 [3mdrained_events[0m[2m=[0m3 [3mreceived_entry_events[0m[2m=[0m1 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.933028Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.933058Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.933082Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.945083Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/delayed.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.945115Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/delayed.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.945137Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/delayed.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.974689Z[0m [34mDEBUG[0m [1mget_capabilities[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.974754Z[0m [32m INFO[0m [1mget_capabilities[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3
[INFO] [stdout] test server::service::tests::capabilities_are_typed ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.976931Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.976988Z[0m [34mDEBUG[0m [1mget_search_index_status[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.977011Z[0m [32m INFO[0m [1mget_search_index_status[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:54.986066Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.986109Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.986126Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::codec::framed_write[0m[2m:[0m send [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] [2m2026-10-18T13:02:54.986200Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mServer[1m}[0m[2m:[0m [2mh2::proto::connection[0m[2m:[0m Connection::poll; connection error [3merror[0m[2m=[0mGoAway(b"", NO_ERROR, Library)
[INFO] [stdout] [2m2026-10-18T13:02:54.986327Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[INFO] [stdout] [2m2026-10-18T13:02:54.986346Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mData { stream_id: StreamId(1) }
[INFO] [stdout] [2m2026-10-18T13:02:54.986363Z[0m [34mDEBUG[0m [1mConnection[0m[1m{[0m[3mpeer[0m[2m=[0mClient[1m}[0m[2m:[0m [2mh2::codec::framed_read[0m[2m:[0m received [3mframe[0m[2m=[0mHeaders { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
[INFO] [stdout] test run::tests::test_serve_drains_in_flight_request_before_returning ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.986992Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.987056Z[0m [31mERROR[0m [1mget_capabilities[0m[2m:[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0mcapabilities failed
[INFO] [stdout] [2m2026-10-18T13:02:54.987085Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.987111Z[0m [31mERROR[0m [1mlist_servers[0m[2m:[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0mlist failed
[INFO] [stdout] [2m2026-10-18T13:02:54.987136Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.987160Z[0m [31mERROR[0m [1mread[0m[2m:[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0mread failed
[INFO] [stdout] [2m2026-10-18T13:02:54.987183Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.987207Z[0m [31mERROR[0m [1mwrite[0m[2m:[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0mwrite failed
[INFO] [stdout] [2m2026-10-18T13:02:54.987230Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.987260Z[0m [31mERROR[0m [1mbrowse[0m[2m:[0m [2mopcda_bridge_gateway::browse[0m[2m:[0m OPC browse operation failed [3merror[0m[2m=[0mopen failed
[INFO] [stdout] test server::service::tests::map_capabilities_clamps_page_size ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.991915Z[0m [31mERROR[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0mdatabase failed
[INFO] [stdout] test server::service::tests::maps_index_status_progress_matches_and_errors ... ok
[INFO] [stdout] test server::service::tests::maps_types_and_defaults ... ok
[INFO] [stdout] test server::service::tests::handlers_map_values_and_surface_client_errors ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.997509Z[0m [31mERROR[0m [2mopcda_bridge_gateway::server::map[0m[2m:[0m OPC operation failed [3merror[0m[2m=[0moperation failed
[INFO] [stdout] test server::service::tests::maps_wire_shapes_and_search_matching ... ok
[INFO] [stdout] [2m2026-10-18T13:02:54.998551Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.998603Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.998675Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.998720Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.998762Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:54.998800Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::search_matching_preserves_exact_item_ids ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.000520Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::search_rejects_invalid_query ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.001784Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.001863Z[0m [31mERROR[0m [2mopcda_bridge_gateway::browse[0m[2m:[0m OPC browse operation failed [3merror[0m[2m=[0mbrowse failed
[INFO] [stdout] [2m2026-10-18T13:02:55.001889Z[0m [31mERROR[0m [2mopcda_bridge_gateway::browse[0m[2m:[0m OPC browse operation failed [3merror[0m[2m=[0mclose failed
[INFO] [stdout] [2m2026-10-18T13:02:55.001901Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::server::search[0m[2m:[0m temporary search session was already closed [3merror[0m[2m=[0mcode: 'The service is currently unavailable', message: "close failed"
[INFO] [stdout] test server::service::tests::search_reports_browse_errors_and_close_errors ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.002513Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::search_stream_emits_progress_matches_and_completion ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.003547Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::search_stream_preserves_event_order_and_payloads ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.004403Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.004536Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.004577Z[0m [32m INFO[0m [1mbrowse[0m[2m:[0m [2mopcda_bridge_gateway::server::service[0m[2m:[0m browsed OPC DA page [3mserver[0m[2m=[0mS [3msession[0m[2m=[0mc106f58f-f9cd-4cd2-9e9b-7f18bed373d1 [3mcount[0m[2m=[0m1 [3mcomplete[0m[2m=[0mtrue
[INFO] [stdout] test server::service::tests::search_traverses_pages_scopes_and_deduplicates_items ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.004840Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/root/.local/share/opcda-bridge/index.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] test server::service::tests::search_truncates_at_result_limit_and_closes_temporary_session ... ok
[INFO] [stdout] test server::service::tests::typed_value_missing_is_invalid ... ok
[INFO] [stdout] test server::service::tests::validates_search_modes_and_limits ... ok
[INFO] [stdout] test service::tests::test_build_service_definition_carries_identity_and_arguments ... ok
[INFO] [stdout] test service::tests::test_is_scm_launch_error_code_matches_expected_code ... ok
[INFO] [stdout] test service::tests::test_is_scm_launch_error_code_rejects_other_codes ... ok
[INFO] [stdout] test service::tests::test_service_launch_arguments_empty_when_no_flags_set ... ok
[INFO] [stdout] test service::tests::test_service_launch_arguments_includes_every_set_flag ... ok
[INFO] [stdout] test service::tests::test_service_launch_arguments_partial_flags ... ok
[INFO] [stdout] test service::tests::test_service_lifecycle_sequence_order ... ok
[INFO] [stdout] test service::tests::test_service_lifecycle_stopped_is_terminal ... ok
[INFO] [stdout] test test_support::test_mock_inventory_stream_and_control ... ok
[INFO] [stdout] test test_support::test_mock_opc_client_default ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.035521Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.035794Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build telemetry [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3moutcome[0m[2m=[0m"completed" [3merror[0m[2m=[0mNone [3mduration_ms[0m[2m=[0m0 [3mterminal_event_ms[0m[2m=[0mSome(0) [3mlast_progress_entries_seen[0m[2m=[0m0 [3mlast_progress_unique_items[0m[2m=[0m0 [3mpersisted_items[0m[2m=[0m0 [3mdrained_events[0m[2m=[0m1 [3mreceived_entry_events[0m[2m=[0m0 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mactive_time_ms[0m[2m=[0m0 [3mpaused_time_ms[0m[2m=[0m0 [3mprogress_events[0m[2m=[0m0 [3mslice_count[0m[2m=[0m0 [3mslice_nodes_returned[0m[2m=[0m0 [3mslice_native_operations[0m[2m=[0m0 [3mslice_elapsed_ms[0m[2m=[0m0 [3mslice_elapsed_max_ms[0m[2m=[0m0 [3mslice_entries_delta[0m[2m=[0m0 [3mslice_entries_delta_max[0m[2m=[0m0 [3mslice_unique_items_delta[0m[2m=[0m0 [3mda2_slices[0m[2m=[0m0 [3mda3_slices[0m[2m=[0m0 [3mitem_entries[0m[2m=[0m0 [3mbranch_and_item_entries[0m[2m=[0m0 [3mcommit_attempts[0m[2m=[0m0 [3mcommit_failures[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m0 [3mcommit_elapsed_ms[0m[2m=[0m0 [3mcommit_elapsed_max_ms[0m[2m=[0m0 [3mcommit_latency_p50_ms[0m[2m=[0mNone [3mcommit_latency_p95_ms[0m[2m=[0mNone
[INFO] [stdout] [2m2026-10-18T13:02:55.035841Z[0m [31mERROR[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index database operation failed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3 [3mserver[0m[2m=[0mS [3mgeneration[0m[2m=[0m1 [3moperation[0m[2m=[0m"promote" [3merror[0m[2m=[0mindex promotion lock poisoned
[INFO] [stdout] [2m2026-10-18T13:02:55.041494Z[0m [33m WARN[0m [2mopcda_bridge_gateway::index[0m[2m:[0m marked namespace index generation failed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpCd5AmX/promotion-lock.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3merror[0m[2m=[0m"index promotion lock poisoned"
[INFO] [stdout] [2m2026-10-18T13:02:55.069727Z[0m [33m WARN[0m [2mopcda_bridge_gateway::index[0m[2m:[0m deferring namespace inventory [3mserver[0m[2m=[0mS [3mreason[0m[2m=[0mhealth probe exceeded 0 ms (3 ms)
[INFO] [stdout] test index::tests::traversal::controller_recovery_pacing_failure_is_returned ... ok
[INFO] [stdout] test index::tests::traversal::run_build_handles_promoting_lock_and_periodic_commit_failures ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.085490Z[0m [32m INFO[0m [1mrefresh_search_index[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index inventory [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mbatch_size[0m[2m=[0m256 [3mitem_rate_per_second[0m[2m=[0m0 [3mduty_cycle_percent[0m[2m=[0m100
[INFO] [stdout] [2m2026-10-18T13:02:55.088830Z[0m [34mDEBUG[0m [1mrefresh_search_index[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.089905Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m skipped namespace index cleanup because no obsolete generations exist [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S"
[INFO] [stdout] [2m2026-10-18T13:02:55.093856Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m updated namespace index progress [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mentries_seen[0m[2m=[0m1 [3munique_items[0m[2m=[0m1
[INFO] [stdout] test index::tests::traversal::controller_recovery_updates_runtime_after_a_pause ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.099824Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m committed namespace index entries [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mbatch_size[0m[2m=[0m1 [3minserted_count[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.099865Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build telemetry [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3moutcome[0m[2m=[0m"completed" [3merror[0m[2m=[0mNone [3mduration_ms[0m[2m=[0m10 [3mterminal_event_ms[0m[2m=[0mSome(4) [3mlast_progress_entries_seen[0m[2m=[0m1 [3mlast_progress_unique_items[0m[2m=[0m1 [3mpersisted_items[0m[2m=[0m1 [3mdrained_events[0m[2m=[0m3 [3mreceived_entry_events[0m[2m=[0m1 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mactive_time_ms[0m[2m=[0m1 [3mpaused_time_ms[0m[2m=[0m0 [3mprogress_events[0m[2m=[0m1 [3mslice_count[0m[2m=[0m0 [3mslice_nodes_returned[0m[2m=[0m0 [3mslice_native_operations[0m[2m=[0m0 [3mslice_elapsed_ms[0m[2m=[0m0 [3mslice_elapsed_max_ms[0m[2m=[0m0 [3mslice_entries_delta[0m[2m=[0m0 [3mslice_entries_delta_max[0m[2m=[0m0 [3mslice_unique_items_delta[0m[2m=[0m0 [3mda2_slices[0m[2m=[0m0 [3mda3_slices[0m[2m=[0m0 [3mitem_entries[0m[2m=[0m1 [3mbranch_and_item_entries[0m[2m=[0m0 [3mcommit_attempts[0m[2m=[0m1 [3mcommit_failures[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m1 [3mcommit_elapsed_ms[0m[2m=[0m5 [3mcommit_elapsed_max_ms[0m[2m=[0m5 [3mcommit_latency_p50_ms[0m[2m=[0mSome(5) [3mcommit_latency_p95_ms[0m[2m=[0mSome(5)
[INFO] [stdout] [2m2026-10-18T13:02:55.103504Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m activated namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mentry_count[0m[2m=[0m1 [3munique_item_count[0m[2m=[0m1 [3meffective_organization[0m[2m=[0m"hierarchical" [3meffective_source[0m[2m=[0m"da2" [3mwarning[0m[2m=[0m"" [3mactivation_duration_ms[0m[2m=[0m3
[INFO] [stdout] [2m2026-10-18T13:02:55.103537Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index generation promotion finished [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mpromotion_duration_ms[0m[2m=[0m3 [3msuccess[0m[2m=[0mtrue
[INFO] [stdout] [2m2026-10-18T13:02:55.103553Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build completed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0mS [3mgeneration[0m[2m=[0m1 [3mduration_ms[0m[2m=[0m14 [3mlast_progress_entries_seen[0m[2m=[0m1 [3mlast_progress_unique_items[0m[2m=[0m1 [3mpersisted_items[0m[2m=[0m1 [3mdrained_events[0m[2m=[0m3 [3mreceived_entry_events[0m[2m=[0m1 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.107266Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m skipped namespace index cleanup because no obsolete generations exist [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S"
[INFO] [stdout] [2m2026-10-18T13:02:55.107893Z[0m [34mDEBUG[0m [1msearch_index[0m[2m:[0m [2mopcda_bridge_gateway::index[0m[2m:[0m completed namespace index search [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpo50Mdg/index.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mmode[0m[2m=[0m3 [3mlimit[0m[2m=[0m10 [3mmatches[0m[2m=[0m1 [3mhas_more[0m[2m=[0mfalse [3mduration_ms[0m[2m=[0m0
[INFO] [stdout] test server::service::tests::search_handles_closed_streams_and_visit_limit ... ok
[INFO] [stdout] test server::service::tests::indexed_search_handlers_validate_map_and_execute_requests ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.171146Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/recovery.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.171180Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/recovery.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:55.171209Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpJAp0uS/recovery.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:55.235541Z[0m [33m WARN[0m [2mopcda_bridge_gateway::index[0m[2m:[0m deferring namespace inventory [3mserver[0m[2m=[0mS [3mreason[0m[2m=[0mhealth probe failed: temporary failure
[INFO] [stdout] test index::tests::traversal::unhealthy_probe_backs_off_and_stops_when_cancelled ... ok
[INFO] [stdout] [2m2026-10-18T13:02:55.486063Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m created namespace index manager [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mconcurrency[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.486099Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m initializing namespace index database handle [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:55.486130Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m opening namespace index database [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3
[INFO] [stdout] [2m2026-10-18T13:02:55.537491Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index inventory [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S" [3mbatch_size[0m[2m=[0m100 [3mitem_rate_per_second[0m[2m=[0m0 [3mduty_cycle_percent[0m[2m=[0m50
[INFO] [stdout] [2m2026-10-18T13:02:55.543506Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m started namespace index generation [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.544882Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m skipped namespace index cleanup because no obsolete generations exist [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S"
[INFO] [stdout] [2m2026-10-18T13:02:55.547474Z[0m [34mDEBUG[0m [2mopcda_bridge_gateway::index[0m[2m:[0m updated namespace index progress [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3mentries_seen[0m[2m=[0m1 [3munique_items[0m[2m=[0m1
[INFO] [stdout] [2m2026-10-18T13:02:55.547514Z[0m [32m INFO[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build telemetry [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3moutcome[0m[2m=[0m"failed" [3merror[0m[2m=[0mSome("inventory stream ended unexpectedly before completion") [3mduration_ms[0m[2m=[0m3 [3mterminal_event_ms[0m[2m=[0mNone [3mlast_progress_entries_seen[0m[2m=[0m1 [3mlast_progress_unique_items[0m[2m=[0m1 [3mpersisted_items[0m[2m=[0m0 [3mdrained_events[0m[2m=[0m1 [3mreceived_entry_events[0m[2m=[0m0 [3mpending_entries[0m[2m=[0m0 [3mpending_unique_items[0m[2m=[0m0 [3mactive_time_ms[0m[2m=[0m1 [3mpaused_time_ms[0m[2m=[0m0 [3mprogress_events[0m[2m=[0m1 [3mslice_count[0m[2m=[0m0 [3mslice_nodes_returned[0m[2m=[0m0 [3mslice_native_operations[0m[2m=[0m0 [3mslice_elapsed_ms[0m[2m=[0m0 [3mslice_elapsed_max_ms[0m[2m=[0m0 [3mslice_entries_delta[0m[2m=[0m0 [3mslice_entries_delta_max[0m[2m=[0m0 [3mslice_unique_items_delta[0m[2m=[0m0 [3mda2_slices[0m[2m=[0m0 [3mda3_slices[0m[2m=[0m0 [3mitem_entries[0m[2m=[0m0 [3mbranch_and_item_entries[0m[2m=[0m0 [3mcommit_attempts[0m[2m=[0m0 [3mcommit_failures[0m[2m=[0m0 [3mcommitted_entries[0m[2m=[0m0 [3mcommit_elapsed_ms[0m[2m=[0m0 [3mcommit_elapsed_max_ms[0m[2m=[0m0 [3mcommit_latency_p50_ms[0m[2m=[0mNone [3mcommit_latency_p95_ms[0m[2m=[0mNone
[INFO] [stdout] [2m2026-10-18T13:02:55.551488Z[0m [33m WARN[0m [2mopcda_bridge_gateway::index[0m[2m:[0m marked namespace index generation failed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0m"S" [3mgeneration[0m[2m=[0m1 [3merror[0m[2m=[0m"inventory stream ended unexpectedly before completion"
[INFO] [stdout] [2m2026-10-18T13:02:55.551518Z[0m [31mERROR[0m [2mopcda_bridge_gateway::index[0m[2m:[0m namespace index build failed [3mprocess_id[0m[2m=[0m2374 [3mdatabase[0m[2m=[0m/tmp/.tmpmSEqUr/duty-progress.sqlite3 [3mserver[0m[2m=[0mS [3mgeneration[0m[2m=[0m1 [3mduration_ms[0m[2m=[0m7 [3merror[0m[2m=[0minventory stream ended unexpectedly before completion
[INFO] [stdout] test index::tests::traversal::maintenance_duty_cycle_and_rate_limit_honor_pause_and_cancellation ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds' (2712) panicked at src/index/tests/store.rs:270:9:
[INFO] [stdout] assertion failed: result.is_err()
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5f35c401ce31 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5f35c4036bfa - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5f35c402277c - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5f35c3ff2876 - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5f35c4011e69 - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5f35c3c2d630 - test[aada8e7e76ba119b]::test_main_inner::{closure#0}
[INFO] [stdout]    6:     0x5f35c4012192 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5f35c3ff2954 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5f35c3feabb9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5f35c3ff3acd - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]   10:     0x5f35c403741c - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5f35c40373e2 - core[a373ad73a504971]::panicking::panic
[INFO] [stdout]   12:     0x5f35c3899b0d - opcda_bridge_gateway[a7096826f827fa54]::index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds
[INFO] [stdout]   13:     0x5f35c38bd529 - <opcda_bridge_gateway[a7096826f827fa54]::index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5f35c3c20a7b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   15:     0x5f35c3c2dc55 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5f35c3c27544 - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5f35c3c30ce2 - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5f35c401b9cf - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7c7e86dabdfa - <unknown>
[INFO] [stdout]   20:     0x7c7e86e3f3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     index::tests::store::sqlite_open_quarantines_invalid_schema_and_recovers_interrupted_builds
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 387 passed; 1 failed; 1 ignored; 0 measured; 0 filtered out; finished in 5.41s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d", kill_on_drop: false }`
[INFO] [stdout] 60f3c3a12e67676e9422db01fbe01babd51446abba416a2ff0b176bf187c475d
