[INFO] fetching crate cassadilia 0.4.2... [INFO] testing cassadilia-0.4.2 against beta-2025-09-21 for beta-1.91-3 [INFO] extracting crate cassadilia 0.4.2 into /workspace/builds/worker-4-tc2/source [INFO] removed /workspace/builds/worker-4-tc2/source/.cargo/config.toml [INFO] started tweaking crates.io crate cassadilia 0.4.2 [INFO] finished tweaking crates.io crate cassadilia 0.4.2 [INFO] tweaked toml for crates.io crate cassadilia 0.4.2 written to /workspace/builds/worker-4-tc2/source/Cargo.toml [INFO] validating manifest of crates.io crate cassadilia 0.4.2 on toolchain beta-2025-09-21 [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+beta-2025-09-21" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] crate crates.io crate cassadilia 0.4.2 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" "+beta-2025-09-21" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2025-09-21" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] f316115838e5ae7cefcb0f181fb1333f1093aeed328cbcbf3d033d1eac5fce5d [INFO] running `Command { std: "docker" "start" "-a" "f316115838e5ae7cefcb0f181fb1333f1093aeed328cbcbf3d033d1eac5fce5d", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "f316115838e5ae7cefcb0f181fb1333f1093aeed328cbcbf3d033d1eac5fce5d", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "f316115838e5ae7cefcb0f181fb1333f1093aeed328cbcbf3d033d1eac5fce5d", kill_on_drop: false }` [INFO] [stdout] f316115838e5ae7cefcb0f181fb1333f1093aeed328cbcbf3d033d1eac5fce5d [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2025-09-21" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 657e715e05e6cfa9976bdab91ac64b35b11b84387ff9061c7f3b19391c14f340 [INFO] running `Command { std: "docker" "start" "-a" "657e715e05e6cfa9976bdab91ac64b35b11b84387ff9061c7f3b19391c14f340", kill_on_drop: false }` [INFO] [stderr] Compiling proc-macro2 v1.0.101 [INFO] [stderr] Compiling unicode-ident v1.0.19 [INFO] [stderr] Compiling libc v0.2.176 [INFO] [stderr] Compiling quote v1.0.41 [INFO] [stderr] Compiling cfg-if v1.0.3 [INFO] [stderr] Compiling crossbeam-utils v0.8.21 [INFO] [stderr] Compiling serde_core v1.0.228 [INFO] [stderr] Compiling getrandom v0.3.3 [INFO] [stderr] Compiling rayon-core v1.13.0 [INFO] [stderr] Compiling find-msvc-tools v0.1.2 [INFO] [stderr] Compiling autocfg v1.5.0 [INFO] [stderr] Compiling once_cell v1.21.3 [INFO] [stderr] Compiling shlex v1.3.0 [INFO] [stderr] Compiling zerocopy v0.8.27 [INFO] [stderr] Compiling rustix v1.1.2 [INFO] [stderr] Compiling crossbeam-epoch v0.9.18 [INFO] [stderr] Compiling cc v1.2.39 [INFO] [stderr] Compiling parking_lot_core v0.9.11 [INFO] [stderr] Compiling lock_api v0.4.13 [INFO] [stderr] Compiling crossbeam-deque v0.8.6 [INFO] [stderr] Compiling ahash v0.8.12 [INFO] [stderr] Compiling smallvec v1.15.1 [INFO] [stderr] Compiling serde_json v1.0.145 [INFO] [stderr] Compiling thiserror v2.0.17 [INFO] [stderr] Compiling linux-raw-sys v0.11.0 [INFO] [stderr] Compiling serde v1.0.228 [INFO] [stderr] Compiling syn v2.0.106 [INFO] [stderr] Compiling bitflags v2.9.4 [INFO] [stderr] Compiling memmap2 v0.9.8 [INFO] [stderr] Compiling tracing-core v0.1.34 [INFO] [stderr] Compiling memchr v2.7.6 [INFO] [stderr] Compiling blake3 v1.8.2 [INFO] [stderr] Compiling fastrand v2.3.0 [INFO] [stderr] Compiling pin-project-lite v0.2.16 [INFO] [stderr] Compiling arrayref v0.3.9 [INFO] [stderr] Compiling ryu v1.0.20 [INFO] [stderr] Compiling arrayvec v0.7.6 [INFO] [stderr] Compiling constant_time_eq v0.3.1 [INFO] [stderr] Compiling itoa v1.0.15 [INFO] [stderr] Compiling parking_lot v0.12.4 [INFO] [stderr] Compiling bytes v1.10.1 [INFO] [stderr] Compiling tempfile v3.23.0 [INFO] [stderr] Compiling tracing-attributes v0.1.30 [INFO] [stderr] Compiling serde_derive v1.0.228 [INFO] [stderr] Compiling thiserror-impl v2.0.17 [INFO] [stderr] Compiling tracing v0.1.41 [INFO] [stderr] Compiling cassadilia v0.4.2 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 35.13s [INFO] running `Command { std: "docker" "inspect" "657e715e05e6cfa9976bdab91ac64b35b11b84387ff9061c7f3b19391c14f340", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "657e715e05e6cfa9976bdab91ac64b35b11b84387ff9061c7f3b19391c14f340", kill_on_drop: false }` [INFO] [stdout] 657e715e05e6cfa9976bdab91ac64b35b11b84387ff9061c7f3b19391c14f340 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2025-09-21" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 3f66ae0cbf720befbd44ce446fe36320a5bd5ea8baef1f243e1f5c5b35dc6c87 [INFO] running `Command { std: "docker" "start" "-a" "3f66ae0cbf720befbd44ce446fe36320a5bd5ea8baef1f243e1f5c5b35dc6c87", kill_on_drop: false }` [INFO] [stderr] Compiling cfg-if v1.0.3 [INFO] [stderr] Compiling once_cell v1.21.3 [INFO] [stderr] Compiling libc v0.2.176 [INFO] [stderr] Compiling crossbeam-utils v0.8.21 [INFO] [stderr] Compiling memchr v2.7.6 [INFO] [stderr] Compiling smallvec v1.15.1 [INFO] [stderr] Compiling object v0.37.3 [INFO] [stderr] Compiling serde_core v1.0.228 [INFO] [stderr] Compiling gimli v0.32.3 [INFO] [stderr] Compiling linux-raw-sys v0.11.0 [INFO] [stderr] Compiling tracing-core v0.1.34 [INFO] [stderr] Compiling bitflags v2.9.4 [INFO] [stderr] Compiling regex-syntax v0.8.6 [INFO] [stderr] Compiling crossbeam-epoch v0.9.18 [INFO] [stderr] Compiling getrandom v0.3.3 [INFO] [stderr] Compiling adler2 v2.0.1 [INFO] [stderr] Compiling pin-project-lite v0.2.16 [INFO] [stderr] Compiling crossbeam-deque v0.8.6 [INFO] [stderr] Compiling scopeguard v1.2.0 [INFO] [stderr] Compiling miniz_oxide v0.8.9 [INFO] [stderr] Compiling lock_api v0.4.13 [INFO] [stderr] Compiling tracing v0.1.41 [INFO] [stderr] Compiling rayon-core v1.13.0 [INFO] [stderr] Compiling parking_lot_core v0.9.11 [INFO] [stderr] Compiling memmap2 v0.9.8 [INFO] [stderr] Compiling rustix v1.1.2 [INFO] [stderr] Compiling zerocopy v0.8.27 [INFO] [stderr] Compiling anyhow v1.0.100 [INFO] [stderr] Compiling itoa v1.0.15 [INFO] [stderr] Compiling fastrand v2.3.0 [INFO] [stderr] Compiling addr2line v0.25.1 [INFO] [stderr] Compiling log v0.4.28 [INFO] [stderr] Compiling lazy_static v1.5.0 [INFO] [stderr] Compiling rustc-demangle v0.1.26 [INFO] [stderr] Compiling arrayref v0.3.9 [INFO] [stderr] Compiling regex-automata v0.4.11 [INFO] [stderr] Compiling ryu v1.0.20 [INFO] [stderr] Compiling constant_time_eq v0.3.1 [INFO] [stderr] Compiling arrayvec v0.7.6 [INFO] [stderr] Compiling serde v1.0.228 [INFO] [stderr] Compiling blake3 v1.8.2 [INFO] [stderr] Compiling serde_json v1.0.145 [INFO] [stderr] Compiling tempfile v3.23.0 [INFO] [stderr] Compiling tracing-log v0.2.0 [INFO] [stderr] Compiling sharded-slab v0.1.7 [INFO] [stderr] Compiling thiserror v2.0.17 [INFO] [stderr] Compiling parking_lot v0.12.4 [INFO] [stderr] Compiling thread_local v1.1.9 [INFO] [stderr] Compiling ahash v0.8.12 [INFO] [stderr] Compiling nu-ansi-term v0.50.1 [INFO] [stderr] Compiling hex v0.4.3 [INFO] [stderr] Compiling matchers v0.2.0 [INFO] [stderr] Compiling bytes v1.10.1 [INFO] [stderr] Compiling tracing-subscriber v0.3.20 [INFO] [stderr] Compiling cassadilia v0.4.2 (/opt/rustwide/workdir) [INFO] [stderr] Compiling backtrace v0.3.76 [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 46.81s [INFO] running `Command { std: "docker" "inspect" "3f66ae0cbf720befbd44ce446fe36320a5bd5ea8baef1f243e1f5c5b35dc6c87", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "3f66ae0cbf720befbd44ce446fe36320a5bd5ea8baef1f243e1f5c5b35dc6c87", kill_on_drop: false }` [INFO] [stdout] 3f66ae0cbf720befbd44ce446fe36320a5bd5ea8baef1f243e1f5c5b35dc6c87 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2025-09-21" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 7cf80d876edc452a95583e440283220b6b4762d94ad5c3109dabbf756e2b9121 [INFO] running `Command { std: "docker" "start" "-a" "7cf80d876edc452a95583e440283220b6b4762d94ad5c3109dabbf756e2b9121", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.14s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/cassadilia-a0a73b0f5543cd05) [INFO] [stdout] [INFO] [stdout] running 68 tests [INFO] [stdout] test io::tests::same_fs_linux ... ok [INFO] [stdout] test serialization::tests::test_btreemap_invalid_data ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_empty ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_last_version_some ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_multiple_keys ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_single_empty_key ... ok [INFO] [stdout] test serialization::tests::test_helper_functions ... ok [INFO] [stdout] test index::tests::test_intent_guard_cleanup_direct_state ... ok [INFO] [stdout] test index::tests::test_intent_guard_multiple_intents_same_key_direct_state ... ok [INFO] [stdout] test serialization::tests::test_helper_functions_errors ... ok [INFO] [stdout] test serialization::tests::test_wal_op_invalid_data ... ok [INFO] [stdout] test serialization::tests::test_wal_op_put_large_key ... ok [INFO] [stdout] test serialization::tests::test_wal_op_remove_empty ... 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] test settings::tests::test_future_version_rejected ... ok [INFO] [stdout] test settings::tests::test_past_version_rejected ... ok [INFO] [stdout] test serialization::tests::test_wal_op_put_empty_key ... ok [INFO] [stdout] test serialization::tests::test_btreemap_serialization_last_version_none ... ok [INFO] [stdout] test index::tests::test_intent_guard_reference_counting_direct_state ... ok [INFO] [stdout] 2025-10-01T07:44:25.572956Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpsWRSYP/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.573030Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.573045Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.573068Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpsWRSYP/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.573099Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.573943Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00075307 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.574949Z  INFO cassadilia: Pre-creating CAS directory tree... [INFO] [stdout] test index::tests::test_index_read_guard_len ... ok [INFO] [stdout] 2025-10-01T07:44:25.583514Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpoOTQEE/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.583513Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpokJGL8/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.583621Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.583625Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.583639Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.583640Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.583663Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpokJGL8/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.583664Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpoOTQEE/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.583791Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpjH4B43/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.584269Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.584288Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.584312Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpjH4B43/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.587104Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00067249 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.587286Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpoOTQEE/staging/.tmplbQqVJ' [INFO] [stdout] 2025-10-01T07:44:25.587426Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-10-01T07:44:25.587640Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.783e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.590564Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00407126 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.590674Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpjH4B43/staging/.tmpKb2dOU' [INFO] [stdout] 2025-10-01T07:44:25.590930Z DEBUG cassadilia::transaction: Committing transaction blob_hash=8b238f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f key="key00" [INFO] [stdout] 2025-10-01T07:44:25.590970Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpsWRSYP/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.591038Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.591187Z DEBUG cassadilia::cas_manager: Moved blob 8b238f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f to CAS path '/tmp/.tmpoOTQEE/cas/8b/23/8f317be0774b380bf423cdf32ff743c4f7c4681e7477b495329019155e1f' [INFO] [stdout] 2025-10-01T07:44:25.591226Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpoOTQEE/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.591248Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.591320Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-10-01T07:44:25.592551Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test index::tests::test_intent_guard_commit_removes_intent ... ok [INFO] [stdout] 2025-10-01T07:44:25.593318Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpoOTQEE/staging/.tmp0qrTns' [INFO] [stdout] 2025-10-01T07:44:25.593567Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e5c858cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c key="key00" [INFO] [stdout] 2025-10-01T07:44:25.593761Z DEBUG cassadilia::cas_manager: Moved blob e5c858cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c to CAS path '/tmp/.tmpjH4B43/cas/e5/c8/58cc2b45f0c423a741c0785b4ec244c7618b7b73d855a1e9b8147eae434c' [INFO] [stdout] 2025-10-01T07:44:25.593783Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpokJGL8/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.593791Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpjH4B43/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.593813Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.593868Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpokJGL8/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.593903Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.593922Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpokJGL8/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.594175Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-10-01T07:44:25.595354Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpokJGL8/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.595574Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.595597Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-10-01T07:44:25.595912Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00011991 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.596072Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpokJGL8/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.596148Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpokJGL8/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.596166Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.596272Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpjH4B43/staging/.tmpk2saYG' [INFO] [stdout] 2025-10-01T07:44:25.596544Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpWEx8lW/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.596631Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.596645Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.596666Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpWEx8lW/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.596841Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-10-01T07:44:25.596900Z DEBUG cassadilia::transaction: Committing transaction blob_hash=58549030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c key="key01" [INFO] [stdout] 2025-10-01T07:44:25.596176Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpokJGL8/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.596983Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpokJGL8/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.597001Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.597012Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-10-01T07:44:25.597090Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.128e-5 total_blobs=0 [INFO] [stdout] test settings::tests::test_immutable_settings_validation ... ok [INFO] [stdout] 2025-10-01T07:44:25.597999Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0003205 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.598779Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpokJGL8/staging/.tmpDcnCMm' [INFO] [stdout] 2025-10-01T07:44:25.599406Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-10-01T07:44:25.604803Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpJoYycM/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.604930Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.604952Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.604978Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpJoYycM/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.605090Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7daf4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca key="key01" [INFO] [stdout] 2025-10-01T07:44:25.605168Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpUcW91W/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.605282Z DEBUG cassadilia::cas_manager: Moved blob 7daf4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca to CAS path '/tmp/.tmpjH4B43/cas/7d/af/4870c31069d381520201dc445fabbd623dd0254163806fda08617a3546ca' [INFO] [stdout] 2025-10-01T07:44:25.605339Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.605561Z DEBUG cassadilia::cas_manager: Moved blob 58549030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c to CAS path '/tmp/.tmpoOTQEE/cas/58/54/9030e11366706bf6c8648f97e6d7e52baa493157aa1ef1679d64f131f93c' [INFO] [stdout] 2025-10-01T07:44:25.606258Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.606327Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpUcW91W/0_index.wal [INFO] [stdout] test io::tests::file_lock ... ok [INFO] [stdout] 2025-10-01T07:44:25.607020Z DEBUG cassadilia::transaction: Committing transaction blob_hash=c4986a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574 key="key00" [INFO] [stdout] 2025-10-01T07:44:25.607333Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0001805 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.607923Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpJoYycM/staging/.tmpWIgEL1' [INFO] [stdout] 2025-10-01T07:44:25.607961Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-10-01T07:44:25.608345Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpoOTQEE/staging/.tmpCWqCr1' [INFO] [stdout] 2025-10-01T07:44:25.608373Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-10-01T07:44:25.608504Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.614e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.608584Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpUcW91W/staging/.tmpSTnwXy' [INFO] [stdout] 2025-10-01T07:44:25.608603Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-10-01T07:44:25.608675Z DEBUG cassadilia::cas_manager: Moved blob c4986a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574 to CAS path '/tmp/.tmpokJGL8/cas/c4/98/6a4567cde92203892070ccc59ae96e88100c4ee650c12bee3eb09324d574' [INFO] [stdout] 2025-10-01T07:44:25.608731Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpokJGL8/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.608755Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.609869Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cd5d9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 key="key1" [INFO] [stdout] 2025-10-01T07:44:25.609954Z DEBUG cassadilia::transaction: Committing transaction blob_hash=549969c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a key="key02" [INFO] [stdout] 2025-10-01T07:44:25.611132Z DEBUG cassadilia::transaction: Committing transaction blob_hash=a739eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0 key="key00" [INFO] [stdout] 2025-10-01T07:44:25.610944Z DEBUG cassadilia::cas_manager: Moved blob cd5d9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 to CAS path '/tmp/.tmpJoYycM/cas/cd/5d/9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340' [INFO] [stdout] 2025-10-01T07:44:25.611343Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpJoYycM/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.611372Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.622945Z DEBUG cassadilia::cas_manager: Moved blob 549969c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a to CAS path '/tmp/.tmpoOTQEE/cas/54/99/69c8f7146d43a1c0f42bd2aa865c704cc491fef4fb887164b48ff1167a1a' [INFO] [stdout] 2025-10-01T07:44:25.623238Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpjH4B43/staging/.tmpFsQStL' [INFO] [stdout] 2025-10-01T07:44:25.623251Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.623435Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpSVGTLU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.623108Z DEBUG cassadilia::cas_manager: Moved blob a739eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0 to CAS path '/tmp/.tmpUcW91W/cas/a7/39/eeab85b32b0d39eaa97be726ef2a5894f8273fb54ea8c17cda5a3e3be9e0' [INFO] [stdout] 2025-10-01T07:44:25.623575Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpUcW91W/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.623678Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-10-01T07:44:25.623684Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.624144Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpokJGL8/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.624347Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpokJGL8/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.624413Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.624431Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpokJGL8/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.624521Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpokJGL8/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.624564Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.624615Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.624870Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.624960Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.624986Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpSVGTLU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.625059Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.625077Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.625794Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpJoYycM/staging/.tmp3gsEej' [INFO] [stdout] 2025-10-01T07:44:25.625853Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-10-01T07:44:25.626218Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.626241Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.626272Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpUcW91W/staging/.tmpg1ol6F' [INFO] [stdout] 2025-10-01T07:44:25.626294Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-10-01T07:44:25.626367Z DEBUG cassadilia::transaction: Committing transaction blob_hash=51cd9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e key="key02" [INFO] [stdout] 2025-10-01T07:44:25.628073Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.0015957 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.629003Z DEBUG cassadilia::transaction: Committing transaction blob_hash=284be493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee key="key1" [INFO] [stdout] 2025-10-01T07:44:25.629026Z DEBUG cassadilia::transaction: Starting transaction for key '"key00"' using staging file '/tmp/.tmpSVGTLU/staging/.tmpQGUJfW' [INFO] [stdout] 2025-10-01T07:44:25.629033Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpokJGL8/index' [INFO] [stdout] 2025-10-01T07:44:25.629080Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 key="key01" [INFO] [stdout] 2025-10-01T07:44:25.629282Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.629165Z DEBUG cassadilia::transaction: Finishing transaction for key '"key00"' [INFO] [stdout] 2025-10-01T07:44:25.629373Z DEBUG cassadilia::cas_manager: Moved blob 284be493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee to CAS path '/tmp/.tmpJoYycM/cas/28/4b/e493da5e8cf2de3c3bf4de5dd28d19ea3e07975e58d32b3c36b04a6ae8ee' [INFO] [stdout] 2025-10-01T07:44:25.629182Z DEBUG cassadilia::cas_manager: Moved blob 51cd9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e to CAS path '/tmp/.tmpjH4B43/cas/51/cd/9402fc08f863ab366f6ed36aa254e28597a0ab6a8f1baa94b0ce1540c04e' [INFO] [stdout] 2025-10-01T07:44:25.629087Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpoOTQEE/index' [INFO] [stdout] 2025-10-01T07:44:25.629456Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.629542Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpoOTQEE/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.629567Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.629579Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=3 [INFO] [stdout] 2025-10-01T07:44:25.629591Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-10-01T07:44:25.629617Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.629720Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpokJGL8/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.629746Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.629755Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.629763Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.630839Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00104302 total_blobs=1 [INFO] [stdout] 2025-10-01T07:44:25.631072Z  INFO cassadilia::index::persistence: Loaded 3 entries from index '/tmp/.tmpoOTQEE/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.631452Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpoOTQEE/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.631512Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=3 [INFO] [stdout] 2025-10-01T07:44:25.631545Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpoOTQEE/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.631725Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpJoYycM/cas/cd/5d/9b6e45fc2098572aefc35b48abf6c81505edcba343900721dfee610e5340 [INFO] [stdout] 2025-10-01T07:44:25.631721Z DEBUG cassadilia::cas_manager: Moved blob 7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 to CAS path '/tmp/.tmpUcW91W/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676' [INFO] [stdout] 2025-10-01T07:44:25.631782Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.631797Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.631801Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmpjH4B43/staging/.tmpoXc73B' [INFO] [stdout] 2025-10-01T07:44:25.631809Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpoOTQEE/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.631824Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] 2025-10-01T07:44:25.631828Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.631840Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=3 [INFO] [stdout] 2025-10-01T07:44:25.632243Z DEBUG cassadilia::transaction: Committing transaction blob_hash=3e21a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359 key="key00" [INFO] [stdout] 2025-10-01T07:44:25.632937Z DEBUG cassadilia::cas_manager: Moved blob 3e21a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359 to CAS path '/tmp/.tmpSVGTLU/cas/3e/21/a4068006bc8f919969e362f5f3ac3e0f589cb770a8b34342fd3b7224c359' [INFO] [stdout] 2025-10-01T07:44:25.633184Z DEBUG cassadilia::transaction: Committing transaction blob_hash=992adda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157 key="key03" [INFO] [stdout] 2025-10-01T07:44:25.633422Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpSVGTLU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.633449Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.633558Z DEBUG cassadilia::cas_manager: Moved blob 992adda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157 to CAS path '/tmp/.tmpjH4B43/cas/99/2a/dda1f42b66cc68a044037ce24619e07f5ce3900c955277f9e35abade2157' [INFO] [stdout] 2025-10-01T07:44:25.633582Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00170034 total_blobs=3 [INFO] [stdout] test tests::checkpoint::test_empty_database_checkpoint_on_first_write ... ok [INFO] [stdout] 2025-10-01T07:44:25.633967Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpJoYycM/index' [INFO] [stdout] 2025-10-01T07:44:25.633986Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.634070Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpJoYycM/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.634095Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.634105Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.634144Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.634193Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.634581Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpUcW91W/staging/.tmpflJ7vY' [INFO] [stdout] 2025-10-01T07:44:25.634671Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-10-01T07:44:25.635434Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmpjH4B43/staging/.tmpaB45Be' [INFO] [stdout] 2025-10-01T07:44:25.635468Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] 2025-10-01T07:44:25.636492Z DEBUG cassadilia::transaction: Committing transaction blob_hash=409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f key="key02" [INFO] [stdout] 2025-10-01T07:44:25.636831Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmpJoYycM/index' and populated ref counts. [INFO] [stdout] test tests::checkpoint::test_checkpoint_prevents_double_replay ... ok [INFO] [stdout] 2025-10-01T07:44:25.637020Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpJoYycM/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.637045Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=2 [INFO] [stdout] 2025-10-01T07:44:25.637057Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpJoYycM/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.637099Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpJoYycM/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.637122Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.637131Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=2 [INFO] [stdout] 2025-10-01T07:44:25.637607Z DEBUG cassadilia::transaction: Starting transaction for key '"key01"' using staging file '/tmp/.tmpSVGTLU/staging/.tmpNmrwBB' [INFO] [stdout] 2025-10-01T07:44:25.637640Z DEBUG cassadilia::transaction: Finishing transaction for key '"key01"' [INFO] [stdout] 2025-10-01T07:44:25.638126Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpz8BUwi/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.638357Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.638379Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.638402Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpz8BUwi/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.638912Z DEBUG cassadilia::cas_manager: Moved blob 409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f to CAS path '/tmp/.tmpUcW91W/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f' [INFO] [stdout] 2025-10-01T07:44:25.639271Z DEBUG cassadilia::transaction: Committing transaction blob_hash=d8fbb1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5 key="key04" [INFO] [stdout] 2025-10-01T07:44:25.639679Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e5a89c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21 key="key01" [INFO] [stdout] 2025-10-01T07:44:25.640840Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.478e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.640861Z DEBUG cassadilia::cas_manager: Moved blob e5a89c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21 to CAS path '/tmp/.tmpSVGTLU/cas/e5/a8/9c89723208444a472878d4887ef85565731bf2c6789ddbc7082040457e21' [INFO] [stdout] test tests::checkpoint::test_overwrite_deletes_old_blob_no_orphans ... ok [INFO] [stdout] 2025-10-01T07:44:25.641228Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmpUcW91W/staging/.tmp2CLYcl' [INFO] [stdout] 2025-10-01T07:44:25.641535Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] 2025-10-01T07:44:25.642353Z DEBUG cassadilia::transaction: Starting transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' using staging file '/tmp/.tmpz8BUwi/staging/.tmpdvQeJ8' [INFO] [stdout] 2025-10-01T07:44:25.642388Z DEBUG cassadilia::transaction: Finishing transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' [INFO] [stdout] 2025-10-01T07:44:25.642370Z DEBUG cassadilia::cas_manager: Moved blob d8fbb1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5 to CAS path '/tmp/.tmpjH4B43/cas/d8/fb/b1336bc105c90af17f12f0a5d7808e445cdcae40324a74c788fa13d7a2b5' [INFO] [stdout] 2025-10-01T07:44:25.643444Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpFKmWJw/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.643537Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.643560Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.643583Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpFKmWJw/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.643781Z DEBUG cassadilia::transaction: Starting transaction for key '"key02"' using staging file '/tmp/.tmpSVGTLU/staging/.tmp3hC3bW' [INFO] [stdout] 2025-10-01T07:44:25.643810Z DEBUG cassadilia::transaction: Finishing transaction for key '"key02"' [INFO] [stdout] 2025-10-01T07:44:25.644020Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmpjH4B43/staging/.tmp3pU6OW' [INFO] [stdout] 2025-10-01T07:44:25.644044Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-10-01T07:44:25.644777Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 key=[115, 97, 109, 101, 32, 107, 101, 121] [INFO] [stdout] 2025-10-01T07:44:25.644857Z DEBUG cassadilia::transaction: Committing transaction blob_hash=68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc key="key03" [INFO] [stdout] 2025-10-01T07:44:25.644941Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00011887 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.644969Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpqFdGOV/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.645043Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.645034Z DEBUG cassadilia::cas_manager: Moved blob 68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc to CAS path '/tmp/.tmpUcW91W/cas/68/e1/d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc' [INFO] [stdout] 2025-10-01T07:44:25.645057Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.645076Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpqFdGOV/0_index.wal [INFO] [stdout] test tests::test_api_on_nonexistent_key ... ok [INFO] [stdout] 2025-10-01T07:44:25.645415Z DEBUG cassadilia::cas_manager: Moved blob 2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 to CAS path '/tmp/.tmpz8BUwi/cas/2b/80/d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50' [INFO] [stdout] 2025-10-01T07:44:25.645447Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpz8BUwi/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.645467Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.646267Z DEBUG cassadilia::transaction: Committing transaction blob_hash=9238706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195 key="key02" [INFO] [stdout] 2025-10-01T07:44:25.646345Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f8165b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2 key="key05" [INFO] [stdout] 2025-10-01T07:44:25.663465Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmpUcW91W/staging/.tmp20Gi62' [INFO] [stdout] 2025-10-01T07:44:25.663922Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] 2025-10-01T07:44:25.664105Z DEBUG cassadilia::transaction: Starting transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' using staging file '/tmp/.tmpz8BUwi/staging/.tmppdWZe3' [INFO] [stdout] 2025-10-01T07:44:25.664175Z DEBUG cassadilia::transaction: Finishing transaction for key '[115, 97, 109, 101, 32, 107, 101, 121]' [INFO] [stdout] 2025-10-01T07:44:25.663625Z DEBUG cassadilia::cas_manager: Moved blob 9238706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195 to CAS path '/tmp/.tmpSVGTLU/cas/92/38/706b442fb58f55eca463f0f0b6fb5d3ee00853b61210178b88ea33e95195' [INFO] [stdout] 2025-10-01T07:44:25.663870Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpw0popM/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.663465Z DEBUG cassadilia::cas_manager: Moved blob f8165b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2 to CAS path '/tmp/.tmpjH4B43/cas/f8/16/5b3c58c0f163fc0aacae0f050d2ba299f3170e772d1d9d5c2435f8c46cc2' [INFO] [stdout] 2025-10-01T07:44:25.664409Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.664429Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.664455Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpw0popM/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.666032Z DEBUG cassadilia::transaction: Committing transaction blob_hash=4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d key="key04" [INFO] [stdout] 2025-10-01T07:44:25.667058Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00079536 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.667094Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.002153751 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.667640Z DEBUG cassadilia::transaction: Starting transaction for key '"key03"' using staging file '/tmp/.tmpSVGTLU/staging/.tmpX7C6KD' [INFO] [stdout] 2025-10-01T07:44:25.667845Z DEBUG cassadilia::transaction: Finishing transaction for key '"key03"' [INFO] [stdout] 2025-10-01T07:44:25.667767Z DEBUG cassadilia::cas_manager: Moved blob 4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d to CAS path '/tmp/.tmpUcW91W/cas/46/07/a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d' [INFO] [stdout] 2025-10-01T07:44:25.668127Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 key=[115, 97, 109, 101, 32, 107, 101, 121] [INFO] [stdout] 2025-10-01T07:44:25.668239Z DEBUG cassadilia::cas_manager: Moved blob 2b80d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50 to CAS path '/tmp/.tmpz8BUwi/cas/2b/80/d6e264690d8a19de16ffa3c3271cd778c96a1bf300c3231cc692786fed50' [INFO] [stdout] 2025-10-01T07:44:25.668293Z DEBUG cassadilia::transaction: Starting transaction for key '"key06"' using staging file '/tmp/.tmpjH4B43/staging/.tmp4UzXV4' [INFO] [stdout] 2025-10-01T07:44:25.668428Z DEBUG cassadilia::transaction: Finishing transaction for key '"key06"' [INFO] [stdout] 2025-10-01T07:44:25.668010Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpqFdGOV/staging/.tmpZQXyBO' [INFO] [stdout] 2025-10-01T07:44:25.668494Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-10-01T07:44:25.669375Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpw0popM/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.669734Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.669734Z DEBUG cassadilia::transaction: Committing transaction blob_hash=82127748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823 key="key03" [INFO] [stdout] 2025-10-01T07:44:25.669994Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpw0popM/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.670126Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.670306Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpw0popM/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.670389Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpw0popM/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.670472Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.670467Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpUcW91W/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.670764Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-10-01T07:44:25.670834Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpUcW91W/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.670853Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.670862Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpUcW91W/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.671129Z DEBUG cassadilia::cas_manager: Moved blob 82127748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823 to CAS path '/tmp/.tmpSVGTLU/cas/82/12/7748252e541c7b3bdfd5b9370d6e1764f374663863d4dcdd1a1845811823' [INFO] [stdout] 2025-10-01T07:44:25.671279Z DEBUG cassadilia::transaction: Committing transaction blob_hash=40eea84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293 key="key06" [INFO] [stdout] 2025-10-01T07:44:25.671279Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f362faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472 key="key1" [INFO] [stdout] 2025-10-01T07:44:25.671469Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpUcW91W/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.671497Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] 2025-10-01T07:44:25.671508Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-10-01T07:44:25.671526Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.671536Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.670490Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.672252Z DEBUG cassadilia::cas_manager: Moved blob f362faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472 to CAS path '/tmp/.tmpqFdGOV/cas/f3/62/faa031d3265e7457430a6907759557c8a983b6f2a31214df75273fe37472' [INFO] [stdout] 2025-10-01T07:44:25.672346Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpqFdGOV/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.672376Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.672556Z DEBUG cassadilia::cas_manager: Moved blob 40eea84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293 to CAS path '/tmp/.tmpjH4B43/cas/40/ee/a84cc0e36fc173385598c36a8beb7dfe908b93c8d0f8cf0a273fb805d293' [INFO] [stdout] test tests::test_cleanup_disabled ... ok [INFO] [stdout] 2025-10-01T07:44:25.675651Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.675676Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.675849Z DEBUG cassadilia::transaction: Starting transaction for key '"key04"' using staging file '/tmp/.tmpSVGTLU/staging/.tmpCvCTPS' [INFO] [stdout] 2025-10-01T07:44:25.676027Z DEBUG cassadilia::transaction: Finishing transaction for key '"key04"' [INFO] [stdout] 2025-10-01T07:44:25.676320Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmparXZw9/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.676401Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.676418Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.676443Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmparXZw9/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.676212Z DEBUG cassadilia::transaction: Starting transaction for key '"key07"' using staging file '/tmp/.tmpjH4B43/staging/.tmpuKoATZ' [INFO] [stdout] 2025-10-01T07:44:25.676499Z DEBUG cassadilia::transaction: Finishing transaction for key '"key07"' [INFO] [stdout] 2025-10-01T07:44:25.678386Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.627e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.678473Z DEBUG cassadilia::transaction: Starting transaction for key '"range_blob"' using staging file '/tmp/.tmparXZw9/staging/.tmpo7efq4' [INFO] [stdout] 2025-10-01T07:44:25.678494Z DEBUG cassadilia::transaction: Finishing transaction for key '"range_blob"' [INFO] [stdout] 2025-10-01T07:44:25.678566Z DEBUG cassadilia::transaction: Committing transaction blob_hash=0d828af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb key="key07" [INFO] [stdout] 2025-10-01T07:44:25.678747Z DEBUG cassadilia::cas_manager: Moved blob 0d828af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb to CAS path '/tmp/.tmpjH4B43/cas/0d/82/8af5e0bdbdb41f026cdf2d1f75e486383fc322c8fc601f308c21ddf00ceb' [INFO] [stdout] 2025-10-01T07:44:25.678856Z  INFO cassadilia::index::persistence: Persisted 5 entries to index '/tmp/.tmpUcW91W/index' [INFO] [stdout] 2025-10-01T07:44:25.678875Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.680036Z DEBUG cassadilia::transaction: Committing transaction blob_hash=22a0b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27 key="key04" [INFO] [stdout] 2025-10-01T07:44:25.680663Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpUcW91W/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.680694Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.680705Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:25.680716Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:25.680749Z DEBUG cassadilia::cas_manager: Moved blob 22a0b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27 to CAS path '/tmp/.tmpSVGTLU/cas/22/a0/b478a78b950b68b18cb61079b51012be4452c570fa98f9b5dba4f6e9bb27' [INFO] [stdout] 2025-10-01T07:44:25.681137Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00038777 total_blobs=5 [INFO] [stdout] 2025-10-01T07:44:25.681168Z DEBUG cassadilia::transaction: Starting transaction for key '"key08"' using staging file '/tmp/.tmpjH4B43/staging/.tmpKDFJoS' [INFO] [stdout] 2025-10-01T07:44:25.681192Z DEBUG cassadilia::transaction: Finishing transaction for key '"key08"' [INFO] [stdout] 2025-10-01T07:44:25.681272Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b8f6b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0 key="range_blob" [INFO] [stdout] 2025-10-01T07:44:25.681374Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmpUcW91W/staging/.tmpeohIl4' [INFO] [stdout] 2025-10-01T07:44:25.681396Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-10-01T07:44:25.681445Z DEBUG cassadilia::cas_manager: Moved blob b8f6b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0 to CAS path '/tmp/.tmparXZw9/cas/b8/f6/b168214bf501f5a4b84bff9e105cc5c1f3851b798dcb55ffe887391e84b0' [INFO] [stdout] 2025-10-01T07:44:25.681477Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmparXZw9/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.681529Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] test tests::regression_put_same_content_should_not_delete_blob ... ok [INFO] [stdout] 2025-10-01T07:44:25.683691Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b230a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843 key="key08" [INFO] [stdout] 2025-10-01T07:44:25.683785Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.683954Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2f5899145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3 key="key05" [INFO] [stdout] 2025-10-01T07:44:25.683902Z DEBUG cassadilia::cas_manager: Moved blob b230a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843 to CAS path '/tmp/.tmpjH4B43/cas/b2/30/a71283381b75647c675fcb43daf84115851f6255178bb93a935f49349843' [INFO] [stdout] 2025-10-01T07:44:25.684620Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpqFdGOV/index' [INFO] [stdout] 2025-10-01T07:44:25.684997Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.685231Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpqFdGOV/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.685784Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.686046Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.686004Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.686915Z DEBUG cassadilia::transaction: Starting transaction for key '"key09"' using staging file '/tmp/.tmpjH4B43/staging/.tmpi78Ds7' [INFO] [stdout] 2025-10-01T07:44:25.686929Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpBGtXnw/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.686948Z DEBUG cassadilia::transaction: Finishing transaction for key '"key09"' [INFO] [stdout] 2025-10-01T07:44:25.687011Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.687033Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.687055Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpBGtXnw/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.686256Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.687125Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.687496Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpSVGTLU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.688334Z DEBUG cassadilia::transaction: Committing transaction blob_hash=600c41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81 key="key09" [INFO] [stdout] 2025-10-01T07:44:25.688400Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.964e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.688506Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key"' using staging file '/tmp/.tmpBGtXnw/staging/.tmp2tulPk' [INFO] [stdout] 2025-10-01T07:44:25.688526Z DEBUG cassadilia::cas_manager: Moved blob 600c41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81 to CAS path '/tmp/.tmpjH4B43/cas/60/0c/41b30aef01961df9b4d93fe56c5b0bd2d8b7ec60767a4f0135a712e16a81' [INFO] [stdout] 2025-10-01T07:44:25.690165Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmpqFdGOV/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.694228Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpSVGTLU/0_index.wal" }] [INFO] [stdout] test tests::test_get_range ... ok [INFO] [stdout] 2025-10-01T07:44:25.694350Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpqFdGOV/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.687140Z DEBUG cassadilia::cas_manager: Moved blob 2f5899145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3 to CAS path '/tmp/.tmpUcW91W/cas/2f/58/99145239bb665c524eda56584e5e995df3dd675d5a78353262fcf61411b3' [INFO] [stdout] 2025-10-01T07:44:25.694302Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.694434Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpSVGTLU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.694554Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpSVGTLU/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.694574Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] 2025-10-01T07:44:25.694585Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-10-01T07:44:25.694608Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 1 (for next op version 6) exists at path: /tmp/.tmpSVGTLU/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.694683Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpUcW91W/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.694705Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.694777Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=1 [INFO] [stdout] 2025-10-01T07:44:25.694789Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpqFdGOV/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.699012Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpqFdGOV/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.699044Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.699656Z DEBUG cassadilia::transaction: Starting transaction for key '"key10"' using staging file '/tmp/.tmpjH4B43/staging/.tmpgm5L2r' [INFO] [stdout] 2025-10-01T07:44:25.699722Z DEBUG cassadilia::transaction: Finishing transaction for key '"key10"' [INFO] [stdout] 2025-10-01T07:44:25.699734Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.700018Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00020638 total_blobs=1 [INFO] [stdout] 2025-10-01T07:44:25.701175Z DEBUG cassadilia::transaction: Committing transaction blob_hash=c2fe34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 key="key10" [INFO] [stdout] 2025-10-01T07:44:25.701535Z DEBUG cassadilia::cas_manager: Moved blob c2fe34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 to CAS path '/tmp/.tmpjH4B43/cas/c2/fe/34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5' [INFO] [stdout] 2025-10-01T07:44:25.701586Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:25.701598Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.702932Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpjH4B43/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.703003Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.704296Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-10-01T07:44:25.705779Z  INFO cassadilia::index::persistence: Persisted 11 entries to index '/tmp/.tmpjH4B43/index' [INFO] [stdout] 2025-10-01T07:44:25.705803Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-10-01T07:44:25.705913Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpjH4B43/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpjH4B43/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.705948Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpjH4B43/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.706018Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:25.706033Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=11 [INFO] [stdout] 2025-10-01T07:44:25.706044Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=11 [INFO] [stdout] 2025-10-01T07:44:25.706138Z DEBUG cassadilia::transaction: Starting transaction for key '"key11"' using staging file '/tmp/.tmpjH4B43/staging/.tmpaNqaYZ' [INFO] [stdout] 2025-10-01T07:44:25.706161Z DEBUG cassadilia::transaction: Finishing transaction for key '"key11"' [INFO] [stdout] 2025-10-01T07:44:25.710584Z DEBUG cassadilia::transaction: Committing transaction blob_hash=6b786ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 key="key11" [INFO] [stdout] 2025-10-01T07:44:25.710776Z DEBUG cassadilia::cas_manager: Moved blob 6b786ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 to CAS path '/tmp/.tmpjH4B43/cas/6b/78/6ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413' [INFO] [stdout] 2025-10-01T07:44:25.712645Z DEBUG cassadilia::transaction: Starting transaction for key '"key12"' using staging file '/tmp/.tmpjH4B43/staging/.tmp2eHCd6' [INFO] [stdout] 2025-10-01T07:44:25.712680Z DEBUG cassadilia::transaction: Finishing transaction for key '"key12"' [INFO] [stdout] 2025-10-01T07:44:25.714727Z DEBUG cassadilia::transaction: Committing transaction blob_hash=bf264d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 key="key12" [INFO] [stdout] 2025-10-01T07:44:25.714935Z DEBUG cassadilia::cas_manager: Moved blob bf264d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 to CAS path '/tmp/.tmpjH4B43/cas/bf/26/4d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579' [INFO] [stdout] 2025-10-01T07:44:25.718233Z DEBUG cassadilia::transaction: Starting transaction for key '"key13"' using staging file '/tmp/.tmpjH4B43/staging/.tmp6x3Vud' [INFO] [stdout] 2025-10-01T07:44:25.718266Z DEBUG cassadilia::transaction: Finishing transaction for key '"key13"' [INFO] [stdout] 2025-10-01T07:44:25.763696Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.763753Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.764819Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpDpQpun/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.764928Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.764948Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.764972Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpDpQpun/0_index.wal [INFO] [stdout] test tests::test_checkpoint_persists_index ... ok [INFO] [stdout] 2025-10-01T07:44:25.765307Z DEBUG cassadilia::transaction: Committing transaction blob_hash=022bf00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 key="key13" [INFO] [stdout] 2025-10-01T07:44:25.766059Z DEBUG cassadilia::cas_manager: Moved blob 022bf00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 to CAS path '/tmp/.tmpjH4B43/cas/02/2b/f00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938' [INFO] [stdout] 2025-10-01T07:44:25.766520Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=7.162e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.766607Z DEBUG cassadilia::transaction: Starting transaction for key '"valid_key1"' using staging file '/tmp/.tmpDpQpun/staging/.tmp6wQxfx' [INFO] [stdout] 2025-10-01T07:44:25.766629Z DEBUG cassadilia::transaction: Finishing transaction for key '"valid_key1"' [INFO] [stdout] 2025-10-01T07:44:25.767005Z DEBUG cassadilia::transaction: Starting transaction for key '"key06"' using staging file '/tmp/.tmpUcW91W/staging/.tmp1aybXG' [INFO] [stdout] 2025-10-01T07:44:25.767033Z DEBUG cassadilia::transaction: Finishing transaction for key '"key06"' [INFO] [stdout] 2025-10-01T07:44:25.767565Z  INFO cassadilia::index::persistence: Persisted 5 entries to index '/tmp/.tmpSVGTLU/index' [INFO] [stdout] 2025-10-01T07:44:25.767590Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.767685Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpSVGTLU/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpSVGTLU/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.767801Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.767813Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:25.767823Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:25.768090Z DEBUG cassadilia::transaction: Starting transaction for key '"key14"' using staging file '/tmp/.tmpjH4B43/staging/.tmp0QE6xH' [INFO] [stdout] 2025-10-01T07:44:25.768121Z DEBUG cassadilia::transaction: Finishing transaction for key '"key14"' [INFO] [stdout] 2025-10-01T07:44:25.768394Z DEBUG cassadilia::transaction: Committing transaction blob_hash=983ad14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244 key="key06" [INFO] [stdout] 2025-10-01T07:44:25.768495Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f key="valid_key1" [INFO] [stdout] 2025-10-01T07:44:25.768598Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpwUwJvO/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.768684Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.768700Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.768724Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpwUwJvO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.769167Z DEBUG cassadilia::cas_manager: Moved blob cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f to CAS path '/tmp/.tmpDpQpun/cas/cd/f3/15a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f' [INFO] [stdout] 2025-10-01T07:44:25.769205Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpDpQpun/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.769226Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.769390Z DEBUG cassadilia::transaction: Committing transaction blob_hash=eeef0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 key="key14" [INFO] [stdout] 2025-10-01T07:44:25.770056Z DEBUG cassadilia::cas_manager: Moved blob 983ad14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244 to CAS path '/tmp/.tmpUcW91W/cas/98/3a/d14be5c0e05f5f9cd121ecb76c248e547922a3a1e0c40ad63c0565e30244' [INFO] [stdout] 2025-10-01T07:44:25.770210Z DEBUG cassadilia::cas_manager: Moved blob eeef0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 to CAS path '/tmp/.tmpjH4B43/cas/ee/ef/0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877' [INFO] [stdout] 2025-10-01T07:44:25.772065Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00160999 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.772167Z DEBUG cassadilia::transaction: Starting transaction for key '"valid_key1"' using staging file '/tmp/.tmpwUwJvO/staging/.tmpYBiMi7' [INFO] [stdout] 2025-10-01T07:44:25.772194Z DEBUG cassadilia::transaction: Finishing transaction for key '"valid_key1"' [INFO] [stdout] 2025-10-01T07:44:25.772360Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00449997 total_blobs=5 [INFO] [stdout] 2025-10-01T07:44:25.772411Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-10-01T07:44:25.772451Z DEBUG cassadilia::transaction: Starting transaction for key '"key05"' using staging file '/tmp/.tmpSVGTLU/staging/.tmpuFauJq' [INFO] [stdout] 2025-10-01T07:44:25.772472Z DEBUG cassadilia::transaction: Finishing transaction for key '"key05"' [INFO] [stdout] 2025-10-01T07:44:25.772810Z  INFO cassadilia::index::persistence: Loaded 11 entries from index '/tmp/.tmpjH4B43/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.772913Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpjH4B43/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.772932Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=11 [INFO] [stdout] 2025-10-01T07:44:25.772944Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpjH4B43/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.773026Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpjH4B43/1_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.773044Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=4 [INFO] [stdout] 2025-10-01T07:44:25.773054Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=4 highest_op_version=15 [INFO] [stdout] 2025-10-01T07:44:25.773073Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.773084Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.773357Z DEBUG cassadilia::transaction: Starting transaction for key '"key07"' using staging file '/tmp/.tmpUcW91W/staging/.tmpVZC3Ta' [INFO] [stdout] 2025-10-01T07:44:25.773386Z DEBUG cassadilia::transaction: Finishing transaction for key '"key07"' [INFO] [stdout] 2025-10-01T07:44:25.773545Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.774033Z DEBUG cassadilia::transaction: Committing transaction blob_hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f key="valid_key1" [INFO] [stdout] 2025-10-01T07:44:25.774731Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpDpQpun/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.774811Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDpQpun/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.774829Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.774840Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpDpQpun/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.774897Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpDpQpun/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.774891Z DEBUG cassadilia::transaction: Committing transaction blob_hash=e1adf0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9 key="key05" [INFO] [stdout] 2025-10-01T07:44:25.774916Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.774927Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.774946Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.774956Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.775013Z DEBUG cassadilia::cas_manager: Moved blob cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f to CAS path '/tmp/.tmpwUwJvO/cas/cd/f3/15a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f' [INFO] [stdout] 2025-10-01T07:44:25.775045Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpwUwJvO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.775068Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.775071Z DEBUG cassadilia::cas_manager: Moved blob e1adf0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9 to CAS path '/tmp/.tmpSVGTLU/cas/e1/ad/f0a000db31748e36902436adb350e41197faf7375298faefb7fa2cae9ba9' [INFO] [stdout] 2025-10-01T07:44:25.775111Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpSVGTLU/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.775110Z DEBUG cassadilia::transaction: Committing transaction blob_hash=760ca58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb key="key07" [INFO] [stdout] 2025-10-01T07:44:25.775133Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.775275Z DEBUG cassadilia::cas_manager: Moved blob 760ca58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb to CAS path '/tmp/.tmpUcW91W/cas/76/0c/a58ec3df7085c57928fe29694647cb011a9dbb8b4fd0d5cf74819bfa90eb' [INFO] [stdout] 2025-10-01T07:44:25.775289Z  INFO cassadilia::index::persistence: Persisted 15 entries to index '/tmp/.tmpjH4B43/index' [INFO] [stdout] 2025-10-01T07:44:25.775305Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-10-01T07:44:25.775421Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpjH4B43/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.775446Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 1). [INFO] [stdout] 2025-10-01T07:44:25.775455Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=15 [INFO] [stdout] 2025-10-01T07:44:25.775465Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=15 [INFO] [stdout] 2025-10-01T07:44:25.776785Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.776813Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.776995Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpwUwJvO/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.777066Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpwUwJvO/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.777082Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.777092Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpwUwJvO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.777133Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpwUwJvO/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.777154Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.777164Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.777182Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.777191Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.777386Z  INFO cassadilia::index::persistence: Loaded 5 entries from index '/tmp/.tmpUcW91W/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.777395Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpDpQpun/index' [INFO] [stdout] 2025-10-01T07:44:25.777412Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.777474Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpUcW91W/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.777490Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpDpQpun/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.777497Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=5 [INFO] [stdout] 2025-10-01T07:44:25.777506Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.777507Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpUcW91W/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.777515Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.777525Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.777587Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpUcW91W/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.777605Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=3 [INFO] [stdout] 2025-10-01T07:44:25.777615Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=3 highest_op_version=8 [INFO] [stdout] 2025-10-01T07:44:25.777633Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.777642Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.777740Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-10-01T07:44:25.777867Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00236911 total_blobs=15 [INFO] [stdout] 2025-10-01T07:44:25.777996Z DEBUG cassadilia::transaction: Starting transaction for key '"key10"' using staging file '/tmp/.tmpjH4B43/staging/.tmp9iUVdH' [INFO] [stdout] 2025-10-01T07:44:25.778017Z DEBUG cassadilia::transaction: Finishing transaction for key '"key10"' [INFO] [stdout] 2025-10-01T07:44:25.782254Z  INFO cassadilia::orphan: Deleted orphaned blob hash=2b2e0f3ac5c07ce0e1a48cbac77e3efcc4b21d58de0826c22319ddb123e4432f [INFO] [stdout] 2025-10-01T07:44:25.783800Z DEBUG cassadilia::transaction: Committing transaction blob_hash=74c13e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e key="key10" [INFO] [stdout] 2025-10-01T07:44:25.784287Z  INFO cassadilia::index::persistence: Persisted 8 entries to index '/tmp/.tmpUcW91W/index' [INFO] [stdout] 2025-10-01T07:44:25.784312Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.784330Z  INFO cassadilia::index::persistence: Persisted 6 entries to index '/tmp/.tmpSVGTLU/index' [INFO] [stdout] 2025-10-01T07:44:25.784348Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-10-01T07:44:25.784404Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpUcW91W/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.784425Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.784435Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=8 [INFO] [stdout] 2025-10-01T07:44:25.784446Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=8 [INFO] [stdout] 2025-10-01T07:44:25.784438Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpSVGTLU/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpSVGTLU/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.784458Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpSVGTLU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.784517Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:25.784529Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=6 [INFO] [stdout] 2025-10-01T07:44:25.784539Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=6 [INFO] [stdout] 2025-10-01T07:44:25.784802Z DEBUG cassadilia::cas_manager: Moved blob 74c13e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e to CAS path '/tmp/.tmpjH4B43/cas/74/c1/3e56f64bbf12a0b5b010b2f289d174cda38aadd7b227f65af4e87b87078e' [INFO] [stdout] 2025-10-01T07:44:25.784836Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpjH4B43/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.784858Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.785073Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00059025 total_blobs=8 [INFO] [stdout] test tests::test_orphan_detection_and_cleanup ... ok [INFO] [stdout] 2025-10-01T07:44:25.785256Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] test tests::checkpoint::test_replay_creates_checkpoint_after_restart ... ok [INFO] [stdout] 2025-10-01T07:44:25.790121Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpwUwJvO/index' [INFO] [stdout] 2025-10-01T07:44:25.790145Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.790226Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpwUwJvO/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.790246Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.790255Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.790265Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.790407Z ERROR cassadilia::orphan: Corrupted blob detected hash=cdf315a98d4330519b10c8c3a3965000d21a130b83f94fe6e172227923b07d5f expected_meta=ExpectedMeta { blob_size: 12 } [INFO] [stdout] 2025-10-01T07:44:25.790477Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=1 staging_files=0 scan_time=0.00017686 total_blobs=1 [INFO] [stdout] test tests::test_orphan_detection_with_integrity_check ... ok [INFO] [stdout] 2025-10-01T07:44:25.795039Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpCwJsRl/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.795131Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.795148Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.795170Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpCwJsRl/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.796727Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpRgbWao/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.796821Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.796836Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.796861Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpRgbWao/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.803045Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpjH4B43/cas/c2/fe/34f9a080b55c101dc9d336438763ddbe757f11ef794b602458e26a21ffe5 [INFO] [stdout] 2025-10-01T07:44:25.803566Z  INFO cassadilia::index::persistence: Loaded 6 entries from index '/tmp/.tmpSVGTLU/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.803664Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpSVGTLU/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.803684Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=6 [INFO] [stdout] 2025-10-01T07:44:25.803697Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpSVGTLU/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.803753Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpSVGTLU/1_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.803773Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.803785Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=6 [INFO] [stdout] 2025-10-01T07:44:25.804605Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.552e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.804909Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpRgbWao/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.804979Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpRgbWao/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.804996Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.805004Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpRgbWao/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.805029Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpRgbWao/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.805043Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.805053Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 [INFO] [stdout] 2025-10-01T07:44:25.805229Z  INFO cassadilia::orphan: Deleted orphaned blob hash=aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3 [INFO] [stdout] 2025-10-01T07:44:25.807070Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00410844 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.807167Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpCwJsRl/staging/.tmpcAacJh' [INFO] [stdout] 2025-10-01T07:44:25.807190Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-10-01T07:44:25.807312Z DEBUG cassadilia::transaction: Starting transaction for key '"key11"' using staging file '/tmp/.tmpjH4B43/staging/.tmpWXWpfr' [INFO] [stdout] 2025-10-01T07:44:25.807342Z DEBUG cassadilia::transaction: Finishing transaction for key '"key11"' [INFO] [stdout] 2025-10-01T07:44:25.807828Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00388479 total_blobs=6 [INFO] [stdout] 2025-10-01T07:44:25.815981Z DEBUG cassadilia::transaction: Committing transaction blob_hash=86339d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58 key="key11" [INFO] [stdout] 2025-10-01T07:44:25.816245Z DEBUG cassadilia::cas_manager: Moved blob 86339d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58 to CAS path '/tmp/.tmpjH4B43/cas/86/33/9d2a113359e47d6335318e526d87cccad2c647633cd9b2130a6d11cf2e58' [INFO] [stdout] 2025-10-01T07:44:25.816446Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 key="key1" [INFO] [stdout] 2025-10-01T07:44:25.816629Z DEBUG cassadilia::cas_manager: Moved blob b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 to CAS path '/tmp/.tmpCwJsRl/cas/b6/e3/82289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22' [INFO] [stdout] 2025-10-01T07:44:25.816664Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpCwJsRl/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.816688Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.818076Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpjH4B43/cas/6b/78/6ef158450a90c98f422b22808925948a61428b6b72fda90216a7bb2fb413 [INFO] [stdout] 2025-10-01T07:44:25.818183Z DEBUG cassadilia::transaction: Starting transaction for key '"key12"' using staging file '/tmp/.tmpjH4B43/staging/.tmpgCByRg' [INFO] [stdout] 2025-10-01T07:44:25.818202Z DEBUG cassadilia::transaction: Finishing transaction for key '"key12"' [INFO] [stdout] 2025-10-01T07:44:25.821268Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2bef6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd key="key12" [INFO] [stdout] 2025-10-01T07:44:25.821476Z DEBUG cassadilia::cas_manager: Moved blob 2bef6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd to CAS path '/tmp/.tmpjH4B43/cas/2b/ef/6d996a68d9ace889cd81ab739fe0408a00dd06046ac1eca9de4a86b23ccd' [INFO] [stdout] 2025-10-01T07:44:25.823332Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.823392Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpjH4B43/cas/bf/26/4d7f3851008e6ba34171bc9b1d1c46999b67c2ab7ae74afa0210146da579 [INFO] [stdout] 2025-10-01T07:44:25.823482Z DEBUG cassadilia::transaction: Starting transaction for key '"key13"' using staging file '/tmp/.tmpjH4B43/staging/.tmpfiYxbU' [INFO] [stdout] 2025-10-01T07:44:25.823504Z DEBUG cassadilia::transaction: Finishing transaction for key '"key13"' [INFO] [stdout] 2025-10-01T07:44:25.823553Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpCwJsRl/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.823637Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpCwJsRl/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.823657Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.823667Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpCwJsRl/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.823716Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpCwJsRl/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.823733Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.823744Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.823762Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.823773Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.825144Z DEBUG cassadilia::transaction: Committing transaction blob_hash=840fef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba key="key13" [INFO] [stdout] 2025-10-01T07:44:25.825967Z DEBUG cassadilia::cas_manager: Moved blob 840fef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba to CAS path '/tmp/.tmpjH4B43/cas/84/0f/ef00251a910c284e237a8ac74883de1a1d7af5a206afca8213fa2aa5a8ba' [INFO] [stdout] 2025-10-01T07:44:25.826221Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpCwJsRl/index' [INFO] [stdout] 2025-10-01T07:44:25.826239Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.826310Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpCwJsRl/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.826328Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.826337Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.826347Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.826663Z  INFO cassadilia::orphan: Quarantined orphaned blob hash=aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3 dest="/tmp/.tmpCwJsRl/quarantine/aa13b58b0bf7dad737cccadc8dba4f966d58f57c61c864c6e8228164358256f3" [INFO] [stdout] test tests::test_orphan_stats_holds_lock ... ok [INFO] [stdout] test tests::test_orphan_quarantine ... ok [INFO] [stdout] 2025-10-01T07:44:25.830618Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpjH4B43/cas/02/2b/f00ea24955df1ffd5f4de80b676435a254dbab8fe0067b4f4794c6290938 [INFO] [stdout] 2025-10-01T07:44:25.830717Z DEBUG cassadilia::transaction: Starting transaction for key '"key14"' using staging file '/tmp/.tmpjH4B43/staging/.tmpSJGk5T' [INFO] [stdout] 2025-10-01T07:44:25.830747Z DEBUG cassadilia::transaction: Finishing transaction for key '"key14"' [INFO] [stdout] 2025-10-01T07:44:25.832142Z DEBUG cassadilia::transaction: Committing transaction blob_hash=11587230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00 key="key14" [INFO] [stdout] 2025-10-01T07:44:25.833149Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpP0ULkU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.833237Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.833250Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.833273Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpP0ULkU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.835128Z DEBUG cassadilia::cas_manager: Moved blob 11587230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00 to CAS path '/tmp/.tmpjH4B43/cas/11/58/7230fea50d75fc5c9cb733010a5c12f75426287ed081e5efd2a31cbdef00' [INFO] [stdout] 2025-10-01T07:44:25.836098Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.602e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.836178Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpP0ULkU/staging/.tmpfbINJq' [INFO] [stdout] 2025-10-01T07:44:25.836199Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] test tests::checkpoint::test_wal_segment_rollover_triggers_checkpoint ... ok [INFO] [stdout] 2025-10-01T07:44:25.836354Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp9QXOPD/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.836461Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp8ICP4C/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.837768Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.837794Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.837818Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp8ICP4C/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.837939Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.837963Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.837986Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp9QXOPD/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.838130Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 key="key1" [INFO] [stdout] 2025-10-01T07:44:25.839312Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.698e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.839409Z DEBUG cassadilia::transaction: Starting transaction for key '[109, 121, 95, 98, 121, 116, 101, 115, 95, 98, 108, 111, 98]' using staging file '/tmp/.tmp8ICP4C/staging/.tmpXeCbzV' [INFO] [stdout] 2025-10-01T07:44:25.839436Z DEBUG cassadilia::transaction: Finishing transaction for key '[109, 121, 95, 98, 121, 116, 101, 115, 95, 98, 108, 111, 98]' [INFO] [stdout] 2025-10-01T07:44:25.839623Z DEBUG cassadilia::cas_manager: Moved blob b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 to CAS path '/tmp/.tmpP0ULkU/cas/b6/e3/82289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22' [INFO] [stdout] 2025-10-01T07:44:25.839660Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpP0ULkU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.839682Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.840305Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpjH4B43/cas/ee/ef/0fe5509d1d8747688deb5189fbfdf1f99c790e1022b53084fe0c9e25a877 [INFO] [stdout] 2025-10-01T07:44:25.841118Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmppDnsLr/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.841247Z DEBUG cassadilia::transaction: Starting transaction for key '"key15"' using staging file '/tmp/.tmpjH4B43/staging/.tmp2rAOcd' [INFO] [stdout] 2025-10-01T07:44:25.841286Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=4.543e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.841433Z DEBUG cassadilia::transaction: Finishing transaction for key '"key15"' [INFO] [stdout] 2025-10-01T07:44:25.841513Z DEBUG cassadilia::transaction: Starting transaction for key '"overwrite_test"' using staging file '/tmp/.tmp9QXOPD/staging/.tmpPQsDCd' [INFO] [stdout] 2025-10-01T07:44:25.841536Z DEBUG cassadilia::transaction: Finishing transaction for key '"overwrite_test"' [INFO] [stdout] 2025-10-01T07:44:25.841312Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.841599Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.841623Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmppDnsLr/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.841303Z 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-10-01T07:44:25.842401Z DEBUG cassadilia::cas_manager: Moved blob 5926801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6 to CAS path '/tmp/.tmp8ICP4C/cas/59/26/801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6' [INFO] [stdout] 2025-10-01T07:44:25.842444Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp8ICP4C/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.842468Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.843326Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00070327 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.843387Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.843417Z DEBUG cassadilia::transaction: Starting transaction for key '"my_first_blob"' using staging file '/tmp/.tmppDnsLr/staging/.tmpF1wqvv' [INFO] [stdout] 2025-10-01T07:44:25.843437Z DEBUG cassadilia::transaction: Finishing transaction for key '"my_first_blob"' [INFO] [stdout] 2025-10-01T07:44:25.844920Z DEBUG cassadilia::transaction: Committing transaction blob_hash=a6e7f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 key="overwrite_test" [INFO] [stdout] 2025-10-01T07:44:25.845075Z DEBUG cassadilia::cas_manager: Moved blob a6e7f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 to CAS path '/tmp/.tmp9QXOPD/cas/a6/e7/f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5' [INFO] [stdout] 2025-10-01T07:44:25.845102Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp9QXOPD/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.845121Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.845278Z DEBUG cassadilia::transaction: Committing transaction blob_hash=d8e1044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e key="key15" [INFO] [stdout] 2025-10-01T07:44:25.846412Z DEBUG cassadilia::cas_manager: Moved blob d8e1044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e to CAS path '/tmp/.tmpjH4B43/cas/d8/e1/044299623a8c5a69ac85299b0c1bee5296749eb81b398165b1db141f192e' [INFO] [stdout] 2025-10-01T07:44:25.846457Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-10-01T07:44:25.846468Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-10-01T07:44:25.846716Z DEBUG cassadilia::transaction: Committing transaction blob_hash=3e5cebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 key="my_first_blob" [INFO] [stdout] 2025-10-01T07:44:25.847958Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmp8ICP4C/cas/59/26/801fac07b300531ff182c815f42c1d11a65c72fb365204de81d2d00acff6 [INFO] [stdout] 2025-10-01T07:44:25.848006Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.848057Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmpjH4B43/2_index.wal [INFO] [stdout] 2025-10-01T07:44:25.848117Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] 2025-10-01T07:44:25.848180Z DEBUG cassadilia::cas_manager: Moved blob 3e5cebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 to CAS path '/tmp/.tmppDnsLr/cas/3e/5c/ebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7' [INFO] [stdout] 2025-10-01T07:44:25.848211Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmppDnsLr/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.848229Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.848315Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.848536Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp9QXOPD/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.848617Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp9QXOPD/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.848636Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.848647Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp9QXOPD/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.848694Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp9QXOPD/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.848719Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.848730Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.848753Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.848764Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] test tests::test_put_get_remove_bytes_key ... ok [INFO] [stdout] 2025-10-01T07:44:25.849084Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpP0ULkU/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.849173Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpP0ULkU/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.849194Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.849204Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpP0ULkU/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.849248Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpP0ULkU/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.849268Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.849278Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:25.849296Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.849305Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.849955Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-10-01T07:44:25.851586Z  INFO cassadilia::index::persistence: Persisted 16 entries to index '/tmp/.tmpjH4B43/index' [INFO] [stdout] 2025-10-01T07:44:25.851607Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-10-01T07:44:25.851695Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpjH4B43/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpjH4B43/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.851689Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmp9QXOPD/index' [INFO] [stdout] 2025-10-01T07:44:25.851720Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.851720Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 1: /tmp/.tmpjH4B43/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.851782Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:25.851789Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp9QXOPD/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.851795Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=21 [INFO] [stdout] 2025-10-01T07:44:25.851804Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.851804Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=21 [INFO] [stdout] 2025-10-01T07:44:25.851812Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.851820Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.851907Z DEBUG cassadilia::transaction: Starting transaction for key '"key16"' using staging file '/tmp/.tmpjH4B43/staging/.tmpbuhNQ5' [INFO] [stdout] 2025-10-01T07:44:25.851929Z DEBUG cassadilia::transaction: Finishing transaction for key '"key16"' [INFO] [stdout] 2025-10-01T07:44:25.851990Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00013912 total_blobs=1 [INFO] [stdout] 2025-10-01T07:44:25.852094Z DEBUG cassadilia::transaction: Starting transaction for key '"overwrite_test"' using staging file '/tmp/.tmp9QXOPD/staging/.tmpiRkgAC' [INFO] [stdout] 2025-10-01T07:44:25.852114Z DEBUG cassadilia::transaction: Finishing transaction for key '"overwrite_test"' [INFO] [stdout] 2025-10-01T07:44:25.853282Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpP0ULkU/index' [INFO] [stdout] 2025-10-01T07:44:25.853304Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.853383Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpP0ULkU/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.853400Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.853409Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.853418Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:25.853548Z ERROR cassadilia::orphan: Missing blob in filesystem hash=b6e382289cdb3b5285d65af149c3420d418ae8d9737779515f4bc8bba7af1a22 [INFO] [stdout] 2025-10-01T07:44:25.853593Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=1 corrupted_blobs=0 staging_files=0 scan_time=0.00014529 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.853975Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmppDnsLr/cas/3e/5c/ebb6c8e26480a4b41a27eb356a16765db43f91e72a506fcb86c13a1628f7 [INFO] [stdout] 2025-10-01T07:44:25.854010Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.854424Z DEBUG cassadilia::transaction: Committing transaction blob_hash=b4de87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f key="overwrite_test" [INFO] [stdout] 2025-10-01T07:44:25.854610Z DEBUG cassadilia::cas_manager: Moved blob b4de87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f to CAS path '/tmp/.tmp9QXOPD/cas/b4/de/87a1c0535ed854ef70db5a5e1b72f4dc30c696b58a4a3615d7317167099f' [INFO] [stdout] 2025-10-01T07:44:25.854642Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp9QXOPD/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.854663Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.854932Z DEBUG cassadilia::transaction: Committing transaction blob_hash=591c6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d key="key16" [INFO] [stdout] test tests::test_put_get_remove_string_key ... ok [INFO] [stdout] test tests::test_orphan_detection_with_missing_blobs ... ok [INFO] [stdout] 2025-10-01T07:44:25.856716Z DEBUG cassadilia::cas_manager: Moved blob 591c6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d to CAS path '/tmp/.tmpjH4B43/cas/59/1c/6c3a9299a2b4d2165956457aff50d6aa376007235a26675d223563d4863d' [INFO] [stdout] 2025-10-01T07:44:25.856902Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmp9QXOPD/cas/a6/e7/f93354fdbbc10c31e6f310a968b94525d577fd4267550dedd55d846ab1c5 [INFO] [stdout] 2025-10-01T07:44:25.856986Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.861098Z  INFO cassadilia::index::persistence: Loaded 1 entries from index '/tmp/.tmp9QXOPD/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.861192Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp9QXOPD/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.861216Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=1 [INFO] [stdout] 2025-10-01T07:44:25.861227Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp9QXOPD/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.862518Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpPv0ex5/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.862646Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmp9QXOPD/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.862813Z DEBUG cassadilia::transaction: Starting transaction for key '"key17"' using staging file '/tmp/.tmpjH4B43/staging/.tmp2C0bHM' [INFO] [stdout] 2025-10-01T07:44:25.862846Z DEBUG cassadilia::transaction: Finishing transaction for key '"key17"' [INFO] [stdout] 2025-10-01T07:44:25.862831Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:25.862934Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=2 [INFO] [stdout] 2025-10-01T07:44:25.862999Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.863041Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.862758Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.863201Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.863293Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpPv0ex5/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.864277Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f1023e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1 key="key17" [INFO] [stdout] 2025-10-01T07:44:25.865012Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp4ADspX/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.865101Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.865117Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.865140Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp4ADspX/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.865174Z DEBUG cassadilia::cas_manager: Moved blob f1023e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1 to CAS path '/tmp/.tmpjH4B43/cas/f1/02/3e972ed87f319c2688019de45c89941bb75fcccfc0f1b73351a49da3f4f1' [INFO] [stdout] 2025-10-01T07:44:25.867119Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.001712381 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.871007Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=5.23e-5 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.871123Z DEBUG cassadilia::transaction: Starting transaction for key '"dropped_tx_key"' using staging file '/tmp/.tmp4ADspX/staging/.tmpEiWa5z' [INFO] [stdout] 2025-10-01T07:44:25.872339Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmp9QXOPD/index' [INFO] [stdout] 2025-10-01T07:44:25.872436Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.872093Z DEBUG cassadilia::transaction: Starting transaction for key '"remove_persist_test"' using staging file '/tmp/.tmpPv0ex5/staging/.tmp9mN0or' [INFO] [stdout] 2025-10-01T07:44:25.872770Z DEBUG cassadilia::transaction: Finishing transaction for key '"remove_persist_test"' [INFO] [stdout] test tests::test_transaction_drop_cleans_up_staging_file ... ok [INFO] [stdout] 2025-10-01T07:44:25.872966Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp9QXOPD/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.873304Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.873316Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.873326Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.873555Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00019235 total_blobs=1 [INFO] [stdout] test tests::test_overwrite_persists_across_reopen ... ok [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_error_cases ... ok [INFO] [stdout] 2025-10-01T07:44:25.880151Z DEBUG cassadilia::transaction: Starting transaction for key '"key18"' using staging file '/tmp/.tmpjH4B43/staging/.tmpaPdzDI' [INFO] [stdout] 2025-10-01T07:44:25.880198Z DEBUG cassadilia::transaction: Finishing transaction for key '"key18"' [INFO] [stdout] 2025-10-01T07:44:25.882267Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7a6268a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90 key="key18" [INFO] [stdout] 2025-10-01T07:44:25.882468Z DEBUG cassadilia::cas_manager: Moved blob 7a6268a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90 to CAS path '/tmp/.tmpjH4B43/cas/7a/62/68a8c31792798d33b5670af2610093f0461ddc2c373416f17e666b6f8d90' [INFO] [stdout] 2025-10-01T07:44:25.883802Z DEBUG cassadilia::transaction: Starting transaction for key '"key19"' using staging file '/tmp/.tmpjH4B43/staging/.tmpHUjtzY' [INFO] [stdout] 2025-10-01T07:44:25.883842Z DEBUG cassadilia::transaction: Finishing transaction for key '"key19"' [INFO] [stdout] 2025-10-01T07:44:25.884977Z DEBUG cassadilia::transaction: Committing transaction blob_hash=2c0e850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 key="remove_persist_test" [INFO] [stdout] 2025-10-01T07:44:25.885009Z DEBUG cassadilia::transaction: Committing transaction blob_hash=f34e40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c key="key19" [INFO] [stdout] 2025-10-01T07:44:25.885165Z DEBUG cassadilia::cas_manager: Moved blob 2c0e850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 to CAS path '/tmp/.tmpPv0ex5/cas/2c/0e/850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1' [INFO] [stdout] 2025-10-01T07:44:25.885188Z DEBUG cassadilia::cas_manager: Moved blob f34e40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c to CAS path '/tmp/.tmpjH4B43/cas/f3/4e/40d8cdd537244aa3858a6dbf867ae1e8c9258b2d846f7c9e9385f76dd14c' [INFO] [stdout] 2025-10-01T07:44:25.885198Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpPv0ex5/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.885222Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.885405Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpacRHjo/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.886098Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.886167Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.886213Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpacRHjo/0_index.wal [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_valid_cases ... ok [INFO] [stdout] test types::tests::test_blob_hash_from_relative_path_with_prefix ... ok [INFO] [stdout] test types::tests::test_blob_hash_relative_path_roundtrip ... ok [INFO] [stdout] test types::tests::test_blob_hash_relative_path_structure ... ok [INFO] [stdout] 2025-10-01T07:44:25.889320Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpHn1Gfh/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.889458Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.889551Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.889574Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.891284Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00044597 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.891628Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpPv0ex5/cas/2c/0e/850013924f7df98347ff6dcf2d84d6f9d04e678ab76e343ae4732edf25d1 [INFO] [stdout] 2025-10-01T07:44:25.891682Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.892040Z  INFO cassadilia::index::persistence: Persisted 20 entries to index '/tmp/.tmpjH4B43/index' [INFO] [stdout] 2025-10-01T07:44:25.892062Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-10-01T07:44:25.892136Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpjH4B43/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.892159Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 2). [INFO] [stdout] 2025-10-01T07:44:25.892168Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=25 [INFO] [stdout] 2025-10-01T07:44:25.892176Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=25 [INFO] [stdout] 2025-10-01T07:44:25.892201Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] 2025-10-01T07:44:25.892554Z DEBUG cassadilia::transaction: Starting transaction for key '"key1"' using staging file '/tmp/.tmpacRHjo/staging/.tmpdtaHQD' [INFO] [stdout] 2025-10-01T07:44:25.892580Z DEBUG cassadilia::transaction: Finishing transaction for key '"key1"' [INFO] [stdout] 2025-10-01T07:44:25.893196Z  INFO cassadilia::index::persistence: Loaded 20 entries from index '/tmp/.tmpjH4B43/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.893278Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpjH4B43/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.893293Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=25 [INFO] [stdout] 2025-10-01T07:44:25.893303Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmpjH4B43/2_index.wal [INFO] [stdout] 2025-10-01T07:44:25.893329Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpPv0ex5/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.893351Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmpjH4B43/2_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.893364Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.893373Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=25 [INFO] [stdout] 2025-10-01T07:44:25.893407Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpPv0ex5/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.894731Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00132279 total_blobs=20 [INFO] [stdout] 2025-10-01T07:44:25.895540Z  INFO cassadilia::index::persistence: Loaded 20 entries from index '/tmp/.tmpjH4B43/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.895624Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpjH4B43/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.895642Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=25 [INFO] [stdout] 2025-10-01T07:44:25.895652Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmpjH4B43/2_index.wal [INFO] [stdout] 2025-10-01T07:44:25.895702Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmpjH4B43/2_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.895719Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.895730Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=25 [INFO] [stdout] 2025-10-01T07:44:25.897075Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpTK5szv/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:25.897161Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.897172Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.897192Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpTK5szv/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.897620Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.001850209 total_blobs=20 [INFO] [stdout] 2025-10-01T07:44:25.893423Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.898591Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpPv0ex5/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.918544Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:25.918587Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.918731Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpPv0ex5/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.918787Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=2 [INFO] [stdout] 2025-10-01T07:44:25.918807Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=2 highest_op_version=2 [INFO] [stdout] 2025-10-01T07:44:25.918835Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.919022Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.919744Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00070641 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.919857Z DEBUG cassadilia::transaction: Starting transaction for key '"key_1"' using staging file '/tmp/.tmpTK5szv/staging/.tmpi8a088' [INFO] [stdout] 2025-10-01T07:44:25.919899Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_1"' [INFO] [stdout] 2025-10-01T07:44:25.920044Z DEBUG cassadilia::transaction: Committing transaction blob_hash=637140a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3 key="key1" [INFO] [stdout] 2025-10-01T07:44:25.920255Z DEBUG cassadilia::cas_manager: Moved blob 637140a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3 to CAS path '/tmp/.tmpacRHjo/cas/63/71/40a8a0a8e97655585db60b46b89af928c2c431953a2ec77b766e113a38a3' [INFO] [stdout] 2025-10-01T07:44:25.920292Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpacRHjo/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.920317Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.922067Z DEBUG cassadilia::transaction: Committing transaction blob_hash=7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 key="key_1" [INFO] [stdout] 2025-10-01T07:44:25.923308Z DEBUG cassadilia::transaction: Starting transaction for key '"key2"' using staging file '/tmp/.tmpacRHjo/staging/.tmp2MSXuh' [INFO] [stdout] 2025-10-01T07:44:25.923337Z DEBUG cassadilia::transaction: Finishing transaction for key '"key2"' [INFO] [stdout] 2025-10-01T07:44:25.923529Z DEBUG cassadilia::cas_manager: Moved blob 7db435c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 to CAS path '/tmp/.tmpTK5szv/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676' [INFO] [stdout] 2025-10-01T07:44:25.923564Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpTK5szv/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.923589Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.923687Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpHn1Gfh/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.925310Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.925429Z  INFO cassadilia::index::persistence: Persisted 0 entries to index '/tmp/.tmpPv0ex5/index' [INFO] [stdout] 2025-10-01T07:44:25.925464Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:25.925649Z DEBUG cassadilia::transaction: Committing transaction blob_hash=71df75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d key="key2" [INFO] [stdout] 2025-10-01T07:44:25.925834Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpPv0ex5/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.925837Z DEBUG cassadilia::cas_manager: Moved blob 71df75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d to CAS path '/tmp/.tmpacRHjo/cas/71/df/75541f3ee9d14a6eecd051a88e1cf16f3ff146901a0886406caffe31004d' [INFO] [stdout] 2025-10-01T07:44:25.925858Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:25.925869Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.925894Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=2 [INFO] [stdout] 2025-10-01T07:44:25.926020Z DEBUG cassadilia::transaction: Starting transaction for key '"key_2"' using staging file '/tmp/.tmpTK5szv/staging/.tmpuVUVyH' [INFO] [stdout] 2025-10-01T07:44:25.926045Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_2"' [INFO] [stdout] 2025-10-01T07:44:25.926045Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00011404 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:25.933938Z DEBUG cassadilia::transaction: Committing transaction blob_hash=409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f key="key_2" [INFO] [stdout] 2025-10-01T07:44:25.934312Z DEBUG cassadilia::cas_manager: Moved blob 409d96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f to CAS path '/tmp/.tmpTK5szv/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f' [INFO] [stdout] test tests::test_remove_persists_across_reopen ... 2025-10-01T07:44:25.934578Z DEBUG cassadilia::transaction: Starting transaction for key '"key3"' using staging file '/tmp/.tmpacRHjo/staging/.tmpROrZtS' [INFO] [stdout] 2025-10-01T07:44:25.935430Z DEBUG cassadilia::transaction: Finishing transaction for key '"key3"' [INFO] [stdout] ok [INFO] [stdout] test tests::checkpoint::test_checkpoint_persists_overwrites_correctly ... ok [INFO] [stdout] 2025-10-01T07:44:25.937074Z DEBUG cassadilia::transaction: Starting transaction for key '"key_3"' using staging file '/tmp/.tmpTK5szv/staging/.tmpdFRote' [INFO] [stdout] 2025-10-01T07:44:25.937106Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_3"' [INFO] [stdout] 2025-10-01T07:44:25.937402Z DEBUG cassadilia::transaction: Committing transaction blob_hash=0393cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520 key="key3" [INFO] [stdout] 2025-10-01T07:44:25.937601Z DEBUG cassadilia::cas_manager: Moved blob 0393cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520 to CAS path '/tmp/.tmpacRHjo/cas/03/93/cf92b050830bcda68a04a88ec0865c0aee91acd19966dff18d8958a38520' [INFO] [stdout] 2025-10-01T07:44:25.937634Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:25.937644Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.939047Z DEBUG cassadilia::transaction: Committing transaction blob_hash=68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc key="key_3" [INFO] [stdout] 2025-10-01T07:44:25.939246Z DEBUG cassadilia::cas_manager: Moved blob 68e1d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc to CAS path '/tmp/.tmpTK5szv/cas/68/e1/d56d64bd1f355f8b709e19d56daa02c60139a5f0cee043e6255a3ce16abc' [INFO] [stdout] 2025-10-01T07:44:25.939327Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpacRHjo/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.939387Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.941236Z DEBUG cassadilia::transaction: Starting transaction for key '"key_4"' using staging file '/tmp/.tmpTK5szv/staging/.tmprSboiv' [INFO] [stdout] 2025-10-01T07:44:25.941266Z DEBUG cassadilia::transaction: Finishing transaction for key '"key_4"' [INFO] [stdout] 2025-10-01T07:44:25.941541Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=SegmentRollover [INFO] [stdout] 2025-10-01T07:44:25.942477Z DEBUG cassadilia::transaction: Committing transaction blob_hash=4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d key="key_4" [INFO] [stdout] 2025-10-01T07:44:25.943426Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpacRHjo/index' [INFO] [stdout] 2025-10-01T07:44:25.943493Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-10-01T07:44:25.943623Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpacRHjo/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpacRHjo/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.943682Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpacRHjo/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.943772Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:25.943817Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=3 [INFO] [stdout] 2025-10-01T07:44:25.943851Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-10-01T07:44:25.943928Z  INFO cassadilia::index: Starting checkpoint operation. reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.943971Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=Explicit [INFO] [stdout] 2025-10-01T07:44:25.945443Z  INFO cassadilia::index::persistence: Persisted 3 entries to index '/tmp/.tmpacRHjo/index' [INFO] [stdout] 2025-10-01T07:44:25.945585Z DEBUG cassadilia::wal: Skipping checkpoint commit (idempotent/no-op). last_checkpointed_version=3 commit_version=3 [INFO] [stdout] 2025-10-01T07:44:25.945606Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=3 [INFO] [stdout] 2025-10-01T07:44:25.945657Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-10-01T07:44:25.946016Z  INFO cassadilia::index::persistence: Loaded 3 entries from index '/tmp/.tmpacRHjo/index' and populated ref counts. [INFO] [stdout] 2025-10-01T07:44:25.946114Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmpacRHjo/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.946135Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 checkpoint=3 [INFO] [stdout] 2025-10-01T07:44:25.946147Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmpacRHjo/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.946189Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 1 at '/tmp/.tmpacRHjo/1_index.wal'. [INFO] [stdout] 2025-10-01T07:44:25.946207Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-10-01T07:44:25.946217Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=0 highest_op_version=3 [INFO] [stdout] 2025-10-01T07:44:25.946524Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00026545 total_blobs=3 [INFO] [stdout] test tests::test_wal_rollover_and_cleanup ... ok [INFO] [stdout] 2025-10-01T07:44:25.947496Z  WARN cassadilia::wal::storage: Found WAL-like file with non-numeric segment ID: /tmp/.tmpyWaMMC/abc_index.wal [INFO] [stdout] 2025-10-01T07:44:25.947548Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpyWaMMC/0_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpyWaMMC/2_index.wal" }] [INFO] [stdout] test wal::tests::discover_segments_ignores_malformed_filenames ... ok [INFO] [stdout] 2025-10-01T07:44:25.947966Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpMcRc4l/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.948031Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.949981Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.950113Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpMcRc4l/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.950137Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.950148Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpMcRc4l/0_index.wal [INFO] [stdout] test wal::tests::replay_fails_on_key_decode_error ... ok [INFO] [stdout] 2025-10-01T07:44:25.953824Z DEBUG cassadilia::cas_manager: Moved blob 4607a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d to CAS path '/tmp/.tmpTK5szv/cas/46/07/a1b43e8c29a684fe473b6bc2302a7c114692f84e8bf4432850fe81abd16d' [INFO] [stdout] 2025-10-01T07:44:25.961242Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpcPWpXO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.961332Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.961771Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:25.961793Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:25.961820Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpjqiQWi/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.963737Z DEBUG cassadilia: Removing 2 keys in range "key_1".."key_3" [INFO] [stdout] 2025-10-01T07:44:25.969978Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp8df3Zm/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:25.970023Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:25.970036Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmp8df3Zm/0_index.wal [INFO] [stdout] test wal::tests::replay_fails_on_corrupted_op_entry ... ok [INFO] [stdout] 2025-10-01T07:44:25.970647Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp6xGVYn/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.970706Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] test wal::tests::replay_on_completely_empty_directory ... ok [INFO] [stdout] test wal::tests::segment_id_calculation_is_correct ... ok [INFO] [stdout] 2025-10-01T07:44:25.973911Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:25.973935Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test wal::tests::segment_reader_next_fails_on_checksum_mismatch ... ok [INFO] [stdout] 2025-10-01T07:44:25.976473Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmp2h90NV/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.976541Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:25.976673Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmpcPWpXO/1_index.wal [INFO] [stdout] 2025-10-01T07:44:25.976775Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.976857Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:25.976872Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:25.977004Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpTK5szv/cas/7d/b4/35c33dc4a7d581a9259698dbcae28a7b130bbff1123b36b2e2e987bf9676 [INFO] [stdout] 2025-10-01T07:44:25.977088Z DEBUG cassadilia::cas_manager: Successfully deleted unreferenced CAS file: /tmp/.tmpTK5szv/cas/40/9d/96651e5e689bdbe491c2ed943ed4d6744be9ee1f01aa5a61b387f2491b0f [INFO] [stdout] 2025-10-01T07:44:25.977177Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:26.007161Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpTK5szv/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:26.007470Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpTK5szv/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.009907Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:26.009958Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpTK5szv/0_index.wal [INFO] [stdout] 2025-10-01T07:44:25.979014Z DEBUG cassadilia::wal::storage: Opening WAL segment 1 for write at path: /tmp/.tmp6xGVYn/1_index.wal [INFO] [stdout] 2025-10-01T07:44:26.011235Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 1. [INFO] [stdout] 2025-10-01T07:44:25.994917Z DEBUG cassadilia::wal::storage: Sealing WAL segment 0 [INFO] [stdout] 2025-10-01T07:44:26.011644Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:26.010100Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpTK5szv/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:26.012025Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=5 [INFO] [stdout] 2025-10-01T07:44:26.012186Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=5 highest_op_version=5 [INFO] [stdout] 2025-10-01T07:44:26.012358Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:26.012510Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:25.989930Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-10-01T07:44:26.012856Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-10-01T07:44:26.015599Z DEBUG cassadilia::wal::storage: Reached end-of-segment marker (version 0) in segment 0. Cleanly ending replay for this segment. [INFO] [stdout] test wal::tests::segment_reader_stops_at_explicit_sentinel ... ok [INFO] [stdout] 2025-10-01T07:44:26.016690Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpflu2UG/0_index.wal [INFO] [stdout] 2025-10-01T07:44:26.016763Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:26.017056Z  INFO cassadilia::index::persistence: Persisted 2 entries to index '/tmp/.tmpTK5szv/index' [INFO] [stdout] 2025-10-01T07:44:26.017110Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:26.017157Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 1. [INFO] [stdout] 2025-10-01T07:44:26.017311Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmpcPWpXO/2_index.wal [INFO] [stdout] 2025-10-01T07:44:26.017484Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmp6xGVYn/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmp6xGVYn/1_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.017524Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmp6xGVYn/0_index.wal [INFO] [stdout] 2025-10-01T07:44:26.017979Z  INFO cassadilia::wal::storage: Successfully removed 1 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:26.018005Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=4 [INFO] [stdout] 2025-10-01T07:44:26.018019Z DEBUG cassadilia::wal::storage: Sealing WAL segment 1 [INFO] [stdout] 2025-10-01T07:44:26.018027Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] 2025-10-01T07:44:26.018124Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpTK5szv/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.018154Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:26.018164Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:26.018174Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:26.018354Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] test wal::tests::wal_manager_drop_is_safe_with_active_writer ... ok [INFO] [stdout] 2025-10-01T07:44:26.018573Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=0.00036008 total_blobs=2 [INFO] [stdout] test wal::tests::wal_manager_new_fails_on_uncreatable_directory ... ok [INFO] [stdout] test wal::tests::zero_panics - should panic ... ok [INFO] [stdout] test tests::test_remove_range_persists ... ok [INFO] [stdout] 2025-10-01T07:44:26.019763Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] 2025-10-01T07:44:26.020999Z DEBUG cassadilia::wal::storage: Opening WAL segment 2 for write at path: /tmp/.tmp6xGVYn/2_index.wal [INFO] [stdout] 2025-10-01T07:44:26.021069Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 2. [INFO] [stdout] 2025-10-01T07:44:26.023743Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 1, path: "/tmp/.tmp6xGVYn/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmp6xGVYn/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.023774Z  INFO cassadilia::wal::replay: Starting WAL replay segments=2 checkpoint=4 [INFO] [stdout] 2025-10-01T07:44:26.023786Z DEBUG cassadilia::wal::replay: Replaying segment segment=1 path=/tmp/.tmp6xGVYn/1_index.wal [INFO] [stdout] 2025-10-01T07:44:26.023824Z DEBUG cassadilia::wal::storage: Reached end-of-segment marker (version 0) in segment 1. Cleanly ending replay for this segment. [INFO] [stdout] 2025-10-01T07:44:26.023841Z  INFO cassadilia::wal::replay: Segment replay complete segment=1 entries=0 [INFO] [stdout] 2025-10-01T07:44:26.023850Z DEBUG cassadilia::wal::replay: Replaying segment segment=2 path=/tmp/.tmp6xGVYn/2_index.wal [INFO] [stdout] 2025-10-01T07:44:26.027028Z DEBUG cassadilia::wal::tests: Replaying op #1 [INFO] [stdout] 2025-10-01T07:44:26.027071Z DEBUG cassadilia::wal::tests: Replaying op #2 [INFO] [stdout] 2025-10-01T07:44:26.027085Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 2 at '/tmp/.tmp6xGVYn/2_index.wal'. [INFO] [stdout] 2025-10-01T07:44:26.027103Z  INFO cassadilia::wal::replay: Segment replay complete segment=2 entries=2 [INFO] [stdout] 2025-10-01T07:44:26.027115Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=2 highest_op_version=6 [INFO] [stdout] 2025-10-01T07:44:26.027143Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 3 (for next op version 7) exists at path: /tmp/.tmp6xGVYn/3_index.wal [INFO] [stdout] 2025-10-01T07:44:26.029417Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] test wal::tests::replay_should_ignore_segments_before_checkpoint ... ok [INFO] [stdout] 2025-10-01T07:44:26.035228Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 2. [INFO] [stdout] 2025-10-01T07:44:26.035837Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpcPWpXO/0_index.wal" }, SegmentInfo { id: 1, path: "/tmp/.tmpcPWpXO/1_index.wal" }, SegmentInfo { id: 2, path: "/tmp/.tmpcPWpXO/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.036176Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 0: /tmp/.tmpcPWpXO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:26.036657Z DEBUG cassadilia::wal::storage: Removing stale WAL segment 1: /tmp/.tmpcPWpXO/1_index.wal [INFO] [stdout] 2025-10-01T07:44:26.037063Z  INFO cassadilia::wal::storage: Successfully removed 2 stale WAL segment(s). [INFO] [stdout] 2025-10-01T07:44:26.037405Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=5 [INFO] [stdout] 2025-10-01T07:44:26.037871Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 2, path: "/tmp/.tmpcPWpXO/2_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:26.038299Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 2 [INFO] [stdout] test wal::tests::checkpoint_succeeds_and_prunes_old_segments ... ok [INFO] [stdout] 2025-10-01T07:44:26.043306Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 1 [INFO] [stdout] test tests::test_io_error_on_staging_file_creation ... FAILED [INFO] [stdout] test wal::tests::append_op_fails_when_segment_rollover_cannot_create_file ... FAILED [INFO] [stdout] 2025-10-01T07:44:37.962142Z  INFO cassadilia: Pre-created 65,536 CAS directories [INFO] [stdout] 2025-10-01T07:44:38.240035Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpYyd5ms/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:38.240206Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:38.240248Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:38.240294Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmpYyd5ms/0_index.wal [INFO] [stdout] 2025-10-01T07:44:38.278183Z  INFO cassadilia: Pre-created 65,536 CAS directories [INFO] [stdout] 2025-10-01T07:44:38.286079Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmp47y2zO/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:38.286246Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [] [INFO] [stdout] 2025-10-01T07:44:38.286300Z  INFO cassadilia::wal::replay: Starting WAL replay segments=0 [INFO] [stdout] 2025-10-01T07:44:38.286352Z DEBUG cassadilia::wal::storage: Ensuring WAL segment file 0 (for next op version 1) exists at path: /tmp/.tmp47y2zO/0_index.wal [INFO] [stdout] 2025-10-01T07:44:41.850639Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=3.60655728 total_blobs=0 [INFO] [stdout] 2025-10-01T07:44:41.944365Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=3.6556712620000003 total_blobs=0 [INFO] [stdout] test settings::tests::test_settings_file ... ok [INFO] [stdout] 2025-10-01T07:44:52.136892Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key"' using staging file '/tmp/.tmpYyd5ms/staging/.tmpbjIsow' [INFO] [stdout] 2025-10-01T07:44:52.137203Z DEBUG cassadilia::transaction: Finishing transaction for key '"test_key"' [INFO] [stdout] 2025-10-01T07:44:52.139285Z DEBUG cassadilia::transaction: Committing transaction blob_hash=6a953581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef key="test_key" [INFO] [stdout] 2025-10-01T07:44:52.139466Z DEBUG cassadilia::cas_manager: Moved blob 6a953581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef to CAS path '/tmp/.tmpYyd5ms/cas/6a/95/3581d60dbebc9749b56d2383277fb02b58d260b4ccf6f119108fa0f1d4ef' [INFO] [stdout] 2025-10-01T07:44:52.139568Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpYyd5ms/0_index.wal [INFO] [stdout] 2025-10-01T07:44:52.139638Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:52.141105Z DEBUG cassadilia::wal::storage: Closing WAL segment writer for segment 0 [INFO] [stdout] 2025-10-01T07:44:52.141497Z  INFO cassadilia::index::persistence: Index file '/tmp/.tmpYyd5ms/index' not found, starting fresh. State remains new. [INFO] [stdout] 2025-10-01T07:44:52.141671Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpYyd5ms/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:52.141770Z  INFO cassadilia::wal::replay: Starting WAL replay segments=1 [INFO] [stdout] 2025-10-01T07:44:52.141806Z DEBUG cassadilia::wal::replay: Replaying segment segment=0 path=/tmp/.tmpYyd5ms/0_index.wal [INFO] [stdout] 2025-10-01T07:44:52.142069Z DEBUG cassadilia::wal::storage: Reached end of WAL segment 0 at '/tmp/.tmpYyd5ms/0_index.wal'. [INFO] [stdout] 2025-10-01T07:44:52.142198Z  INFO cassadilia::wal::replay: Segment replay complete segment=0 entries=1 [INFO] [stdout] 2025-10-01T07:44:52.142271Z  INFO cassadilia::wal::replay: WAL replay complete total_entries=1 highest_op_version=1 [INFO] [stdout] 2025-10-01T07:44:52.142328Z  INFO cassadilia::index: Starting checkpoint operation. reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:52.142575Z  INFO cassadilia::index: Starting checkpoint operation. checkpoint_reason=AfterReplay [INFO] [stdout] 2025-10-01T07:44:52.144607Z  INFO cassadilia::index::persistence: Persisted 1 entries to index '/tmp/.tmpYyd5ms/index' [INFO] [stdout] 2025-10-01T07:44:52.144857Z  INFO cassadilia::wal::storage: Removing stale WAL segments older than segment ID 0. [INFO] [stdout] 2025-10-01T07:44:52.145033Z DEBUG cassadilia::wal::storage: Discovered WAL segments: [SegmentInfo { id: 0, path: "/tmp/.tmpYyd5ms/0_index.wal" }] [INFO] [stdout] 2025-10-01T07:44:52.145107Z DEBUG cassadilia::wal::storage: No stale WAL segments found to remove (older than 0). [INFO] [stdout] 2025-10-01T07:44:52.145138Z  INFO cassadilia::wal: Checkpoint committed checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:52.145218Z  INFO cassadilia::index: Checkpoint completed successfully. checkpoint_version=1 [INFO] [stdout] 2025-10-01T07:44:54.170723Z  INFO cassadilia: Orphan scan complete orphans=0 invalid_files=0 missing_blobs=0 corrupted_blobs=0 staging_files=0 scan_time=2.025401923 total_blobs=1 [INFO] [stdout] 2025-10-01T07:44:54.170975Z DEBUG cassadilia::transaction: Starting transaction for key '"test_key2"' using staging file '/tmp/.tmpYyd5ms/staging/.tmpsgLXaJ' [INFO] [stdout] 2025-10-01T07:44:54.171171Z DEBUG cassadilia::transaction: Finishing transaction for key '"test_key2"' [INFO] [stdout] 2025-10-01T07:44:54.173796Z DEBUG cassadilia::transaction: Committing transaction blob_hash=be8c48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6 key="test_key2" [INFO] [stdout] 2025-10-01T07:44:54.173916Z DEBUG cassadilia::cas_manager: Moved blob be8c48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6 to CAS path '/tmp/.tmpYyd5ms/cas/be/8c/48be81ad6bb45df2eae3f8261e6232ee8cebe8f8f8aa3c2fd7bf61ba5fc6' [INFO] [stdout] 2025-10-01T07:44:54.173955Z DEBUG cassadilia::wal::storage: Opening WAL segment 0 for write at path: /tmp/.tmpYyd5ms/0_index.wal [INFO] [stdout] 2025-10-01T07:44:54.173983Z  INFO cassadilia::wal::storage: Successfully opened writer for WAL segment 0. [INFO] [stdout] 2025-10-01T07:44:54.175279Z 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' (54) panicked at src/tests/mod.rs:324:5: [INFO] [stdout] assertion failed: result.is_err() [INFO] [stdout] stack backtrace: [INFO] [stdout] 0: 0x56dcd02c48c2 - std::backtrace_rs::backtrace::libunwind::trace::hcab59e1e990fdc24 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x56dcd02c48c2 - std::backtrace_rs::backtrace::trace_unsynchronized::he24cc57f3d2f47b7 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x56dcd02c48c2 - std::sys::backtrace::_print_fmt::hf8d65ede198eeb54 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x56dcd02c48c2 - ::fmt::h67edf0e4d33c343c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x56dcd02d657f - core::fmt::rt::Argument::fmt::hef94184842aeafdd [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/fmt/rt.rs:173:76 [INFO] [stdout] 5: 0x56dcd02d657f - core::fmt::write::hcf0c66b48a8fa606 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/fmt/mod.rs:1468:25 [INFO] [stdout] 6: 0x56dcd028e641 - std::io::default_write_fmt::h69967ac0ba93195f [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/io/mod.rs:639:11 [INFO] [stdout] 7: 0x56dcd028e641 - std::io::Write::write_fmt::h8db9396209deaa1c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/io/mod.rs:1954:13 [INFO] [stdout] 8: 0x56dcd029b812 - std::sys::backtrace::BacktraceLock::print::h07e5435aa717b414 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 9: 0x56dcd02a143f - std::panicking::default_hook::{{closure}}::h91001850288db5f7 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:301:27 [INFO] [stdout] 10: 0x56dcd02a12d1 - std::panicking::default_hook::h2346dbb704ef5512 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:325:9 [INFO] [stdout] 11: 0x56dcd021a88e - as core::ops::function::Fn>::call::h18383b2e29377420 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1999:9 [INFO] [stdout] 12: 0x56dcd021a88e - test::test_main_with_exit_callback::{{closure}}::h272d7ef99aef06dc [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:145:21 [INFO] [stdout] 13: 0x56dcd02a1baf - as core::ops::function::Fn>::call::h6dba6e441651a0d1 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1999:9 [INFO] [stdout] 14: 0x56dcd02a1baf - std::panicking::panic_with_hook::hd2b063a6090d23a4 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:842:13 [INFO] [stdout] 15: 0x56dcd02a1926 - std::panicking::panic_handler::{{closure}}::he666d95f139a333e [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:700:13 [INFO] [stdout] 16: 0x56dcd029b949 - std::sys::backtrace::__rust_end_short_backtrace::h631ad224854ebee5 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:174:18 [INFO] [stdout] 17: 0x56dcd028155d - __rustc[1d67440d6e82e4f]::rust_begin_unwind [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:698:5 [INFO] [stdout] 18: 0x56dcd02e0030 - core::panicking::panic_fmt::h420ddb7fd73daf53 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panicking.rs:75:14 [INFO] [stdout] 19: 0x56dcd02e000c - core::panicking::panic::h355c5fec13755e30 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panicking.rs:145:5 [INFO] [stdout] 20: 0x56dccff0a3cd - cassadilia::tests::test_io_error_on_staging_file_creation::hcc33782c3c95b7cd [INFO] [stdout] at /opt/rustwide/workdir/src/tests/mod.rs:324:5 [INFO] [stdout] 21: 0x56dccff0a9c7 - cassadilia::tests::test_io_error_on_staging_file_creation::{{closure}}::hbcd8e3c015532505 [INFO] [stdout] at /opt/rustwide/workdir/src/tests/mod.rs:314:48 [INFO] [stdout] 22: 0x56dccff49c66 - core::ops::function::FnOnce::call_once::he1316559f4a79924 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 23: 0x56dcd021a64b - core::ops::function::FnOnce::call_once::h70887edf07a630ba [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 24: 0x56dcd021a64b - test::__rust_begin_short_backtrace::h27763c4cbbdb8601 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:663:18 [INFO] [stdout] 25: 0x56dcd02302b5 - test::run_test_in_process::{{closure}}::h4dc8bc6d5e3924d3 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:686:74 [INFO] [stdout] 26: 0x56dcd02302b5 - as core::ops::function::FnOnce<()>>::call_once::h75905e8ffe81974f [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 27: 0x56dcd02302b5 - std::panicking::catch_unwind::do_call::h0bc60366ba66eba5 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:590:40 [INFO] [stdout] 28: 0x56dcd02302b5 - std::panicking::catch_unwind::hae1ec7bf94407afa [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:553:19 [INFO] [stdout] 29: 0x56dcd02302b5 - std::panic::catch_unwind::h0f4ff4773d84d3cd [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panic.rs:359:14 [INFO] [stdout] 30: 0x56dcd02302b5 - test::run_test_in_process::h03fbc77ae48b3f10 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:686:27 [INFO] [stdout] 31: 0x56dcd02302b5 - test::run_test::{{closure}}::h83476a9c453dc4d3 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:607:43 [INFO] [stdout] 32: 0x56dcd0206aa4 - test::run_test::{{closure}}::h515482ad1e7fe7de [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:637:41 [INFO] [stdout] 33: 0x56dcd0206aa4 - std::sys::backtrace::__rust_begin_short_backtrace::hed09f6ac5fe9d647 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:158:18 [INFO] [stdout] 34: 0x56dcd020a36a - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h988e2cd969319888 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/thread/mod.rs:559:17 [INFO] [stdout] 35: 0x56dcd020a36a - as core::ops::function::FnOnce<()>>::call_once::hd70e28dc46ec20be [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 36: 0x56dcd020a36a - std::panicking::catch_unwind::do_call::hdc29e11311eb7655 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:590:40 [INFO] [stdout] 37: 0x56dcd020a36a - std::panicking::catch_unwind::h9e402d6a96fef41c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:553:19 [INFO] [stdout] 38: 0x56dcd020a36a - std::panic::catch_unwind::h9213c0c54aec70e0 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panic.rs:359:14 [INFO] [stdout] 39: 0x56dcd020a36a - std::thread::Builder::spawn_unchecked_::{{closure}}::h6262965869ed2b87 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/thread/mod.rs:557:30 [INFO] [stdout] 40: 0x56dcd020a36a - core::ops::function::FnOnce::call_once{{vtable.shim}}::h05c05ed02619e462 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 41: 0x56dcd0296aaf - as core::ops::function::FnOnce>::call_once::h2044e71c41d3958a [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1985:9 [INFO] [stdout] 42: 0x56dcd0296aaf - std::sys::thread::unix::Thread::new::thread_start::hf277835320aa8e5a [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/thread/unix.rs:126:17 [INFO] [stdout] 43: 0x7375b682daa4 - [INFO] [stdout] 44: 0x7375b68baa34 - 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' (72) 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: 0x56dcd02c48c2 - std::backtrace_rs::backtrace::libunwind::trace::hcab59e1e990fdc24 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9 [INFO] [stdout] 1: 0x56dcd02c48c2 - std::backtrace_rs::backtrace::trace_unsynchronized::he24cc57f3d2f47b7 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14 [INFO] [stdout] 2: 0x56dcd02c48c2 - std::sys::backtrace::_print_fmt::hf8d65ede198eeb54 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:66:9 [INFO] [stdout] 3: 0x56dcd02c48c2 - ::fmt::h67edf0e4d33c343c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:39:26 [INFO] [stdout] 4: 0x56dcd02d657f - core::fmt::rt::Argument::fmt::hef94184842aeafdd [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/fmt/rt.rs:173:76 [INFO] [stdout] 5: 0x56dcd02d657f - core::fmt::write::hcf0c66b48a8fa606 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/fmt/mod.rs:1468:25 [INFO] [stdout] 6: 0x56dcd028e641 - std::io::default_write_fmt::h69967ac0ba93195f [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/io/mod.rs:639:11 [INFO] [stdout] 7: 0x56dcd028e641 - std::io::Write::write_fmt::h8db9396209deaa1c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/io/mod.rs:1954:13 [INFO] [stdout] 8: 0x56dcd029b812 - std::sys::backtrace::BacktraceLock::print::h07e5435aa717b414 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:42:9 [INFO] [stdout] 9: 0x56dcd02a143f - std::panicking::default_hook::{{closure}}::h91001850288db5f7 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:301:27 [INFO] [stdout] 10: 0x56dcd02a12d1 - std::panicking::default_hook::h2346dbb704ef5512 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:325:9 [INFO] [stdout] 11: 0x56dcd021a88e - as core::ops::function::Fn>::call::h18383b2e29377420 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1999:9 [INFO] [stdout] 12: 0x56dcd021a88e - test::test_main_with_exit_callback::{{closure}}::h272d7ef99aef06dc [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:145:21 [INFO] [stdout] 13: 0x56dcd02a1baf - as core::ops::function::Fn>::call::h6dba6e441651a0d1 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1999:9 [INFO] [stdout] 14: 0x56dcd02a1baf - std::panicking::panic_with_hook::hd2b063a6090d23a4 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:842:13 [INFO] [stdout] 15: 0x56dcd02a195a - std::panicking::panic_handler::{{closure}}::he666d95f139a333e [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:707:13 [INFO] [stdout] 16: 0x56dcd029b949 - std::sys::backtrace::__rust_end_short_backtrace::h631ad224854ebee5 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:174:18 [INFO] [stdout] 17: 0x56dcd028155d - __rustc[1d67440d6e82e4f]::rust_begin_unwind [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:698:5 [INFO] [stdout] 18: 0x56dcd02e0030 - core::panicking::panic_fmt::h420ddb7fd73daf53 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panicking.rs:75:14 [INFO] [stdout] 19: 0x56dccfec8930 - cassadilia::wal::tests::append_op_fails_when_segment_rollover_cannot_create_file::hcd2ba042fe7c06a4 [INFO] [stdout] at /opt/rustwide/workdir/src/wal/tests.rs:106:9 [INFO] [stdout] 20: 0x56dccfec8bc7 - cassadilia::wal::tests::append_op_fails_when_segment_rollover_cannot_create_file::{{closure}}::h19418d183a47e968 [INFO] [stdout] at /opt/rustwide/workdir/src/wal/tests.rs:87:62 [INFO] [stdout] 21: 0x56dccff4a0c6 - core::ops::function::FnOnce::call_once::hfed8fe53e1f53bd0 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 22: 0x56dcd021a64b - core::ops::function::FnOnce::call_once::h70887edf07a630ba [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 23: 0x56dcd021a64b - test::__rust_begin_short_backtrace::h27763c4cbbdb8601 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:663:18 [INFO] [stdout] 24: 0x56dcd02302b5 - test::run_test_in_process::{{closure}}::h4dc8bc6d5e3924d3 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:686:74 [INFO] [stdout] 25: 0x56dcd02302b5 - as core::ops::function::FnOnce<()>>::call_once::h75905e8ffe81974f [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 26: 0x56dcd02302b5 - std::panicking::catch_unwind::do_call::h0bc60366ba66eba5 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:590:40 [INFO] [stdout] 27: 0x56dcd02302b5 - std::panicking::catch_unwind::hae1ec7bf94407afa [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:553:19 [INFO] [stdout] 28: 0x56dcd02302b5 - std::panic::catch_unwind::h0f4ff4773d84d3cd [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panic.rs:359:14 [INFO] [stdout] 29: 0x56dcd02302b5 - test::run_test_in_process::h03fbc77ae48b3f10 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:686:27 [INFO] [stdout] 30: 0x56dcd02302b5 - test::run_test::{{closure}}::h83476a9c453dc4d3 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:607:43 [INFO] [stdout] 31: 0x56dcd0206aa4 - test::run_test::{{closure}}::h515482ad1e7fe7de [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/test/src/lib.rs:637:41 [INFO] [stdout] 32: 0x56dcd0206aa4 - std::sys::backtrace::__rust_begin_short_backtrace::hed09f6ac5fe9d647 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/backtrace.rs:158:18 [INFO] [stdout] 33: 0x56dcd020a36a - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h988e2cd969319888 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/thread/mod.rs:559:17 [INFO] [stdout] 34: 0x56dcd020a36a - as core::ops::function::FnOnce<()>>::call_once::hd70e28dc46ec20be [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/panic/unwind_safe.rs:274:9 [INFO] [stdout] 35: 0x56dcd020a36a - std::panicking::catch_unwind::do_call::hdc29e11311eb7655 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:590:40 [INFO] [stdout] 36: 0x56dcd020a36a - std::panicking::catch_unwind::h9e402d6a96fef41c [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panicking.rs:553:19 [INFO] [stdout] 37: 0x56dcd020a36a - std::panic::catch_unwind::h9213c0c54aec70e0 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/panic.rs:359:14 [INFO] [stdout] 38: 0x56dcd020a36a - std::thread::Builder::spawn_unchecked_::{{closure}}::h6262965869ed2b87 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/thread/mod.rs:557:30 [INFO] [stdout] 39: 0x56dcd020a36a - core::ops::function::FnOnce::call_once{{vtable.shim}}::h05c05ed02619e462 [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/core/src/ops/function.rs:250:5 [INFO] [stdout] 40: 0x56dcd0296aaf - as core::ops::function::FnOnce>::call_once::h2044e71c41d3958a [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/alloc/src/boxed.rs:1985:9 [INFO] [stdout] 41: 0x56dcd0296aaf - std::sys::thread::unix::Thread::new::thread_start::hf277835320aa8e5a [INFO] [stdout] at /rustc/bb624dcb4c8ab987e10c0808d92d76f3b84dd117/library/std/src/sys/thread/unix.rs:126:17 [INFO] [stdout] 42: 0x7375b682daa4 - [INFO] [stdout] 43: 0x7375b68baa34 - 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 34.07s [INFO] [stdout] [INFO] [stderr] error: test failed, to rerun pass `--lib` [INFO] running `Command { std: "docker" "inspect" "7cf80d876edc452a95583e440283220b6b4762d94ad5c3109dabbf756e2b9121", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "7cf80d876edc452a95583e440283220b6b4762d94ad5c3109dabbf756e2b9121", kill_on_drop: false }` [INFO] [stdout] 7cf80d876edc452a95583e440283220b6b4762d94ad5c3109dabbf756e2b9121