[INFO] fetching crate cassadilia 0.4.3... [INFO] testing cassadilia-0.4.3 against master#c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38 for pr-146098-7 [INFO] extracting crate cassadilia 0.4.3 into /workspace/builds/worker-3-tc1/source [INFO] removed /workspace/builds/worker-3-tc1/source/.cargo/config.toml [INFO] started tweaking crates.io crate cassadilia 0.4.3 [INFO] finished tweaking crates.io crate cassadilia 0.4.3 [INFO] tweaked toml for crates.io crate cassadilia 0.4.3 written to /workspace/builds/worker-3-tc1/source/Cargo.toml [INFO] validating manifest of crates.io crate cassadilia 0.4.3 on toolchain c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] crate crates.io crate cassadilia 0.4.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" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 374c9aa6e5de66e5c836d37ea4835e87b38d153af0139089d28ced8f8a14b199 [INFO] running `Command { std: "docker" "start" "-a" "374c9aa6e5de66e5c836d37ea4835e87b38d153af0139089d28ced8f8a14b199", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "374c9aa6e5de66e5c836d37ea4835e87b38d153af0139089d28ced8f8a14b199", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "374c9aa6e5de66e5c836d37ea4835e87b38d153af0139089d28ced8f8a14b199", kill_on_drop: false }` [INFO] [stdout] 374c9aa6e5de66e5c836d37ea4835e87b38d153af0139089d28ced8f8a14b199 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 838574639a8b21001d68d329876455ba77d72997a04792cf4e843963b68e29bd [INFO] running `Command { std: "docker" "start" "-a" "838574639a8b21001d68d329876455ba77d72997a04792cf4e843963b68e29bd", kill_on_drop: false }` [INFO] [stderr] Compiling proc-macro2 v1.0.103 [INFO] [stderr] Compiling cc v1.2.43 [INFO] [stderr] Compiling memmap2 v0.9.9 [INFO] [stderr] Compiling ahash v0.8.12 [INFO] [stderr] Compiling parking_lot v0.12.5 [INFO] [stderr] Compiling tempfile v3.23.0 [INFO] [stderr] Compiling quote v1.0.41 [INFO] [stderr] Compiling syn v2.0.108 [INFO] [stderr] Compiling blake3 v1.8.2 [INFO] [stderr] Compiling thiserror-impl v2.0.17 [INFO] [stderr] Compiling tracing-attributes v0.1.30 [INFO] [stderr] Compiling serde_derive v1.0.228 [INFO] [stderr] Compiling thiserror v2.0.17 [INFO] [stderr] Compiling tracing v0.1.41 [INFO] [stderr] Compiling serde v1.0.228 [INFO] [stderr] Compiling cassadilia v0.4.3 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 14.13s [INFO] running `Command { std: "docker" "inspect" "838574639a8b21001d68d329876455ba77d72997a04792cf4e843963b68e29bd", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "838574639a8b21001d68d329876455ba77d72997a04792cf4e843963b68e29bd", kill_on_drop: false }` [INFO] [stdout] 838574639a8b21001d68d329876455ba77d72997a04792cf4e843963b68e29bd [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 0aca3304368e592b92cfb07fbd4665bb4d4ba1c27b906ee399b539bbbbbdc98c [INFO] running `Command { std: "docker" "start" "-a" "0aca3304368e592b92cfb07fbd4665bb4d4ba1c27b906ee399b539bbbbbdc98c", kill_on_drop: false }` [INFO] [stderr] Compiling cfg-if v1.0.4 [INFO] [stderr] Compiling once_cell v1.21.3 [INFO] [stderr] Compiling memchr v2.7.6 [INFO] [stderr] Compiling smallvec v1.15.1 [INFO] [stderr] Compiling libc v0.2.177 [INFO] [stderr] Compiling crossbeam-utils v0.8.21 [INFO] [stderr] Compiling serde_core v1.0.228 [INFO] [stderr] Compiling pin-project-lite v0.2.16 [INFO] [stderr] Compiling scopeguard v1.2.0 [INFO] [stderr] Compiling regex-syntax v0.8.8 [INFO] [stderr] Compiling gimli v0.32.3 [INFO] [stderr] Compiling linux-raw-sys v0.11.0 [INFO] [stderr] Compiling bitflags v2.10.0 [INFO] [stderr] Compiling adler2 v2.0.1 [INFO] [stderr] Compiling zerocopy v0.8.27 [INFO] [stderr] Compiling constant_time_eq v0.3.1 [INFO] [stderr] Compiling ryu v1.0.20 [INFO] [stderr] Compiling lock_api v0.4.14 [INFO] [stderr] Compiling lazy_static v1.5.0 [INFO] [stderr] Compiling itoa v1.0.15 [INFO] [stderr] Compiling fastrand v2.3.0 [INFO] [stderr] Compiling anyhow v1.0.100 [INFO] [stderr] Compiling miniz_oxide v0.8.9 [INFO] [stderr] Compiling arrayref v0.3.9 [INFO] [stderr] Compiling tracing-core v0.1.34 [INFO] [stderr] Compiling log v0.4.28 [INFO] [stderr] Compiling arrayvec v0.7.6 [INFO] [stderr] Compiling rustc-demangle v0.1.26 [INFO] [stderr] Compiling crossbeam-epoch v0.9.18 [INFO] [stderr] Compiling sharded-slab v0.1.7 [INFO] [stderr] Compiling thread_local v1.1.9 [INFO] [stderr] Compiling thiserror v2.0.17 [INFO] [stderr] Compiling bytes v1.10.1 [INFO] [stderr] Compiling nu-ansi-term v0.50.3 [INFO] [stderr] Compiling crossbeam-deque v0.8.6 [INFO] [stderr] Compiling rustix v1.1.2 [INFO] [stderr] Compiling tracing v0.1.41 [INFO] [stderr] Compiling tracing-log v0.2.0 [INFO] [stderr] Compiling object v0.37.3 [INFO] [stderr] Compiling rayon-core v1.13.0 [INFO] [stderr] Compiling hex v0.4.3 [INFO] [stderr] Compiling regex-automata v0.4.13 [INFO] [stderr] Compiling getrandom v0.3.4 [INFO] [stderr] Compiling parking_lot_core v0.9.12 [INFO] [stderr] Compiling memmap2 v0.9.9 [INFO] [stderr] Compiling parking_lot v0.12.5 [INFO] [stderr] Compiling blake3 v1.8.2 [INFO] [stderr] Compiling ahash v0.8.12 [INFO] [stderr] Compiling matchers v0.2.0 [INFO] [stderr] Compiling tracing-subscriber v0.3.20 [INFO] [stderr] Compiling tempfile v3.23.0 [INFO] [stderr] Compiling addr2line v0.25.1 [INFO] [stderr] Compiling serde v1.0.228 [INFO] [stderr] Compiling serde_json v1.0.145 [INFO] [stderr] Compiling cassadilia v0.4.3 (/opt/rustwide/workdir) [INFO] [stderr] Compiling backtrace v0.3.76 [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 29.24s [INFO] running `Command { std: "docker" "inspect" "0aca3304368e592b92cfb07fbd4665bb4d4ba1c27b906ee399b539bbbbbdc98c", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "0aca3304368e592b92cfb07fbd4665bb4d4ba1c27b906ee399b539bbbbbdc98c", kill_on_drop: false }` [INFO] [stdout] 0aca3304368e592b92cfb07fbd4665bb4d4ba1c27b906ee399b539bbbbbdc98c [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 484aafb152c4a9d1f0c49aa66be779f4b5a02bdb8326aaa4b01e2c9ed489c41f [INFO] running `Command { std: "docker" "start" "-a" "484aafb152c4a9d1f0c49aa66be779f4b5a02bdb8326aaa4b01e2c9ed489c41f", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.16s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/cassadilia-e043a4c10ef96033) [INFO] [stdout] [INFO] [stdout] running 68 tests [INFO] [stdout] test io::tests::same_fs_linux ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_empty ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_multiple_keys ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_last_version_none ... ok [INFO] [stdout] test serialization::tests::test_wal_op_invalid_data ... ok [INFO] [stdout] test serialization::tests::test_helper_functions ... ok [INFO] [stdout] test serialization::tests::test_helper_functions_errors ... ok [INFO] [stdout] test serialization::tests::test_wal_op_put_empty_key ... ok [INFO] [stdout] test serialization::tests::test_wal_op_put_large_key ... ok [INFO] [stdout] test serialization::tests::test_btreemap_invalid_data ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_single_empty_key ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_last_version_some ... ok [INFO] [stdout] test serialization::tests::test_wal_op_remove_mixed_keys ... ok [INFO] [stdout] test serialization::tests::test_wal_op_remove_single_empty_key ... ok [INFO] [stdout] 2025-11-11T09:01:56.387915Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.387978Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.388012Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpcAFqkM/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.388007Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp96CMQF/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.388127Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.388167Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.388200Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp96CMQF/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.388266Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.388292Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.388323Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpnGLUDJ/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.388416Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.388359Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmphmeRru/0_index.wal [INFO] [stdout] test serialization::tests::test_wal_op_remove_empty ... ok [INFO] [stdout] test index::tests::test_intent_guard_reference_counting_direct_state ... ok [INFO] [stdout] 2025-11-11T09:01:56.392552Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmphmeRru/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.392661Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.392748Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmprUgd3D/index' not found, starting fresh. State remains new. [INFO] [stdout] test index::tests::test_intent_guard_cleanup_direct_state ... ok [INFO] [stdout] 2025-11-11T09:01:56.392809Z  INFO cassadilia: Pre-creating CAS directory tree... [INFO] [stdout] 2025-11-11T09:01:56.392850Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.392870Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.392880Z  INFO cassadilia: Pre-creating CAS directory tree... [INFO] [stdout] 2025-11-11T09:01:56.392895Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmprUgd3D/0_index.wal [INFO] [stdout] test index::tests::test_index_read_guard_len ... ok [INFO] [stdout] 2025-11-11T09:01:56.392753Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.394707Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=6.575e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.394851Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmprUgd3D/staging/.tmpIqxDft' [INFO] [stdout] 2025-11-11T09:01:56.394920Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-11-11T09:01:56.396171Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test settings::tests::test_future_version_rejected ... ok [INFO] [stdout] test settings::tests::test_past_version_rejected ... ok [INFO] [stdout] 2025-11-11T09:01:56.398254Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpLJjlg5/index' not found, starting fresh. State remains new. [INFO] [stdout] test index::tests::test_intent_guard_multiple_intents_same_key_direct_state ... ok [INFO] [stdout] 2025-11-11T09:01:56.398422Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8IqWyU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.397984Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cd5d9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 key="key1" [INFO] [stdout] 2025-11-11T09:01:56.396562Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpu6DUC5/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.397578Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpQA2FZT/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.398632Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.398652Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.398678Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp8IqWyU/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.398731Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpL45gzQ/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.399551Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.399579Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.399592Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.399605Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpLJjlg5/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.399616Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.399645Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpu6DUC5/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.398081Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpeqjczG/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.399739Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.399766Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.399794Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpL45gzQ/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.399716Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.399914Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.399992Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpQA2FZT/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.399863Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.400169Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.400238Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpeqjczG/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.408606Z DEBUG cassadilia::cas_manager: Moved blob cd5d9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 to CAS path '/tmp/.tmprUgd3D/cas/cd/5d/9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340' [INFO] [stdout] 2025-11-11T09:01:56.408849Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmprUgd3D/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.408992Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.409213Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=9.9449e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.409366Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=6.104e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.409213Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.000101509 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.410190Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0010446 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.410300Z DEBUG cassadilia::transaction: Starting transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' using staging file '/tmp/.tmpLJjlg5/staging/.tmpGBfNcc' [INFO] [stdout] 2025-11-11T09:01:56.410340Z DEBUG cassadilia::transaction: Finishing transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' [INFO] [stdout] 2025-11-11T09:01:56.410904Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=6.725e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.411024Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpQA2FZT/staging/.tmp2EJSnb' [INFO] [stdout] 2025-11-11T09:01:56.411058Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-11-11T09:01:56.411083Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8IqWyU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.411086Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpA3njDV/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.411148Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00038064 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.411200Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8IqWyU/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.411202Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.411225Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.411228Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.411251Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp8IqWyU/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.411257Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpA3njDV/0_index.wal [INFO] [stdout] test index::tests::test_intent_guard_commit_removes_intent ... ok [INFO] [stdout] 2025-11-11T09:01:56.411792Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp8IqWyU/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.411847Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.411800Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpeqjczG/staging/.tmp9EmjGt' [INFO] [stdout] 2025-11-11T09:01:56.411865Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-11-11T09:01:56.411883Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-11-11T09:01:56.411949Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.374e-5 total_blobs=0 [INFO] [stdout] test io::tests::file_lock ... ok [INFO] [stdout] 2025-11-11T09:01:56.412340Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp6sbVOa/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.412430Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.412447Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.412469Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp6sbVOa/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.412526Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 key=[115, 97, 109, 101, 32, 107, 101, 121] [INFO] [stdout] test settings::tests::test_immutable_settings_validation ... ok [INFO] [stdout] 2025-11-11T09:01:56.412792Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmprUgd3D/staging/.tmpApxHf7' [INFO] [stdout] 2025-11-11T09:01:56.412829Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-11-11T09:01:56.413821Z DEBUG cassadilia::cas_manager: Moved blob 2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 to CAS path '/tmp/.tmpLJjlg5/cas/2b/80/d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50' [INFO] [stdout] 2025-11-11T09:01:56.413902Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpLJjlg5/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.413947Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.414497Z DEBUG cassadilia::transaction: Committing transaction blob_hash=8b238f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f key="key00" [INFO] [stdout] 2025-11-11T09:01:56.414588Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e5c858cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c key="key00" [INFO] [stdout] 2025-11-11T09:01:56.414730Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00022233 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.414901Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpA3njDV/staging/.tmpLAFEhK' [INFO] [stdout] 2025-11-11T09:01:56.415026Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-11-11T09:01:56.415781Z DEBUG cassadilia::cas_manager: Moved blob e5c858cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c to CAS path '/tmp/.tmpeqjczG/cas/e5/c8/58cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c' [INFO] [stdout] 2025-11-11T09:01:56.416128Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpeqjczG/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.416343Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=8.08e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.416483Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.416346Z DEBUG cassadilia::cas_manager: Moved blob 8b238f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f to CAS path '/tmp/.tmpQA2FZT/cas/8b/23/8f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f' [INFO] [stdout] 2025-11-11T09:01:56.416605Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpQA2FZT/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.416655Z DEBUG cassadilia::transaction: Committing transaction blob_hash=284be493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee key="key1" [INFO] [stdout] 2025-11-11T09:01:56.416806Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.417113Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmp6sbVOa/staging/.tmpyDTDNG' [INFO] [stdout] 2025-11-11T09:01:56.417149Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-11-11T09:01:56.417211Z DEBUG cassadilia::transaction: Starting transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' using staging file '/tmp/.tmpLJjlg5/staging/.tmppWGT7k' [INFO] [stdout] 2025-11-11T09:01:56.417655Z DEBUG cassadilia::transaction: Finishing transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' [INFO] [stdout] 2025-11-11T09:01:56.417665Z DEBUG cassadilia::transaction: Committing transaction blob_hash=3e21a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359 key="key00" [INFO] [stdout] 2025-11-11T09:01:56.417561Z DEBUG cassadilia::cas_manager: Moved blob 284be493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee to CAS path '/tmp/.tmprUgd3D/cas/28/4b/e493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee' [INFO] [stdout] 2025-11-11T09:01:56.418550Z DEBUG cassadilia::cas_manager: Moved blob 3e21a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359 to CAS path '/tmp/.tmpA3njDV/cas/3e/21/a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359' [INFO] [stdout] 2025-11-11T09:01:56.418592Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpA3njDV/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.418614Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.418932Z DEBUG cassadilia::transaction: Committing transaction blob_hash=a739eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0 key="key00" [INFO] [stdout] 2025-11-11T09:01:56.419873Z DEBUG cassadilia::cas_manager: Moved blob a739eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0 to CAS path '/tmp/.tmp6sbVOa/cas/a7/39/eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0' [INFO] [stdout] 2025-11-11T09:01:56.419976Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp6sbVOa/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.420072Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.421058Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpQA2FZT/staging/.tmpMUu0c2' [INFO] [stdout] 2025-11-11T09:01:56.421061Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmprUgd3D/cas/cd/5d/9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 [INFO] [stdout] 2025-11-11T09:01:56.421106Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-11-11T09:01:56.421147Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.421182Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.421245Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpeqjczG/staging/.tmp2Evqjr' [INFO] [stdout] 2025-11-11T09:01:56.421275Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-11-11T09:01:56.421696Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpA3njDV/staging/.tmpTq7LMp' [INFO] [stdout] 2025-11-11T09:01:56.421735Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-11-11T09:01:56.422198Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 key=[115, 97, 109, 101, 32, 107, 101, 121] [INFO] [stdout] 2025-11-11T09:01:56.422454Z DEBUG cassadilia::cas_manager: Moved blob 2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 to CAS path '/tmp/.tmpLJjlg5/cas/2b/80/d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50' [INFO] [stdout] 2025-11-11T09:01:56.422865Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7daf4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca key="key01" [INFO] [stdout] 2025-11-11T09:01:56.422952Z DEBUG cassadilia::transaction: Committing transaction blob_hash=58549030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c key="key01" [INFO] [stdout] 2025-11-11T09:01:56.426391Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmprUgd3D/index' [INFO] [stdout] 2025-11-11T09:01:56.426433Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.426617Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmprUgd3D/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.426658Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.426694Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.426708Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.426706Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmppleuZB/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.426773Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.427215Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmp6sbVOa/staging/.tmpTWXaGz' [INFO] [stdout] 2025-11-11T09:01:56.427385Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-11-11T09:01:56.427663Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmprUgd3D/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.427825Z DEBUG cassadilia::cas_manager: Moved blob 58549030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c to CAS path '/tmp/.tmpQA2FZT/cas/58/54/9030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c' [INFO] [stdout] 2025-11-11T09:01:56.427906Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmprUgd3D/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.427929Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=2 [INFO] [stdout] 2025-11-11T09:01:56.427942Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmprUgd3D/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.427929Z DEBUG cassadilia::cas_manager: Moved blob 7daf4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca to CAS path '/tmp/.tmpeqjczG/cas/7d/af/4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca' [INFO] [stdout] 2025-11-11T09:01:56.427998Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmprUgd3D/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.428007Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpoVCEw2/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.428021Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.428046Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=2 [INFO] [stdout] 2025-11-11T09:01:56.428109Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.428130Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.428172Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpoVCEw2/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.427758Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e5a89c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21 key="key01" [INFO] [stdout] 2025-11-11T09:01:56.428329Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpYlLea7/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.428434Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpo25iWV/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.430917Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8IqWyU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.431239Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.431277Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.431306Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmppleuZB/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.431715Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.431747Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.431771Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpo25iWV/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.431914Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8IqWyU/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.432225Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.432243Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp8IqWyU/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.432279Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp8IqWyU/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.432310Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.432330Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-11-11T09:01:56.432432Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=5.255e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.432554Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmp8IqWyU/staging/.tmpScg7nh' [INFO] [stdout] 2025-11-11T09:01:56.432583Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-11-11T09:01:56.432610Z DEBUG cassadilia::cas_manager: Moved blob e5a89c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21 to CAS path '/tmp/.tmpA3njDV/cas/e5/a8/9c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21' [INFO] [stdout] 2025-11-11T09:01:56.432770Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.432849Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.432882Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.432909Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpYlLea7/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.433113Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 key="key01" [INFO] [stdout] 2025-11-11T09:01:56.437405Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00427024 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.437452Z DEBUG cassadilia::cas_manager: Moved blob 7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 to CAS path '/tmp/.tmp6sbVOa/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676' [INFO] [stdout] 2025-11-11T09:01:56.437673Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpeqjczG/staging/.tmpcHo9TM' [INFO] [stdout] 2025-11-11T09:01:56.437798Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-11-11T09:01:56.437762Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpQA2FZT/staging/.tmpXbDLnB' [INFO] [stdout] 2025-11-11T09:01:56.437924Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-11-11T09:01:56.438234Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=7.5069e-5 total_blobs=0 [INFO] [stdout] test tests::test_api_on_nonexistent_key ... 2025-11-11T09:01:56.437920Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=5.102e-5 total_blobs=0 [INFO] [stdout] ok [INFO] [stdout] test tests::checkpoint::test_overwrite_deletes_old_blob_no_orphans ... ok [INFO] [stdout] 2025-11-11T09:01:56.437964Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpA3njDV/staging/.tmpEDpjvD' [INFO] [stdout] 2025-11-11T09:01:56.438368Z DEBUG cassadilia::transaction: Starting transaction for key '"range_blob"' using staging file '/tmp/.tmpo25iWV/staging/.tmpqoBwei' [INFO] [stdout] 2025-11-11T09:01:56.438538Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-11-11T09:01:56.438554Z DEBUG cassadilia::transaction: Finishing transaction for key '"range_blob"' [INFO] [stdout] 2025-11-11T09:01:56.442200Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpWsbLJI/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.442228Z DEBUG cassadilia::transaction: Committing transaction blob_hash=549969c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a key="key02" [INFO] [stdout] 2025-11-11T09:01:56.442332Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpYlLea7/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.442377Z DEBUG cassadilia::transaction: Committing transaction blob_hash=51cd9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e key="key02" [INFO] [stdout] 2025-11-11T09:01:56.444405Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00018906 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.444668Z DEBUG cassadilia::cas_manager: Moved blob 51cd9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e to CAS path '/tmp/.tmpeqjczG/cas/51/cd/9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e' [INFO] [stdout] 2025-11-11T09:01:56.445331Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.445366Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.445377Z DEBUG cassadilia::cas_manager: Moved blob 549969c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a to CAS path '/tmp/.tmpQA2FZT/cas/54/99/69c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a' [INFO] [stdout] 2025-11-11T09:01:56.444419Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpYlLea7/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.445469Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.445487Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpYlLea7/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.445525Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpYlLea7/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.445555Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.445568Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-11-11T09:01:56.445401Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpWsbLJI/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.445687Z DEBUG cassadilia::transaction: Committing transaction blob_hash=9238706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195 key="key02" [INFO] [stdout] 2025-11-11T09:01:56.445706Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b8f6b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0 key="range_blob" [INFO] [stdout] 2025-11-11T09:01:56.447474Z DEBUG cassadilia::transaction: Committing transaction blob_hash=c4986a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574 key="key00" [INFO] [stdout] 2025-11-11T09:01:56.444416Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmp6sbVOa/staging/.tmprOBmu5' [INFO] [stdout] 2025-11-11T09:01:56.448451Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-11-11T09:01:56.448481Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmppleuZB/staging/.tmpVmEmyg' [INFO] [stdout] 2025-11-11T09:01:56.448509Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-11-11T09:01:56.448631Z DEBUG cassadilia::cas_manager: Moved blob 9238706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195 to CAS path '/tmp/.tmpA3njDV/cas/92/38/706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195' [INFO] [stdout] 2025-11-11T09:01:56.449537Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpD4vqRb/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.449648Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.449677Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.449703Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpD4vqRb/0_index.wal [INFO] [stdout] test tests::test_cleanup_disabled ... ok [INFO] [stdout] 2025-11-11T09:01:56.449839Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpSDgzDV/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.449926Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.449942Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.449966Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpSDgzDV/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.449983Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.450008Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.450222Z DEBUG cassadilia::cas_manager: Moved blob c4986a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574 to CAS path '/tmp/.tmp8IqWyU/cas/c4/98/6a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574' [INFO] [stdout] 2025-11-11T09:01:56.450274Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp8IqWyU/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.450312Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.453354Z DEBUG cassadilia::cas_manager: Moved blob b8f6b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0 to CAS path '/tmp/.tmpo25iWV/cas/b8/f6/b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0' [INFO] [stdout] 2025-11-11T09:01:56.453413Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpo25iWV/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.453423Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpW8GPwv/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.453444Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.453424Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmpeqjczG/staging/.tmpei4291' [INFO] [stdout] 2025-11-11T09:01:56.453475Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] 2025-11-11T09:01:56.453522Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.453547Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.453572Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpW8GPwv/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.453670Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpez5BJc/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.453777Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.453799Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.453826Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpez5BJc/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.455000Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0048565 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.455023Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f362faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472 key="key1" [INFO] [stdout] 2025-11-11T09:01:56.457397Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmpA3njDV/staging/.tmpb3p6qL' [INFO] [stdout] 2025-11-11T09:01:56.457460Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] 2025-11-11T09:01:56.458283Z DEBUG cassadilia::cas_manager: Moved blob f362faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472 to CAS path '/tmp/.tmppleuZB/cas/f3/62/faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472' [INFO] [stdout] 2025-11-11T09:01:56.458347Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmppleuZB/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.458380Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.458422Z DEBUG cassadilia::transaction: Starting transaction for key '"valid_key1"' using staging file '/tmp/.tmpWsbLJI/staging/.tmpFcGuyJ' [INFO] [stdout] 2025-11-11T09:01:56.458452Z DEBUG cassadilia::transaction: Finishing transaction for key '"valid_key1"' [INFO] [stdout] 2025-11-11T09:01:56.458869Z DEBUG cassadilia::transaction: Committing transaction blob_hash=992adda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157 key="key03" [INFO] [stdout] 2025-11-11T09:01:56.458914Z DEBUG cassadilia::transaction: Committing transaction blob_hash=409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f key="key02" [INFO] [stdout] 2025-11-11T09:01:56.459102Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.461638Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00276603 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.461640Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpQA2FZT/index' [INFO] [stdout] 2025-11-11T09:01:56.461701Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.461704Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.461805Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpQA2FZT/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.461835Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.461847Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=3 [INFO] [stdout] 2025-11-11T09:01:56.461859Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-11-11T09:01:56.461889Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.462493Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpW8GPwv/staging/.tmpAFpN8x' [INFO] [stdout] 2025-11-11T09:01:56.462537Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-11-11T09:01:56.462660Z DEBUG cassadilia::cas_manager: Moved blob 992adda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157 to CAS path '/tmp/.tmpeqjczG/cas/99/2a/dda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157' [INFO] [stdout] 2025-11-11T09:01:56.462777Z  INFO cassadilia::index::persistence: Loaded 3 entries from index '/tmp/.tmpQA2FZT/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.462870Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpQA2FZT/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.462888Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=3 [INFO] [stdout] 2025-11-11T09:01:56.462902Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpQA2FZT/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.462971Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpQA2FZT/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.462992Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.463038Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=3 [INFO] [stdout] 2025-11-11T09:01:56.463388Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.463421Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.464219Z DEBUG cassadilia::transaction: Committing transaction blob_hash=82127748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823 key="key03" [INFO] [stdout] 2025-11-11T09:01:56.465325Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00645062 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.466227Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f key="valid_key1" [INFO] [stdout] 2025-11-11T09:01:56.466446Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00742769 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.466584Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpez5BJc/staging/.tmpPlqrMM' [INFO] [stdout] 2025-11-11T09:01:56.466628Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-11-11T09:01:56.466633Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key"' using staging file '/tmp/.tmpSDgzDV/staging/.tmpoH2Qln' [INFO] [stdout] test tests::test_get_range ... ok [INFO] [stdout] 2025-11-11T09:01:56.466702Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00360609 total_blobs=3 [INFO] [stdout] 2025-11-11T09:01:56.466754Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.011490708 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.466868Z DEBUG cassadilia::transaction: Starting transaction for key '"valid_key1"' using staging file '/tmp/.tmpD4vqRb/staging/.tmp9BDCJL' [INFO] [stdout] 2025-11-11T09:01:56.466893Z DEBUG cassadilia::transaction: Finishing transaction for key '"valid_key1"' [INFO] [stdout] 2025-11-11T09:01:56.467081Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 key="key1" [INFO] [stdout] 2025-11-11T09:01:56.467213Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmpeqjczG/staging/.tmpZD7ncM' [INFO] [stdout] 2025-11-11T09:01:56.467248Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] 2025-11-11T09:01:56.469244Z DEBUG cassadilia::cas_manager: Moved blob 409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f to CAS path '/tmp/.tmp6sbVOa/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f' [INFO] [stdout] 2025-11-11T09:01:56.470498Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8IqWyU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.470608Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8IqWyU/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.470632Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.470645Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp8IqWyU/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.470716Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp8IqWyU/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.470738Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.470749Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.470771Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.470880Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.470918Z DEBUG cassadilia::cas_manager: Moved blob 82127748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823 to CAS path '/tmp/.tmpA3njDV/cas/82/12/7748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823' [INFO] [stdout] 2025-11-11T09:01:56.471052Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f key="valid_key1" [INFO] [stdout] 2025-11-11T09:01:56.471140Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 key="key1" [INFO] [stdout] 2025-11-11T09:01:56.471234Z DEBUG cassadilia::transaction: Committing transaction blob_hash=d8fbb1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5 key="key04" [INFO] [stdout] 2025-11-11T09:01:56.471401Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmppleuZB/index' [INFO] [stdout] 2025-11-11T09:01:56.471425Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.471454Z DEBUG cassadilia::cas_manager: Moved blob b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 to CAS path '/tmp/.tmpW8GPwv/cas/b6/e3/82289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22' [INFO] [stdout] 2025-11-11T09:01:56.471493Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpW8GPwv/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.471520Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.471528Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmppleuZB/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.471554Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.471564Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.471577Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.471628Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.472302Z DEBUG cassadilia::cas_manager: Moved blob cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f to CAS path '/tmp/.tmpWsbLJI/cas/cd/f3/15a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f' [INFO] [stdout] 2025-11-11T09:01:56.472349Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpWsbLJI/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.472381Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.472440Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmppleuZB/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.472524Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmppleuZB/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.472540Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=1 [INFO] [stdout] 2025-11-11T09:01:56.472523Z DEBUG cassadilia::cas_manager: Moved blob d8fbb1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5 to CAS path '/tmp/.tmpeqjczG/cas/d8/fb/b1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5' [INFO] [stdout] 2025-11-11T09:01:56.472551Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmppleuZB/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.472587Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmppleuZB/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.472603Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.472614Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.472803Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00014992 total_blobs=1 [INFO] [stdout] test tests::checkpoint::test_checkpoint_prevents_double_replay ... ok [INFO] [stdout] 2025-11-11T09:01:56.473381Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpDMFv5Q/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.473468Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.473483Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.473508Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpDMFv5Q/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.474441Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmp6sbVOa/staging/.tmphxW2Vq' [INFO] [stdout] 2025-11-11T09:01:56.474469Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] test tests::regression_put_same_content_should_not_delete_blob ... ok [INFO] [stdout] 2025-11-11T09:01:56.475622Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmpA3njDV/staging/.tmpK7vGng' [INFO] [stdout] 2025-11-11T09:01:56.475667Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] 2025-11-11T09:01:56.476403Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpvpeoQ6/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.476483Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.476513Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.476530Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.476555Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpvpeoQ6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.476667Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.476974Z DEBUG cassadilia::transaction: Committing transaction blob_hash=68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc key="key03" [INFO] [stdout] 2025-11-11T09:01:56.476981Z DEBUG cassadilia::cas_manager: Moved blob cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f to CAS path '/tmp/.tmpD4vqRb/cas/cd/f3/15a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f' [INFO] [stdout] 2025-11-11T09:01:56.477060Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpD4vqRb/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.477091Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.477248Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00024852 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.477385Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmpeqjczG/staging/.tmpWcOk8c' [INFO] [stdout] 2025-11-11T09:01:56.477421Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-11-11T09:01:56.478107Z DEBUG cassadilia::transaction: Starting transaction for key '"overwrite_test"' using staging file '/tmp/.tmpDMFv5Q/staging/.tmpBxK4I1' [INFO] [stdout] 2025-11-11T09:01:56.478141Z DEBUG cassadilia::transaction: Finishing transaction for key '"overwrite_test"' [INFO] [stdout] 2025-11-11T09:01:56.478057Z DEBUG cassadilia::cas_manager: Moved blob b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 to CAS path '/tmp/.tmpez5BJc/cas/b6/e3/82289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22' [INFO] [stdout] 2025-11-11T09:01:56.478214Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpez5BJc/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.478229Z DEBUG cassadilia::cas_manager: Moved blob 68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc to CAS path '/tmp/.tmp6sbVOa/cas/68/e1/d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc' [INFO] [stdout] 2025-11-11T09:01:56.478244Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.478260Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpWsbLJI/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.478313Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpwGSiGF/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.478356Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmp8IqWyU/index' [INFO] [stdout] 2025-11-11T09:01:56.478385Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.478395Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpWsbLJI/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.478419Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.478426Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.478445Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.478472Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpwGSiGF/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.478483Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8IqWyU/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.478511Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.478522Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] test tests::test_checkpoint_persists_index ... 2025-11-11T09:01:56.478532Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] ok [INFO] [stdout] 2025-11-11T09:01:56.478752Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpW8GPwv/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.478432Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpWsbLJI/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.478883Z DEBUG cassadilia::transaction: Committing transaction blob_hash=22a0b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27 key="key04" [INFO] [stdout] 2025-11-11T09:01:56.478988Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpx3v8qJ/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.479010Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpW8GPwv/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.479074Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.479078Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.479092Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.479095Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpW8GPwv/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.479117Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpx3v8qJ/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.479714Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00087484 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.479745Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpWsbLJI/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.479782Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.479795Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.479822Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.479834Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.480004Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpW8GPwv/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.480029Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.480041Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.480073Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.480085Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.480116Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpvpeoQ6/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.480239Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpvpeoQ6/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.480261Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.480271Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpvpeoQ6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.480305Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpvpeoQ6/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.480322Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.480333Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-11-11T09:01:56.480569Z DEBUG cassadilia::transaction: Committing transaction blob_hash=a6e7f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 key="overwrite_test" [INFO] [stdout] 2025-11-11T09:01:56.480578Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f8165b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2 key="key05" [INFO] [stdout] 2025-11-11T09:01:56.480826Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0003366 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.480941Z DEBUG cassadilia::transaction: Starting transaction for key '[109, 121, 95, 98, 121, 116, 101, 115, 95, 98, 108, 111, 98]' using staging file '/tmp/.tmpwGSiGF/staging/.tmpXnivVd' [INFO] [stdout] 2025-11-11T09:01:56.480937Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00236295 total_blobs=1 [INFO] [stdout] 2025-11-11T09:01:56.481172Z DEBUG cassadilia::transaction: Finishing transaction for key '[109, 121, 95, 98, 121, 116, 101, 115, 95, 98, 108, 111, 98]' [INFO] [stdout] 2025-11-11T09:01:56.481850Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.481911Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmp6sbVOa/staging/.tmpZuc4Kv' [INFO] [stdout] 2025-11-11T09:01:56.481943Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] test tests::checkpoint::test_empty_database_checkpoint_on_first_write ... ok [INFO] [stdout] 2025-11-11T09:01:56.486646Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00425382 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.487586Z DEBUG cassadilia::transaction: Starting transaction for key '"my_first_blob"' using staging file '/tmp/.tmpx3v8qJ/staging/.tmpZvPUE6' [INFO] [stdout] 2025-11-11T09:01:56.487615Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpWsbLJI/index' [INFO] [stdout] 2025-11-11T09:01:56.487636Z DEBUG cassadilia::transaction: Finishing transaction for key '"my_first_blob"' [INFO] [stdout] 2025-11-11T09:01:56.487640Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.487700Z DEBUG cassadilia::cas_manager: Moved blob 22a0b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27 to CAS path '/tmp/.tmpA3njDV/cas/22/a0/b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27' [INFO] [stdout] 2025-11-11T09:01:56.487742Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpWsbLJI/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.487763Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.487774Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.487784Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.487849Z DEBUG cassadilia::cas_manager: Moved blob f8165b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2 to CAS path '/tmp/.tmpeqjczG/cas/f8/16/5b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2' [INFO] [stdout] 2025-11-11T09:01:56.487979Z ERROR cassadilia::orphan: Corrupted blob detected hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f expected_meta=ExpectedMeta { blob_size: 12 } [INFO] [stdout] 2025-11-11T09:01:56.488060Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpez5BJc/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.488078Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=1 staging_files=0 scan_time=0.00024665 total_blobs=1 [INFO] [stdout] 2025-11-11T09:01:56.488368Z DEBUG cassadilia::transaction: Committing transaction blob_hash=5926801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6 key=[109, 121, 95, 98, 121, 116, 101, 115, 95, 98, 108, 111, 98] [INFO] [stdout] 2025-11-11T09:01:56.488551Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpez5BJc/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.488577Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.488590Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpez5BJc/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.488742Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpW8GPwv/index' [INFO] [stdout] 2025-11-11T09:01:56.488875Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.490435Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.490487Z  INFO cassadilia::orphan: Deleted orphaned blob hash=aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3 [INFO] [stdout] 2025-11-11T09:01:56.490732Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpW8GPwv/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.490760Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.490771Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.490782Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.490986Z DEBUG cassadilia::transaction: Committing transaction blob_hash=3e5cebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 key="my_first_blob" [INFO] [stdout] 2025-11-11T09:01:56.491045Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpD4vqRb/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.491085Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.491095Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpmEqQh6/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.491147Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpD4vqRb/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.491187Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.491200Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpD4vqRb/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.491214Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.491229Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.491223Z DEBUG cassadilia::transaction: Committing transaction blob_hash=4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d key="key04" [INFO] [stdout] 2025-11-11T09:01:56.491256Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpmEqQh6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.491261Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpD4vqRb/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.491281Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.491281Z DEBUG cassadilia::transaction: Starting transaction for key '"key06"' using staging file '/tmp/.tmpeqjczG/staging/.tmpRkIkId' [INFO] [stdout] 2025-11-11T09:01:56.491293Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.491310Z DEBUG cassadilia::transaction: Finishing transaction for key '"key06"' [INFO] [stdout] 2025-11-11T09:01:56.491316Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.491328Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.494473Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpez5BJc/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.494541Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.494557Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.494604Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.494629Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] test tests::test_orphan_detection_with_integrity_check ... 2025-11-11T09:01:56.495448Z  INFO cassadilia::orphan: Quarantined orphaned blob hash=aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3 dest="/tmp/.tmpW8GPwv/quarantine/aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3" [INFO] [stdout] 2025-11-11T09:01:56.495272Z DEBUG cassadilia::cas_manager: Moved blob a6e7f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 to CAS path '/tmp/.tmpDMFv5Q/cas/a6/e7/f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5' [INFO] [stdout] ok [INFO] [stdout] test tests::test_orphan_quarantine ... ok [INFO] [stdout] 2025-11-11T09:01:56.496479Z DEBUG cassadilia::cas_manager: Moved blob 4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d to CAS path '/tmp/.tmp6sbVOa/cas/46/07/a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d' [INFO] [stdout] 2025-11-11T09:01:56.495883Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpDMFv5Q/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.496522Z DEBUG cassadilia::cas_manager: Moved blob 3e5cebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 to CAS path '/tmp/.tmpx3v8qJ/cas/3e/5c/ebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7' [INFO] [stdout] 2025-11-11T09:01:56.496985Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.497030Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpx3v8qJ/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.497066Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.495342Z DEBUG cassadilia::cas_manager: Moved blob 5926801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6 to CAS path '/tmp/.tmpwGSiGF/cas/59/26/801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6' [INFO] [stdout] 2025-11-11T09:01:56.497151Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpwGSiGF/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.497197Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.498752Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00142501 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.498872Z DEBUG cassadilia::transaction: Starting transaction for key '"key_1"' using staging file '/tmp/.tmpmEqQh6/staging/.tmpmJ5Nox' [INFO] [stdout] 2025-11-11T09:01:56.498908Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_1"' [INFO] [stdout] 2025-11-11T09:01:56.499266Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test tests::test_orphan_stats_holds_lock ... ok [INFO] [stdout] 2025-11-11T09:01:56.499795Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpez5BJc/index' [INFO] [stdout] 2025-11-11T09:01:56.499832Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.499795Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp6sbVOa/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.499948Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpez5BJc/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.499970Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.499980Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.499980Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp6sbVOa/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.499991Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.500003Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.500014Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp6sbVOa/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.500104Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp6sbVOa/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.500124Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] 2025-11-11T09:01:56.500136Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-11-11T09:01:56.500141Z ERROR cassadilia::orphan: Missing blob in filesystem hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 [INFO] [stdout] 2025-11-11T09:01:56.500187Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.500202Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.500211Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=1 corrupted_blobs=0 staging_files=0 scan_time=0.00018403 total_blobs=0 [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_error_cases ... ok [INFO] [stdout] 2025-11-11T09:01:56.501241Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpA3njDV/index' not found, starting fresh. State remains new. [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_valid_cases ... ok [INFO] [stdout] 2025-11-11T09:01:56.505502Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpA3njDV/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.505529Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.505541Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpA3njDV/0_index.wal [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_with_prefix ... ok [INFO] [stdout] 2025-11-11T09:01:56.505648Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpA3njDV/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.505673Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] test types::tests::test_blob_hash_relative_path_roundtrip ... ok [INFO] [stdout] 2025-11-11T09:01:56.505686Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-11-11T09:01:56.505713Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 1 (for next op version 6) exists at path: /tmp/.tmpA3njDV/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.502461Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 key="key_1" [INFO] [stdout] test types::tests::test_blob_hash_relative_path_structure ... ok [INFO] [stdout] 2025-11-11T09:01:56.502732Z  INFO cassadilia::index::persistence: Persisted 5 entries to index '/tmp/.tmp6sbVOa/index' [INFO] [stdout] 2025-11-11T09:01:56.505832Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.504010Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpwGSiGF/cas/59/26/801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6 [INFO] [stdout] 2025-11-11T09:01:56.505921Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.505938Z DEBUG cassadilia::transaction: Committing transaction blob_hash=40eea84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293 key="key06" [INFO] [stdout] 2025-11-11T09:01:56.504108Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpx3v8qJ/cas/3e/5c/ebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 [INFO] [stdout] 2025-11-11T09:01:56.506008Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.501146Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpbYjfPr/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.506095Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpD4vqRb/index' [INFO] [stdout] 2025-11-11T09:01:56.506115Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.506200Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.506222Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.506245Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpbYjfPr/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.507256Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpD4vqRb/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.507306Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.507320Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.507331Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.507537Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.507743Z  INFO cassadilia::orphan: Deleted orphaned blob hash=2b2e0f3ac5c07ce0e1a48cbac77e3efcc4b21d58de0826c22319ddb123e4432f [INFO] [stdout] test tests::test_put_get_remove_bytes_key ... ok [INFO] [stdout] 2025-11-11T09:01:56.507258Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp6sbVOa/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.507266Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpwXQfm6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.507872Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.507889Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.507900Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.511393Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.511598Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.511638Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.512847Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00490291 total_blobs=5 [INFO] [stdout] 2025-11-11T09:01:56.512870Z DEBUG cassadilia::cas_manager: Moved blob 40eea84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293 to CAS path '/tmp/.tmpeqjczG/cas/40/ee/a84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293' [INFO] [stdout] 2025-11-11T09:01:56.513380Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00036798 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.513492Z DEBUG cassadilia::transaction: Starting transaction for key '"dropped_tx_key"' using staging file '/tmp/.tmpbYjfPr/staging/.tmpyKLuI1' [INFO] [stdout] 2025-11-11T09:01:56.514523Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmp6sbVOa/staging/.tmpoIwXvl' [INFO] [stdout] 2025-11-11T09:01:56.514558Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-11-11T09:01:56.514647Z DEBUG cassadilia::cas_manager: Moved blob 7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 to CAS path '/tmp/.tmpmEqQh6/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676' [INFO] [stdout] 2025-11-11T09:01:56.514687Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpmEqQh6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.514715Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.514705Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpJUTgqX/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.514836Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] test tests::test_transaction_drop_cleans_up_staging_file ... ok [INFO] [stdout] 2025-11-11T09:01:56.515020Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpDMFv5Q/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.515143Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDMFv5Q/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.515199Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.515214Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpDMFv5Q/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.515426Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpDMFv5Q/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.515460Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.515473Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:01:56.515483Z  INFO cassadilia::index::persistence: Persisted 5 entries to index '/tmp/.tmpA3njDV/index' [INFO] [stdout] 2025-11-11T09:01:56.515498Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.515512Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.515513Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.515623Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpA3njDV/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpA3njDV/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.515658Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.515670Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.515685Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.516471Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpEm7rLW/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.516586Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.516601Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] test tests::test_orphan_detection_with_missing_blobs ... ok [INFO] [stdout] 2025-11-11T09:01:56.516629Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpEm7rLW/0_index.wal [INFO] [stdout] test tests::test_put_get_remove_string_key ... ok [INFO] [stdout] 2025-11-11T09:01:56.516987Z  WARN cassadilia::wal::storage: Found WAL-like file with non-numeric segment ID: /tmp/.tmpKkKulx/abc_index.wal [INFO] [stdout] 2025-11-11T09:01:56.517080Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpKkKulx/0_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpKkKulx/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.517408Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00167907 total_blobs=5 [INFO] [stdout] 2025-11-11T09:01:56.517524Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmpA3njDV/staging/.tmpVyaxf6' [INFO] [stdout] 2025-11-11T09:01:56.517555Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-11-11T09:01:56.517874Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2f5899145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3 key="key05" [INFO] [stdout] test tests::test_orphan_detection_and_cleanup ... ok [INFO] [stdout] 2025-11-11T09:01:56.518315Z DEBUG cassadilia::transaction: Starting transaction for key '"key07"' using staging file '/tmp/.tmpeqjczG/staging/.tmptKUDEo' [INFO] [stdout] test wal::tests::discover_segments_ignores_malformed_filenames ... 2025-11-11T09:01:56.518346Z DEBUG cassadilia::transaction: Finishing transaction for key '"key07"' [INFO] [stdout] ok [INFO] [stdout] 2025-11-11T09:01:56.518494Z DEBUG cassadilia::transaction: Starting transaction for key '"key_2"' using staging file '/tmp/.tmpmEqQh6/staging/.tmp01zbRQ' [INFO] [stdout] 2025-11-11T09:01:56.518526Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_2"' [INFO] [stdout] 2025-11-11T09:01:56.519257Z DEBUG cassadilia::cas_manager: Moved blob 2f5899145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3 to CAS path '/tmp/.tmp6sbVOa/cas/2f/58/99145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3' [INFO] [stdout] 2025-11-11T09:01:56.519285Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpH0GIfy/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.519314Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp6sbVOa/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.519344Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.519693Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpMPNGTL/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.519720Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.519747Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.519797Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.519867Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.519796Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp7TCinn/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.523304Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpDMFv5Q/index' [INFO] [stdout] 2025-11-11T09:01:56.523315Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.523336Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.523347Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.523438Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDMFv5Q/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.523460Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.523470Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.523482Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:01:56.523484Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00354718 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.523677Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpI1Jo2d/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.523773Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:01:56.523799Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:01:56.523824Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpI1Jo2d/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.524458Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpFFjGC3/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.524500Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.524512Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpFFjGC3/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.524531Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpEm7rLW/staging/.tmpS5TU1m' [INFO] [stdout] 2025-11-11T09:01:56.524567Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] test wal::tests::replay_fails_on_corrupted_op_entry ... ok [INFO] [stdout] 2025-11-11T09:01:56.524947Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.001421239 total_blobs=1 [INFO] [stdout] 2025-11-11T09:01:56.525113Z DEBUG cassadilia::transaction: Starting transaction for key '"overwrite_test"' using staging file '/tmp/.tmpDMFv5Q/staging/.tmpXn9qtr' [INFO] [stdout] 2025-11-11T09:01:56.525152Z DEBUG cassadilia::transaction: Finishing transaction for key '"overwrite_test"' [INFO] [stdout] 2025-11-11T09:01:56.525198Z DEBUG cassadilia::transaction: Committing transaction blob_hash=0d828af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb key="key07" [INFO] [stdout] 2025-11-11T09:01:56.525237Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.525251Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test wal::tests::segment_id_calculation_is_correct ... ok [INFO] [stdout] 2025-11-11T09:01:56.526387Z DEBUG cassadilia::cas_manager: Moved blob 0d828af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb to CAS path '/tmp/.tmpeqjczG/cas/0d/82/8af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb' [INFO] [stdout] 2025-11-11T09:01:56.526925Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.526975Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpwXQfm6/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.527019Z DEBUG cassadilia::transaction: Committing transaction blob_hash=637140a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3 key="key1" [INFO] [stdout] 2025-11-11T09:01:56.527205Z DEBUG cassadilia::transaction: Committing transaction blob_hash=409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f key="key_2" [INFO] [stdout] 2025-11-11T09:01:56.527040Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=5.892e-5 total_blobs=0 [INFO] [stdout] 2025-11-11T09:01:56.527240Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e1adf0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9 key="key05" [INFO] [stdout] 2025-11-11T09:01:56.527570Z DEBUG cassadilia::transaction: Starting transaction for key '"remove_persist_test"' using staging file '/tmp/.tmpI1Jo2d/staging/.tmplUc2Xv' [INFO] [stdout] 2025-11-11T09:01:56.527928Z DEBUG cassadilia::transaction: Finishing transaction for key '"remove_persist_test"' [INFO] [stdout] 2025-11-11T09:01:56.527647Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpH0GIfy/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.528077Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.528116Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpH0GIfy/0_index.wal [INFO] [stdout] test wal::tests::replay_on_completely_empty_directory ... 2025-11-11T09:01:56.528233Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b4de87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f key="overwrite_test" [INFO] [stdout] 2025-11-11T09:01:56.527822Z DEBUG cassadilia::cas_manager: Moved blob e1adf0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9 to CAS path '/tmp/.tmpA3njDV/cas/e1/ad/f0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9' [INFO] [stdout] 2025-11-11T09:01:56.527706Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.528184Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpJUTgqX/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.527881Z DEBUG cassadilia::cas_manager: Moved blob 637140a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3 to CAS path '/tmp/.tmpEm7rLW/cas/63/71/40a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3' [INFO] [stdout] 2025-11-11T09:01:56.528378Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpEm7rLW/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.528407Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.528289Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpA3njDV/1_index.wal [INFO] [stdout] ok [INFO] [stdout] 2025-11-11T09:01:56.528457Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.531439Z DEBUG cassadilia::transaction: Starting transaction for key '"key06"' using staging file '/tmp/.tmp6sbVOa/staging/.tmpfi7kCn' [INFO] [stdout] 2025-11-11T09:01:56.531486Z DEBUG cassadilia::transaction: Finishing transaction for key '"key06"' [INFO] [stdout] 2025-11-11T09:01:56.532790Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.533538Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2c0e850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 key="remove_persist_test" [INFO] [stdout] 2025-11-11T09:01:56.535210Z DEBUG cassadilia::cas_manager: Moved blob 409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f to CAS path '/tmp/.tmpmEqQh6/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f' [INFO] [stdout] 2025-11-11T09:01:56.536355Z DEBUG cassadilia::cas_manager: Moved blob b4de87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f to CAS path '/tmp/.tmpDMFv5Q/cas/b4/de/87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f' [INFO] [stdout] 2025-11-11T09:01:56.536384Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpRxo69L/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.536402Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpDMFv5Q/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.536437Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.536519Z DEBUG cassadilia::transaction: Starting transaction for key '"key08"' using staging file '/tmp/.tmpeqjczG/staging/.tmp7tHlCr' [INFO] [stdout] 2025-11-11T09:01:56.536547Z DEBUG cassadilia::transaction: Finishing transaction for key '"key08"' [INFO] [stdout] test wal::tests::replay_fails_on_key_decode_error ... ok [INFO] [stdout] 2025-11-11T09:01:56.536930Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpzM5z4g/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.537006Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.537492Z DEBUG cassadilia::cas_manager: Moved blob 2c0e850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 to CAS path '/tmp/.tmpI1Jo2d/cas/2c/0e/850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1' [INFO] [stdout] 2025-11-11T09:01:56.537536Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpI1Jo2d/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.537561Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] test wal::tests::segment_reader_next_fails_on_checksum_mismatch ... ok [INFO] [stdout] test wal::tests::wal_manager_new_fails_on_uncreatable_directory ... ok [INFO] [stdout] 2025-11-11T09:01:56.537952Z DEBUG cassadilia::transaction: Committing transaction blob_hash=983ad14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244 key="key06" [INFO] [stdout] 2025-11-11T09:01:56.537965Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-11-11T09:01:56.538044Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.538067Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.538121Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:01:56.539359Z DEBUG cassadilia::transaction: Starting transaction for key '"key2"' using staging file '/tmp/.tmpEm7rLW/staging/.tmpjNRcKS' [INFO] [stdout] 2025-11-11T09:01:56.539397Z DEBUG cassadilia::transaction: Finishing transaction for key '"key2"' [INFO] [stdout] 2025-11-11T09:01:56.540475Z DEBUG cassadilia::cas_manager: Moved blob 983ad14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244 to CAS path '/tmp/.tmp6sbVOa/cas/98/3a/d14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244' [INFO] [stdout] 2025-11-11T09:01:56.540951Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b230a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843 key="key08" [INFO] [stdout] 2025-11-11T09:01:56.541179Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpDMFv5Q/cas/a6/e7/f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 [INFO] [stdout] 2025-11-11T09:01:56.541320Z DEBUG cassadilia::transaction: Starting transaction for key '"key_3"' using staging file '/tmp/.tmpmEqQh6/staging/.tmpbZHhpc' [INFO] [stdout] 2025-11-11T09:01:56.541355Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_3"' [INFO] [stdout] 2025-11-11T09:01:56.542007Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.542115Z DEBUG cassadilia::cas_manager: Moved blob b230a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843 to CAS path '/tmp/.tmpeqjczG/cas/b2/30/a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843' [INFO] [stdout] 2025-11-11T09:01:56.542589Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpMPNGTL/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.542589Z DEBUG cassadilia::transaction: Committing transaction blob_hash=71df75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d key="key2" [INFO] [stdout] 2025-11-11T09:01:56.542588Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.542624Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-11-11T09:01:56.542639Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-11-11T09:01:56.542853Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmpDMFv5Q/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.542924Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.542963Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDMFv5Q/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.542988Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=1 [INFO] [stdout] 2025-11-11T09:01:56.543000Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpDMFv5Q/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.543063Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpDMFv5Q/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.543088Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:01:56.543099Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=2 [INFO] [stdout] 2025-11-11T09:01:56.543120Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.543134Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.543680Z  INFO cassadilia::index::persistence: Persisted 6 entries to index '/tmp/.tmpA3njDV/index' [INFO] [stdout] 2025-11-11T09:01:56.543710Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-11-11T09:01:56.543745Z DEBUG cassadilia::transaction: Starting transaction for key '"key07"' using staging file '/tmp/.tmp6sbVOa/staging/.tmplNvIp8' [INFO] [stdout] 2025-11-11T09:01:56.543774Z DEBUG cassadilia::transaction: Finishing transaction for key '"key07"' [INFO] [stdout] 2025-11-11T09:01:56.543813Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpA3njDV/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpA3njDV/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.543841Z DEBUG cassadilia::cas_manager: Moved blob 71df75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d to CAS path '/tmp/.tmpEm7rLW/cas/71/df/75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d' [INFO] [stdout] 2025-11-11T09:01:56.543855Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpA3njDV/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.543934Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.543956Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=6 [INFO] [stdout] 2025-11-11T09:01:56.543968Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=6 [INFO] [stdout] 2025-11-11T09:01:56.544070Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] test wal::tests::wal_manager_drop_is_safe_with_active_writer ... ok [INFO] [stdout] 2025-11-11T09:01:56.544297Z DEBUG cassadilia::transaction: Committing transaction blob_hash=68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc key="key_3" [INFO] [stdout] 2025-11-11T09:01:56.544527Z  INFO cassadilia::index::persistence: Loaded 6 entries from index '/tmp/.tmpA3njDV/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.544549Z DEBUG cassadilia::cas_manager: Moved blob 68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc to CAS path '/tmp/.tmpmEqQh6/cas/68/e1/d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc' [INFO] [stdout] 2025-11-11T09:01:56.544629Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpA3njDV/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.544656Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=6 [INFO] [stdout] 2025-11-11T09:01:56.544668Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpA3njDV/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.544721Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpA3njDV/1_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.544739Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.544754Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=6 [INFO] [stdout] 2025-11-11T09:01:56.544845Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpI1Jo2d/cas/2c/0e/850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 [INFO] [stdout] 2025-11-11T09:01:56.545112Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.544941Z DEBUG cassadilia::transaction: Starting transaction for key '"key09"' using staging file '/tmp/.tmpeqjczG/staging/.tmpU50Lz8' [INFO] [stdout] 2025-11-11T09:01:56.545242Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.000444039 total_blobs=6 [INFO] [stdout] 2025-11-11T09:01:56.545247Z DEBUG cassadilia::transaction: Finishing transaction for key '"key09"' [INFO] [stdout] 2025-11-11T09:01:56.545833Z DEBUG cassadilia::transaction: Committing transaction blob_hash=760ca58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb key="key07" [INFO] [stdout] 2025-11-11T09:01:56.545861Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmpJUTgqX/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.546094Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpDMFv5Q/index' [INFO] [stdout] 2025-11-11T09:01:56.546126Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.546210Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] 2025-11-11T09:01:56.546233Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDMFv5Q/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.546252Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.546261Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.546274Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.546495Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00018632 total_blobs=1 [INFO] [stdout] 2025-11-11T09:01:56.546929Z DEBUG cassadilia::transaction: Starting transaction for key '"key3"' using staging file '/tmp/.tmpEm7rLW/staging/.tmpM9hutj' [INFO] [stdout] 2025-11-11T09:01:56.549337Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.549371Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test tests::test_overwrite_persists_across_reopen ... ok [INFO] [stdout] test tests::checkpoint::test_wal_segment_rollover_triggers_checkpoint ... ok [INFO] [stdout] 2025-11-11T09:01:56.547677Z DEBUG cassadilia::transaction: Starting transaction for key '"key_4"' using staging file '/tmp/.tmpmEqQh6/staging/.tmpZfPnNF' [INFO] [stdout] 2025-11-11T09:01:56.549432Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-11-11T09:01:56.549437Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_4"' [INFO] [stdout] 2025-11-11T09:01:56.549457Z DEBUG cassadilia::transaction: Committing transaction blob_hash=600c41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81 key="key09" [INFO] [stdout] 2025-11-11T09:01:56.549515Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpMPNGTL/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpMPNGTL/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.549547Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpMPNGTL/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.549568Z DEBUG cassadilia::transaction: Finishing transaction for key '"key3"' [INFO] [stdout] 2025-11-11T09:01:56.549618Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.549632Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=4 [INFO] [stdout] 2025-11-11T09:01:56.549648Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-11-11T09:01:56.549287Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpI1Jo2d/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.549657Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-11-11T09:01:56.547121Z DEBUG cassadilia::cas_manager: Moved blob 760ca58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb to CAS path '/tmp/.tmp6sbVOa/cas/76/0c/a58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb' [INFO] [stdout] 2025-11-11T09:01:56.549337Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-11-11T09:01:56.549894Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpJUTgqX/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpJUTgqX/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpJUTgqX/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.549923Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpJUTgqX/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.549984Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpI1Jo2d/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.550002Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.550013Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpI1Jo2d/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.550268Z DEBUG cassadilia::cas_manager: Moved blob 600c41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81 to CAS path '/tmp/.tmpeqjczG/cas/60/0c/41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81' [INFO] [stdout] 2025-11-11T09:01:56.550938Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpI1Jo2d/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.551105Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=2 [INFO] [stdout] 2025-11-11T09:01:56.551123Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=2 highest_op_version=2 [INFO] [stdout] 2025-11-11T09:01:56.551146Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.551199Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.551056Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 1: /tmp/.tmpJUTgqX/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.551428Z  INFO cassadilia::wal::storage: Successfully removed 2 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.551447Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.551503Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpJUTgqX/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.551516Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmpMPNGTL/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.552388Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] 2025-11-11T09:01:56.552485Z DEBUG cassadilia::wal::storage: Reached end-of-segment marker (version 0) in segment 0. Cleanly ending replay for this segment. [INFO] [stdout] 2025-11-11T09:01:56.553571Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] test wal::tests::checkpoint_succeeds_and_prunes_old_segments ... ok [INFO] [stdout] 2025-11-11T09:01:56.554043Z DEBUG cassadilia::transaction: Committing transaction blob_hash=0393cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520 key="key3" [INFO] [stdout] 2025-11-11T09:01:56.554083Z DEBUG cassadilia::transaction: Committing transaction blob_hash=4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d key="key_4" [INFO] [stdout] test wal::tests::segment_reader_stops_at_explicit_sentinel ... ok [INFO] [stdout] 2025-11-11T09:01:56.554464Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.555192Z  INFO cassadilia::index::persistence: Persisted 0 entries to index '/tmp/.tmpI1Jo2d/index' [INFO] [stdout] 2025-11-11T09:01:56.555221Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.555315Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpI1Jo2d/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.555338Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.555349Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.555360Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-11-11T09:01:56.555514Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00011561 total_blobs=0 [INFO] [stdout] test tests::test_remove_persists_across_reopen ... ok [INFO] [stdout] 2025-11-11T09:01:56.556175Z DEBUG cassadilia::cas_manager: Moved blob 0393cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520 to CAS path '/tmp/.tmpEm7rLW/cas/03/93/cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520' [INFO] [stdout] 2025-11-11T09:01:56.556213Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.556223Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.556305Z DEBUG cassadilia::transaction: Starting transaction for key '"key10"' using staging file '/tmp/.tmpeqjczG/staging/.tmp4NvkEz' [INFO] [stdout] 2025-11-11T09:01:56.556494Z DEBUG cassadilia::transaction: Finishing transaction for key '"key10"' [INFO] [stdout] 2025-11-11T09:01:56.557351Z  INFO cassadilia::index::persistence: Loaded 5 entries from index '/tmp/.tmp6sbVOa/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.557495Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp6sbVOa/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.557520Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=5 [INFO] [stdout] 2025-11-11T09:01:56.557534Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp6sbVOa/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.557623Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp6sbVOa/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.557645Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=3 [INFO] [stdout] 2025-11-11T09:01:56.557634Z DEBUG cassadilia::cas_manager: Moved blob 4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d to CAS path '/tmp/.tmpmEqQh6/cas/46/07/a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d' [INFO] [stdout] 2025-11-11T09:01:56.557657Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=3 highest_op_version=8 [INFO] [stdout] 2025-11-11T09:01:56.557680Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.557693Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.558021Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpMPNGTL/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpMPNGTL/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.558054Z  INFO cassadilia::wal::replay: Starting WAL replay segments=2 checkpoint=4 [INFO] [stdout] 2025-11-11T09:01:56.558067Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpMPNGTL/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.558115Z DEBUG cassadilia::wal::storage: Reached end-of-segment marker (version 0) in segment 1. Cleanly ending replay for this segment. [INFO] [stdout] 2025-11-11T09:01:56.558146Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.558251Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmpMPNGTL/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.558671Z DEBUG cassadilia::wal::tests: Replaying op #1 [INFO] [stdout] 2025-11-11T09:01:56.558707Z DEBUG cassadilia::wal::tests: Replaying op #2 [INFO] [stdout] 2025-11-11T09:01:56.558719Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmpMPNGTL/2_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.558746Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=2 [INFO] [stdout] 2025-11-11T09:01:56.558763Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=2 highest_op_version=6 [INFO] [stdout] 2025-11-11T09:01:56.558791Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 3 (for next op version 7) exists at path: /tmp/.tmpMPNGTL/3_index.wal [INFO] [stdout] 2025-11-11T09:01:56.559112Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpEm7rLW/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.559185Z DEBUG cassadilia: Removing 2 keys in range "key_1".."key_3" [INFO] [stdout] 2025-11-11T09:01:56.559225Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.559259Z DEBUG cassadilia::transaction: Committing transaction blob_hash=c2fe34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 key="key10" [INFO] [stdout] 2025-11-11T09:01:56.559968Z DEBUG cassadilia::cas_manager: Moved blob c2fe34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 to CAS path '/tmp/.tmpeqjczG/cas/c2/fe/34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5' [INFO] [stdout] 2025-11-11T09:01:56.560024Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-11-11T09:01:56.560037Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.562357Z  INFO cassadilia::index::persistence: Persisted 8 entries to index '/tmp/.tmp6sbVOa/index' [INFO] [stdout] 2025-11-11T09:01:56.562387Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.562501Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp6sbVOa/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.562525Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.562536Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=8 [INFO] [stdout] 2025-11-11T09:01:56.562547Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=8 [INFO] [stdout] 2025-11-11T09:01:56.562886Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-11-11T09:01:56.562979Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpmEqQh6/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 [INFO] [stdout] 2025-11-11T09:01:56.563117Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpmEqQh6/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f [INFO] [stdout] 2025-11-11T09:01:56.563250Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:01:56.563260Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00066902 total_blobs=8 [INFO] [stdout] 2025-11-11T09:01:56.563491Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpeqjczG/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.563726Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.563757Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpmEqQh6/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:01:56.563863Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpmEqQh6/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.563887Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:01:56.563899Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpmEqQh6/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.564019Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpmEqQh6/0_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.564063Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] 2025-11-11T09:01:56.564077Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-11-11T09:01:56.564101Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.564114Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.575587Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] 2025-11-11T09:01:56.575587Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpEm7rLW/index' [INFO] [stdout] 2025-11-11T09:01:56.575679Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-11-11T09:01:56.575820Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpEm7rLW/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpEm7rLW/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.575852Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpEm7rLW/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.575936Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.575953Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=3 [INFO] [stdout] 2025-11-11T09:01:56.575966Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-11-11T09:01:56.576030Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.576049Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.576296Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] test wal::tests::replay_should_ignore_segments_before_checkpoint ... ok [INFO] [stdout] 2025-11-11T09:01:56.578823Z  INFO cassadilia::index::persistence: Persisted 2 entries to index '/tmp/.tmpmEqQh6/index' [INFO] [stdout] 2025-11-11T09:01:56.578860Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:01:56.578967Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpmEqQh6/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.578999Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:01:56.579011Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-11-11T09:01:56.579074Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] test tests::checkpoint::test_replay_creates_checkpoint_after_restart ... ok [INFO] [stdout] 2025-11-11T09:01:56.581015Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00189253 total_blobs=2 [INFO] [stdout] 2025-11-11T09:01:56.581413Z  INFO cassadilia::index::persistence: Persisted 11 entries to index '/tmp/.tmpeqjczG/index' [INFO] [stdout] 2025-11-11T09:01:56.581444Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-11-11T09:01:56.581546Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpeqjczG/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpeqjczG/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.581582Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpeqjczG/0_index.wal [INFO] [stdout] 2025-11-11T09:01:56.583219Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.583250Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=11 [INFO] [stdout] 2025-11-11T09:01:56.583263Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=11 [INFO] [stdout] 2025-11-11T09:01:56.583404Z DEBUG cassadilia::transaction: Starting transaction for key '"key11"' using staging file '/tmp/.tmpeqjczG/staging/.tmpnZBwx1' [INFO] [stdout] 2025-11-11T09:01:56.583445Z DEBUG cassadilia::transaction: Finishing transaction for key '"key11"' [INFO] [stdout] 2025-11-11T09:01:56.583622Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpEm7rLW/index' [INFO] [stdout] 2025-11-11T09:01:56.583668Z DEBUG cassadilia::wal: Skipping checkpoint commit (idempotent/no-op). last_checkpointed_version=3 commit_version=3 [INFO] [stdout] 2025-11-11T09:01:56.583694Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-11-11T09:01:56.583778Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] test tests::test_remove_range_persists ... ok [INFO] [stdout] 2025-11-11T09:01:56.585300Z  INFO cassadilia::index::persistence: Loaded 3 entries from index '/tmp/.tmpEm7rLW/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.585425Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpEm7rLW/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.585457Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=3 [INFO] [stdout] 2025-11-11T09:01:56.585472Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpEm7rLW/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.585523Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpEm7rLW/1_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.585556Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.585569Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=3 [INFO] [stdout] 2025-11-11T09:01:56.585818Z DEBUG cassadilia::transaction: Committing transaction blob_hash=6b786ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 key="key11" [INFO] [stdout] 2025-11-11T09:01:56.586081Z DEBUG cassadilia::cas_manager: Moved blob 6b786ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 to CAS path '/tmp/.tmpeqjczG/cas/6b/78/6ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413' [INFO] [stdout] 2025-11-11T09:01:56.586346Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00073003 total_blobs=3 [INFO] [stdout] test tests::test_wal_rollover_and_cleanup ... ok [INFO] [stdout] 2025-11-11T09:01:56.591221Z DEBUG cassadilia::transaction: Starting transaction for key '"key12"' using staging file '/tmp/.tmpeqjczG/staging/.tmpxseZV2' [INFO] [stdout] 2025-11-11T09:01:56.591266Z DEBUG cassadilia::transaction: Finishing transaction for key '"key12"' [INFO] [stdout] 2025-11-11T09:01:56.596244Z DEBUG cassadilia::transaction: Committing transaction blob_hash=bf264d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 key="key12" [INFO] [stdout] 2025-11-11T09:01:56.596532Z DEBUG cassadilia::cas_manager: Moved blob bf264d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 to CAS path '/tmp/.tmpeqjczG/cas/bf/26/4d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579' [INFO] [stdout] 2025-11-11T09:01:56.602405Z DEBUG cassadilia::transaction: Starting transaction for key '"key13"' using staging file '/tmp/.tmpeqjczG/staging/.tmpDogjEM' [INFO] [stdout] test tests::test_io_error_on_staging_file_creation ... FAILED [INFO] [stdout] 2025-11-11T09:01:56.602493Z DEBUG cassadilia::transaction: Finishing transaction for key '"key13"' [INFO] [stdout] test wal::tests::zero_panics - should panic ... ok [INFO] [stdout] 2025-11-11T09:01:56.604204Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-11-11T09:01:56.604627Z DEBUG cassadilia::transaction: Committing transaction blob_hash=022bf00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 key="key13" [INFO] [stdout] test wal::tests::append_op_fails_when_segment_rollover_cannot_create_file ... FAILED [INFO] [stdout] 2025-11-11T09:01:56.604937Z DEBUG cassadilia::cas_manager: Moved blob 022bf00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 to CAS path '/tmp/.tmpeqjczG/cas/02/2b/f00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938' [INFO] [stdout] 2025-11-11T09:01:56.606937Z DEBUG cassadilia::transaction: Starting transaction for key '"key14"' using staging file '/tmp/.tmpeqjczG/staging/.tmpwMbB6F' [INFO] [stdout] 2025-11-11T09:01:56.606983Z DEBUG cassadilia::transaction: Finishing transaction for key '"key14"' [INFO] [stdout] 2025-11-11T09:01:56.608701Z DEBUG cassadilia::transaction: Committing transaction blob_hash=eeef0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 key="key14" [INFO] [stdout] 2025-11-11T09:01:56.608961Z DEBUG cassadilia::cas_manager: Moved blob eeef0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 to CAS path '/tmp/.tmpeqjczG/cas/ee/ef/0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877' [INFO] [stdout] 2025-11-11T09:01:56.610733Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-11-11T09:01:56.611151Z  INFO cassadilia::index::persistence: Loaded 11 entries from index '/tmp/.tmpeqjczG/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.611291Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpeqjczG/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.611340Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=11 [INFO] [stdout] 2025-11-11T09:01:56.611357Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpeqjczG/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.611459Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpeqjczG/1_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.611490Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=4 [INFO] [stdout] 2025-11-11T09:01:56.611503Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=4 highest_op_version=15 [INFO] [stdout] 2025-11-11T09:01:56.611534Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.611556Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:01:56.613763Z  INFO cassadilia::index::persistence: Persisted 15 entries to index '/tmp/.tmpeqjczG/index' [INFO] [stdout] 2025-11-11T09:01:56.613799Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-11-11T09:01:56.613892Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpeqjczG/1_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.613925Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 1). [INFO] [stdout] 2025-11-11T09:01:56.613936Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=15 [INFO] [stdout] 2025-11-11T09:01:56.613947Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=15 [INFO] [stdout] 2025-11-11T09:01:56.615318Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00132275 total_blobs=15 [INFO] [stdout] 2025-11-11T09:01:56.615445Z DEBUG cassadilia::transaction: Starting transaction for key '"key10"' using staging file '/tmp/.tmpeqjczG/staging/.tmpnBsf7K' [INFO] [stdout] 2025-11-11T09:01:56.615480Z DEBUG cassadilia::transaction: Finishing transaction for key '"key10"' [INFO] [stdout] 2025-11-11T09:01:56.617677Z DEBUG cassadilia::transaction: Committing transaction blob_hash=74c13e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e key="key10" [INFO] [stdout] 2025-11-11T09:01:56.618115Z DEBUG cassadilia::cas_manager: Moved blob 74c13e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e to CAS path '/tmp/.tmpeqjczG/cas/74/c1/3e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e' [INFO] [stdout] 2025-11-11T09:01:56.618177Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpeqjczG/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.618205Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-11-11T09:01:56.620240Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpeqjczG/cas/c2/fe/34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 [INFO] [stdout] 2025-11-11T09:01:56.620401Z DEBUG cassadilia::transaction: Starting transaction for key '"key11"' using staging file '/tmp/.tmpeqjczG/staging/.tmp11bz0t' [INFO] [stdout] 2025-11-11T09:01:56.620445Z DEBUG cassadilia::transaction: Finishing transaction for key '"key11"' [INFO] [stdout] 2025-11-11T09:01:56.622454Z DEBUG cassadilia::transaction: Committing transaction blob_hash=86339d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58 key="key11" [INFO] [stdout] 2025-11-11T09:01:56.622715Z DEBUG cassadilia::cas_manager: Moved blob 86339d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58 to CAS path '/tmp/.tmpeqjczG/cas/86/33/9d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58' [INFO] [stdout] 2025-11-11T09:01:56.624759Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpeqjczG/cas/6b/78/6ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 [INFO] [stdout] 2025-11-11T09:01:56.624908Z DEBUG cassadilia::transaction: Starting transaction for key '"key12"' using staging file '/tmp/.tmpeqjczG/staging/.tmppj5Kgq' [INFO] [stdout] 2025-11-11T09:01:56.624936Z DEBUG cassadilia::transaction: Finishing transaction for key '"key12"' [INFO] [stdout] 2025-11-11T09:01:56.626827Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2bef6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd key="key12" [INFO] [stdout] 2025-11-11T09:01:56.627102Z DEBUG cassadilia::cas_manager: Moved blob 2bef6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd to CAS path '/tmp/.tmpeqjczG/cas/2b/ef/6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd' [INFO] [stdout] 2025-11-11T09:01:56.629278Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpeqjczG/cas/bf/26/4d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 [INFO] [stdout] 2025-11-11T09:01:56.629424Z DEBUG cassadilia::transaction: Starting transaction for key '"key13"' using staging file '/tmp/.tmpeqjczG/staging/.tmpZ4P0Wc' [INFO] [stdout] 2025-11-11T09:01:56.629449Z DEBUG cassadilia::transaction: Finishing transaction for key '"key13"' [INFO] [stdout] 2025-11-11T09:01:56.631345Z DEBUG cassadilia::transaction: Committing transaction blob_hash=840fef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba key="key13" [INFO] [stdout] 2025-11-11T09:01:56.631681Z DEBUG cassadilia::cas_manager: Moved blob 840fef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba to CAS path '/tmp/.tmpeqjczG/cas/84/0f/ef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba' [INFO] [stdout] 2025-11-11T09:01:56.635293Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpeqjczG/cas/02/2b/f00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 [INFO] [stdout] 2025-11-11T09:01:56.636284Z DEBUG cassadilia::transaction: Starting transaction for key '"key14"' using staging file '/tmp/.tmpeqjczG/staging/.tmpjpr0wY' [INFO] [stdout] 2025-11-11T09:01:56.636375Z DEBUG cassadilia::transaction: Finishing transaction for key '"key14"' [INFO] [stdout] 2025-11-11T09:01:56.638973Z DEBUG cassadilia::transaction: Committing transaction blob_hash=11587230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00 key="key14" [INFO] [stdout] 2025-11-11T09:01:56.639333Z DEBUG cassadilia::cas_manager: Moved blob 11587230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00 to CAS path '/tmp/.tmpeqjczG/cas/11/58/7230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00' [INFO] [stdout] 2025-11-11T09:01:56.641991Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpeqjczG/cas/ee/ef/0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 [INFO] [stdout] 2025-11-11T09:01:56.642210Z DEBUG cassadilia::transaction: Starting transaction for key '"key15"' using staging file '/tmp/.tmpeqjczG/staging/.tmpD9hvMl' [INFO] [stdout] 2025-11-11T09:01:56.642280Z DEBUG cassadilia::transaction: Finishing transaction for key '"key15"' [INFO] [stdout] 2025-11-11T09:01:56.644648Z DEBUG cassadilia::transaction: Committing transaction blob_hash=d8e1044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e key="key15" [INFO] [stdout] 2025-11-11T09:01:56.645090Z DEBUG cassadilia::cas_manager: Moved blob d8e1044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e to CAS path '/tmp/.tmpeqjczG/cas/d8/e1/044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e' [INFO] [stdout] 2025-11-11T09:01:56.645214Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-11-11T09:01:56.645253Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-11-11T09:01:56.648902Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmpeqjczG/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.649090Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] 2025-11-11T09:01:56.651219Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-11-11T09:01:56.658319Z  INFO cassadilia::index::persistence: Persisted 16 entries to index '/tmp/.tmpeqjczG/index' [INFO] [stdout] 2025-11-11T09:01:56.658381Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-11-11T09:01:56.658499Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpeqjczG/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpeqjczG/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.658536Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 1: /tmp/.tmpeqjczG/1_index.wal [INFO] [stdout] 2025-11-11T09:01:56.658601Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-11-11T09:01:56.658629Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=21 [INFO] [stdout] 2025-11-11T09:01:56.658642Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=21 [INFO] [stdout] 2025-11-11T09:01:56.658753Z DEBUG cassadilia::transaction: Starting transaction for key '"key16"' using staging file '/tmp/.tmpeqjczG/staging/.tmpNl6xuB' [INFO] [stdout] 2025-11-11T09:01:56.658795Z DEBUG cassadilia::transaction: Finishing transaction for key '"key16"' [INFO] [stdout] 2025-11-11T09:01:56.661056Z DEBUG cassadilia::transaction: Committing transaction blob_hash=591c6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d key="key16" [INFO] [stdout] 2025-11-11T09:01:56.661340Z DEBUG cassadilia::cas_manager: Moved blob 591c6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d to CAS path '/tmp/.tmpeqjczG/cas/59/1c/6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d' [INFO] [stdout] 2025-11-11T09:01:56.663082Z DEBUG cassadilia::transaction: Starting transaction for key '"key17"' using staging file '/tmp/.tmpeqjczG/staging/.tmpvIeLI0' [INFO] [stdout] 2025-11-11T09:01:56.663127Z DEBUG cassadilia::transaction: Finishing transaction for key '"key17"' [INFO] [stdout] 2025-11-11T09:01:56.664856Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f1023e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1 key="key17" [INFO] [stdout] 2025-11-11T09:01:56.665068Z DEBUG cassadilia::cas_manager: Moved blob f1023e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1 to CAS path '/tmp/.tmpeqjczG/cas/f1/02/3e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1' [INFO] [stdout] 2025-11-11T09:01:56.666892Z DEBUG cassadilia::transaction: Starting transaction for key '"key18"' using staging file '/tmp/.tmpeqjczG/staging/.tmpMY1iu6' [INFO] [stdout] 2025-11-11T09:01:56.666935Z DEBUG cassadilia::transaction: Finishing transaction for key '"key18"' [INFO] [stdout] 2025-11-11T09:01:56.668514Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7a6268a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90 key="key18" [INFO] [stdout] 2025-11-11T09:01:56.668712Z DEBUG cassadilia::cas_manager: Moved blob 7a6268a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90 to CAS path '/tmp/.tmpeqjczG/cas/7a/62/68a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90' [INFO] [stdout] 2025-11-11T09:01:56.670445Z DEBUG cassadilia::transaction: Starting transaction for key '"key19"' using staging file '/tmp/.tmpeqjczG/staging/.tmp6bplD5' [INFO] [stdout] 2025-11-11T09:01:56.670490Z DEBUG cassadilia::transaction: Finishing transaction for key '"key19"' [INFO] [stdout] 2025-11-11T09:01:56.672135Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f34e40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c key="key19" [INFO] [stdout] 2025-11-11T09:01:56.672353Z DEBUG cassadilia::cas_manager: Moved blob f34e40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c to CAS path '/tmp/.tmpeqjczG/cas/f3/4e/40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c' [INFO] [stdout] 2025-11-11T09:01:56.674125Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.674178Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-11-11T09:01:56.675947Z  INFO cassadilia::index::persistence: Persisted 20 entries to index '/tmp/.tmpeqjczG/index' [INFO] [stdout] 2025-11-11T09:01:56.675985Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-11-11T09:01:56.676086Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpeqjczG/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.676123Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 2). [INFO] [stdout] 2025-11-11T09:01:56.676135Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=25 [INFO] [stdout] 2025-11-11T09:01:56.676147Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=25 [INFO] [stdout] 2025-11-11T09:01:56.676203Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] 2025-11-11T09:01:56.679475Z  INFO cassadilia::index::persistence: Loaded 20 entries from index '/tmp/.tmpeqjczG/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.679584Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpeqjczG/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.679615Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=25 [INFO] [stdout] 2025-11-11T09:01:56.679629Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmpeqjczG/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.679692Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmpeqjczG/2_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.679722Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.679735Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=25 [INFO] [stdout] 2025-11-11T09:01:56.681382Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00160079 total_blobs=20 [INFO] [stdout] 2025-11-11T09:01:56.686066Z  INFO cassadilia::index::persistence: Loaded 20 entries from index '/tmp/.tmpeqjczG/index' and populated ref counts. [INFO] [stdout] 2025-11-11T09:01:56.686208Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpeqjczG/2_index.wal" }] [INFO] [stdout] 2025-11-11T09:01:56.686242Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=25 [INFO] [stdout] 2025-11-11T09:01:56.686256Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmpeqjczG/2_index.wal [INFO] [stdout] 2025-11-11T09:01:56.686326Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmpeqjczG/2_index.wal'. [INFO] [stdout] 2025-11-11T09:01:56.686356Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=0 [INFO] [stdout] 2025-11-11T09:01:56.686368Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=25 [INFO] [stdout] 2025-11-11T09:01:56.687814Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.001399019 total_blobs=20 [INFO] [stdout] test tests::checkpoint::test_checkpoint_persists_overwrites_correctly ... ok [INFO] [stdout] 2025-11-11T09:02:05.464482Z  INFO cassadilia: Pre-created 65,536 CAS directories [INFO] [stdout] 2025-11-11T09:02:06.061314Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8wkuXh/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:02:06.061535Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:02:06.061580Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:02:06.061625Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp8wkuXh/0_index.wal [INFO] [stdout] 2025-11-11T09:02:06.387974Z  INFO cassadilia: Pre-created 65,536 CAS directories [INFO] [stdout] 2025-11-11T09:02:06.797397Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpcEYRqx/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:02:06.797595Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-11-11T09:02:06.797704Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-11-11T09:02:06.797775Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpcEYRqx/0_index.wal [INFO] [stdout] 2025-11-11T09:02:10.324260Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.259540185 total_blobs=0 [INFO] [stdout] 2025-11-11T09:02:10.675913Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=3.834553069 total_blobs=0 [INFO] [stdout] test settings::tests::test_settings_file ... ok [INFO] [stdout] 2025-11-11T09:02:16.445958Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key"' using staging file '/tmp/.tmp8wkuXh/staging/.tmp9Z6SNj' [INFO] [stdout] 2025-11-11T09:02:16.446229Z DEBUG cassadilia::transaction: Finishing transaction for key '"test_key"' [INFO] [stdout] 2025-11-11T09:02:16.447729Z DEBUG cassadilia::transaction: Committing transaction blob_hash=6a953581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef key="test_key" [INFO] [stdout] 2025-11-11T09:02:16.447983Z DEBUG cassadilia::cas_manager: Moved blob 6a953581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef to CAS path '/tmp/.tmp8wkuXh/cas/6a/95/3581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef' [INFO] [stdout] 2025-11-11T09:02:16.448148Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp8wkuXh/0_index.wal [INFO] [stdout] 2025-11-11T09:02:16.448288Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:02:16.449779Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-11-11T09:02:16.450183Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8wkuXh/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-11-11T09:02:16.450433Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8wkuXh/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:02:16.450545Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-11-11T09:02:16.450681Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp8wkuXh/0_index.wal [INFO] [stdout] 2025-11-11T09:02:16.450904Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp8wkuXh/0_index.wal'. [INFO] [stdout] 2025-11-11T09:02:16.451086Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-11-11T09:02:16.451245Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-11-11T09:02:16.451410Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-11-11T09:02:16.451468Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-11-11T09:02:16.453018Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmp8wkuXh/index' [INFO] [stdout] 2025-11-11T09:02:16.453100Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-11-11T09:02:16.453243Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8wkuXh/0_index.wal" }] [INFO] [stdout] 2025-11-11T09:02:16.453322Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-11-11T09:02:16.453359Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:02:16.453408Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-11-11T09:02:18.270687Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=1.8171975599999999 total_blobs=1 [INFO] [stdout] 2025-11-11T09:02:18.270935Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key2"' using staging file '/tmp/.tmp8wkuXh/staging/.tmpH7bsGc' [INFO] [stdout] 2025-11-11T09:02:18.271013Z DEBUG cassadilia::transaction: Finishing transaction for key '"test_key2"' [INFO] [stdout] 2025-11-11T09:02:18.275664Z DEBUG cassadilia::transaction: Committing transaction blob_hash=be8c48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6 key="test_key2" [INFO] [stdout] 2025-11-11T09:02:18.275875Z DEBUG cassadilia::cas_manager: Moved blob be8c48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6 to CAS path '/tmp/.tmp8wkuXh/cas/be/8c/48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6' [INFO] [stdout] 2025-11-11T09:02:18.275951Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp8wkuXh/0_index.wal [INFO] [stdout] 2025-11-11T09:02:18.276012Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-11-11T09:02:18.277451Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test settings::tests::test_pre_create_cas_dirs ... ok [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] [INFO] [stdout] ---- tests::test_io_error_on_staging_file_creation stdout ---- [INFO] [stdout] [INFO] [stdout] thread 'tests::test_io_error_on_staging_file_creation' (62) panicked at src/tests/mod.rs:324:5: [INFO] [stdout] assertion failed: result.is_err() [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x5d0668cfc4e2 - std::backtrace_rs::backtrace::libunwind::trace::ha50a1f28c7a10cf8 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x5d0668cfc4e2 - std::backtrace_rs::backtrace::trace_unsynchronized::h34f8c4ec82a320bc [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x5d0668cfc4e2 - std::sys::backtrace::_print_fmt::h2d23e84e13d343bc [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x5d0668cfc4e2 - ::fmt::hde21067283f7e82e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x5d0668d0dd2f - core::fmt::rt::Argument::fmt::he65307037dca33c6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/fmt/rt.rs:173:76 [INFO] [stdout] 5: 0x5d0668d0dd2f - core::fmt::write::h24186904251c31cb [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/fmt/mod.rs:1469:25 [INFO] [stdout] 6: 0x5d0668cc6853 - std::io::default_write_fmt::h4e8d11c5c4b9cafe [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/io/mod.rs:639:11 [INFO] [stdout] 7: 0x5d0668cc6853 - std::io::Write::write_fmt::ha849be0824d095ef [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/io/mod.rs:1954:13 [INFO] [stdout] 8: 0x5d0668cd3692 - std::sys::backtrace::BacktraceLock::print::he038489aba5894a6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 9: 0x5d0668cd929f - std::panicking::default_hook::{{closure}}::h80a26d916c49679b [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:301:27 [INFO] [stdout] 10: 0x5d0668cd9131 - std::panicking::default_hook::he2e9efee79b3dce9 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:325:9 [INFO] [stdout] 11: 0x5d0668c56cfe - as core::ops::function::Fn>::call::h202f496763929329 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2099:9 [INFO] [stdout] 12: 0x5d0668c56cfe - test::test_main_with_exit_callback::{{closure}}::h805a6913adddaea3 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:145:21 [INFO] [stdout] 13: 0x5d0668cd995f - as core::ops::function::Fn>::call::h2883c9d2dbd4e81c [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2099:9 [INFO] [stdout] 14: 0x5d0668cd995f - std::panicking::panic_with_hook::hf5648b7cec6bc73e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:842:13 [INFO] [stdout] 15: 0x5d0668cd96d6 - std::panicking::panic_handler::{{closure}}::h1b2ed3864ba94359 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:700:13 [INFO] [stdout] 16: 0x5d0668cd37d9 - std::sys::backtrace::__rust_end_short_backtrace::hd0186b2b27f5aaa7 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:174:18 [INFO] [stdout] 17: 0x5d0668cb9a4d - __rustc[f7dae8b92efe1d7a]::rust_begin_unwind [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:698:5 [INFO] [stdout] 18: 0x5d0668d17760 - core::panicking::panic_fmt::hb5d6b83773432920 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panicking.rs:80:14 [INFO] [stdout] 19: 0x5d0668d1773c - core::panicking::panic::h1fe63ac7a400263b [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panicking.rs:150:5 [INFO] [stdout] 20: 0x5d066895d51d - cassadilia::tests::test_io_error_on_staging_file_creation::he9de172a3c60d9b0 [INFO] [stdout] at /opt/rustwide/workdir/src/tests/mod.rs:324:5 [INFO] [stdout] 21: 0x5d066895db27 - cassadilia::tests::test_io_error_on_staging_file_creation::{{closure}}::ha8dca85b153e2baf [INFO] [stdout] at /opt/rustwide/workdir/src/tests/mod.rs:314:48 [INFO] [stdout] 22: 0x5d0668999b56 - core::ops::function::FnOnce::call_once::h9addee896c456886 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 23: 0x5d0668c56b6b - core::ops::function::FnOnce::call_once::h3a2d82edd1a9b770 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 24: 0x5d0668c56b6b - test::__rust_begin_short_backtrace::h85d4fe5033219107 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:663:18 [INFO] [stdout] 25: 0x5d0668c6ab5d - test::run_test_in_process::{{closure}}::h67b48a81b9c9d7b6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:686:74 [INFO] [stdout] 26: 0x5d0668c6ab5d - as core::ops::function::FnOnce<()>>::call_once::h7680585480377cb5 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 27: 0x5d0668c6ab5d - std::panicking::catch_unwind::do_call::hf71351b2657d4002 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:590:40 [INFO] [stdout] 28: 0x5d0668c6ab5d - std::panicking::catch_unwind::h7fcb5c0312d9e172 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:553:19 [INFO] [stdout] 29: 0x5d0668c6ab5d - std::panic::catch_unwind::h5cf3c9bdee894ebe [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panic.rs:359:14 [INFO] [stdout] 30: 0x5d0668c6ab5d - test::run_test_in_process::h1469cb85193a3a25 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:686:27 [INFO] [stdout] 31: 0x5d0668c6ab5d - test::run_test::{{closure}}::h59d45b3cd6453d69 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:607:43 [INFO] [stdout] 32: 0x5d0668c440a4 - test::run_test::{{closure}}::h9baa0c3d443f28c9 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:637:41 [INFO] [stdout] 33: 0x5d0668c440a4 - std::sys::backtrace::__rust_begin_short_backtrace::h97ea8cee4828663e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:158:18 [INFO] [stdout] 34: 0x5d0668c478fa - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h5d7539d5f78cee61 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/thread/mod.rs:562:17 [INFO] [stdout] 35: 0x5d0668c478fa - as core::ops::function::FnOnce<()>>::call_once::he4c551e23c5e9b22 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 36: 0x5d0668c478fa - std::panicking::catch_unwind::do_call::h522b41a6c157aaba [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:590:40 [INFO] [stdout] 37: 0x5d0668c478fa - std::panicking::catch_unwind::h0efbf72006b8e365 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:553:19 [INFO] [stdout] 38: 0x5d0668c478fa - std::panic::catch_unwind::h3b081041e6c97066 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panic.rs:359:14 [INFO] [stdout] 39: 0x5d0668c478fa - std::thread::Builder::spawn_unchecked_::{{closure}}::ha751309815d5d8cf [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/thread/mod.rs:560:30 [INFO] [stdout] 40: 0x5d0668c478fa - core::ops::function::FnOnce::call_once{{vtable.shim}}::h2084b887a5fe25a7 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 41: 0x5d0668ccebcf - as core::ops::function::FnOnce>::call_once::h3adbd6ccf5f737af [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2085:9 [INFO] [stdout] 42: 0x5d0668ccebcf - std::sys::thread::unix::Thread::new::thread_start::hb3dc6483caa1b987 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/thread/unix.rs:124:17 [INFO] [stdout] 43: 0x76ca35efdaa4 - [INFO] [stdout] 44: 0x76ca35f8aa64 - clone [INFO] [stdout] 45: 0x0 - [INFO] [stdout] [INFO] [stdout] ---- wal::tests::append_op_fails_when_segment_rollover_cannot_create_file stdout ---- [INFO] [stdout] [INFO] [stdout] thread 'wal::tests::append_op_fails_when_segment_rollover_cannot_create_file' (80) panicked at src/wal/tests.rs:106:9: [INFO] [stdout] want OpenSegmentWrite, got Ok(WalAppendInfo { version: 3, op_hash: BlobHash("a97aa27894ace3aa4ce112ee883097ea9f4d158b7c55757e1215a5f19dd7de26") }) [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x5d0668cfc4e2 - std::backtrace_rs::backtrace::libunwind::trace::ha50a1f28c7a10cf8 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x5d0668cfc4e2 - std::backtrace_rs::backtrace::trace_unsynchronized::h34f8c4ec82a320bc [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x5d0668cfc4e2 - std::sys::backtrace::_print_fmt::h2d23e84e13d343bc [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x5d0668cfc4e2 - ::fmt::hde21067283f7e82e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x5d0668d0dd2f - core::fmt::rt::Argument::fmt::he65307037dca33c6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/fmt/rt.rs:173:76 [INFO] [stdout] 5: 0x5d0668d0dd2f - core::fmt::write::h24186904251c31cb [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/fmt/mod.rs:1469:25 [INFO] [stdout] 6: 0x5d0668cc6853 - std::io::default_write_fmt::h4e8d11c5c4b9cafe [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/io/mod.rs:639:11 [INFO] [stdout] 7: 0x5d0668cc6853 - std::io::Write::write_fmt::ha849be0824d095ef [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/io/mod.rs:1954:13 [INFO] [stdout] 8: 0x5d0668cd3692 - std::sys::backtrace::BacktraceLock::print::he038489aba5894a6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 9: 0x5d0668cd929f - std::panicking::default_hook::{{closure}}::h80a26d916c49679b [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:301:27 [INFO] [stdout] 10: 0x5d0668cd9131 - std::panicking::default_hook::he2e9efee79b3dce9 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:325:9 [INFO] [stdout] 11: 0x5d0668c56cfe - as core::ops::function::Fn>::call::h202f496763929329 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2099:9 [INFO] [stdout] 12: 0x5d0668c56cfe - test::test_main_with_exit_callback::{{closure}}::h805a6913adddaea3 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:145:21 [INFO] [stdout] 13: 0x5d0668cd995f - as core::ops::function::Fn>::call::h2883c9d2dbd4e81c [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2099:9 [INFO] [stdout] 14: 0x5d0668cd995f - std::panicking::panic_with_hook::hf5648b7cec6bc73e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:842:13 [INFO] [stdout] 15: 0x5d0668cd970a - std::panicking::panic_handler::{{closure}}::h1b2ed3864ba94359 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:707:13 [INFO] [stdout] 16: 0x5d0668cd37d9 - std::sys::backtrace::__rust_end_short_backtrace::hd0186b2b27f5aaa7 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:174:18 [INFO] [stdout] 17: 0x5d0668cb9a4d - __rustc[f7dae8b92efe1d7a]::rust_begin_unwind [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:698:5 [INFO] [stdout] 18: 0x5d0668d17760 - core::panicking::panic_fmt::hb5d6b83773432920 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panicking.rs:80:14 [INFO] [stdout] 19: 0x5d066891b568 - cassadilia::wal::tests::append_op_fails_when_segment_rollover_cannot_create_file::hea17cf02e3e26055 [INFO] [stdout] at /opt/rustwide/workdir/src/wal/tests.rs:106:9 [INFO] [stdout] 20: 0x5d066891b7f7 - cassadilia::wal::tests::append_op_fails_when_segment_rollover_cannot_create_file::{{closure}}::hb6a9190a241fc232 [INFO] [stdout] at /opt/rustwide/workdir/src/wal/tests.rs:87:62 [INFO] [stdout] 21: 0x5d06689991e6 - core::ops::function::FnOnce::call_once::h5366fd298d299148 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 22: 0x5d0668c56b6b - core::ops::function::FnOnce::call_once::h3a2d82edd1a9b770 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 23: 0x5d0668c56b6b - test::__rust_begin_short_backtrace::h85d4fe5033219107 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:663:18 [INFO] [stdout] 24: 0x5d0668c6ab5d - test::run_test_in_process::{{closure}}::h67b48a81b9c9d7b6 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:686:74 [INFO] [stdout] 25: 0x5d0668c6ab5d - as core::ops::function::FnOnce<()>>::call_once::h7680585480377cb5 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 26: 0x5d0668c6ab5d - std::panicking::catch_unwind::do_call::hf71351b2657d4002 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:590:40 [INFO] [stdout] 27: 0x5d0668c6ab5d - std::panicking::catch_unwind::h7fcb5c0312d9e172 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:553:19 [INFO] [stdout] 28: 0x5d0668c6ab5d - std::panic::catch_unwind::h5cf3c9bdee894ebe [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panic.rs:359:14 [INFO] [stdout] 29: 0x5d0668c6ab5d - test::run_test_in_process::h1469cb85193a3a25 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:686:27 [INFO] [stdout] 30: 0x5d0668c6ab5d - test::run_test::{{closure}}::h59d45b3cd6453d69 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:607:43 [INFO] [stdout] 31: 0x5d0668c440a4 - test::run_test::{{closure}}::h9baa0c3d443f28c9 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/test/src/lib.rs:637:41 [INFO] [stdout] 32: 0x5d0668c440a4 - std::sys::backtrace::__rust_begin_short_backtrace::h97ea8cee4828663e [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/backtrace.rs:158:18 [INFO] [stdout] 33: 0x5d0668c478fa - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h5d7539d5f78cee61 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/thread/mod.rs:562:17 [INFO] [stdout] 34: 0x5d0668c478fa - as core::ops::function::FnOnce<()>>::call_once::he4c551e23c5e9b22 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 35: 0x5d0668c478fa - std::panicking::catch_unwind::do_call::h522b41a6c157aaba [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:590:40 [INFO] [stdout] 36: 0x5d0668c478fa - std::panicking::catch_unwind::h0efbf72006b8e365 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panicking.rs:553:19 [INFO] [stdout] 37: 0x5d0668c478fa - std::panic::catch_unwind::h3b081041e6c97066 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/panic.rs:359:14 [INFO] [stdout] 38: 0x5d0668c478fa - std::thread::Builder::spawn_unchecked_::{{closure}}::ha751309815d5d8cf [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/thread/mod.rs:560:30 [INFO] [stdout] 39: 0x5d0668c478fa - core::ops::function::FnOnce::call_once{{vtable.shim}}::h2084b887a5fe25a7 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 40: 0x5d0668ccebcf - as core::ops::function::FnOnce>::call_once::h3adbd6ccf5f737af [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/alloc/src/boxed.rs:2085:9 [INFO] [stdout] 41: 0x5d0668ccebcf - std::sys::thread::unix::Thread::new::thread_start::hb3dc6483caa1b987 [INFO] [stdout] at /rustc/c90bcb9571b7aab0d8beaa2ce8a998ffaf079d38/library/std/src/sys/thread/unix.rs:124:17 [INFO] [stdout] 42: 0x76ca35efdaa4 - [INFO] [stdout] 43: 0x76ca35f8aa64 - clone [INFO] [stdout] 44: 0x0 - [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] failures: [INFO] [stdout] tests::test_io_error_on_staging_file_creation [INFO] [stdout] wal::tests::append_op_fails_when_segment_rollover_cannot_create_file [INFO] [stdout] [INFO] [stdout] test result: FAILED. 66 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 26.79s [INFO] [stdout] [INFO] [stderr] error: test failed, to rerun pass `--lib` [INFO] running `Command { std: "docker" "inspect" "484aafb152c4a9d1f0c49aa66be779f4b5a02bdb8326aaa4b01e2c9ed489c41f", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "484aafb152c4a9d1f0c49aa66be779f4b5a02bdb8326aaa4b01e2c9ed489c41f", kill_on_drop: false }` [INFO] [stdout] 484aafb152c4a9d1f0c49aa66be779f4b5a02bdb8326aaa4b01e2c9ed489c41f