01KP3RYPDCQ2D3ZS5AK7R5Q3FH: test-up-encrypted

BasicConfig {
    output_rules: [
        "%/tmp/test_up*/*.txt",
        "%/tmp/test_up*/dsc/*.txt",
        "%/tmp/debug/*",
        "/tmp/core.*",
    ],
    rust_toolchain: None,
    target: Some(
        "helios-2.0",
    ),
    access_repos: [],
    publish: [],
    skip_clone: true,
}

Buildomat Job: 01KP3RZ5RY5VM1ZYQF0ETY1AQW

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12026-04-13T16:09:08.947Zjob dependencies complete; ready to run (waiting for 12 m 1 s)
22026-04-13T16:10:42.198Zjob assigned to worker 01KP3SP6W39KKHJSY4SVY5BPWE [factory aws, i-038ab6d2f25546d9c] (queued for 1 m 33 s)
32026-04-13T16:10:48.757Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42026-04-13T16:10:51.002Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52026-04-13T16:10:51.006Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62026-04-13T16:10:53.214Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72026-04-13T16:10:53.218Zdownloading input: /input/build/work/bins/crutest.gz
82026-04-13T16:10:54.937Zdownloaded input: /input/build/work/bins/crutest.gz
92026-04-13T16:10:54.941Zdownloading input: /input/build/work/bins/dsc.gz
102026-04-13T16:10:55.770Zdownloaded input: /input/build/work/bins/dsc.gz
112026-04-13T16:10:55.773Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122026-04-13T16:10:55.800Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132026-04-13T16:10:55.804Zdownloading input: /input/build/work/scripts/test_ds.sh
142026-04-13T16:10:55.836Zdownloaded input: /input/build/work/scripts/test_ds.sh
152026-04-13T16:10:55.840Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162026-04-13T16:10:55.864Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172026-04-13T16:10:55.864Zdownloading input: /input/build/work/scripts/test_repair.sh
182026-04-13T16:10:55.894Zdownloaded input: /input/build/work/scripts/test_repair.sh
192026-04-13T16:10:55.894Zdownloading input: /input/build/work/scripts/test_replay.sh
202026-04-13T16:10:55.940Zdownloaded input: /input/build/work/scripts/test_replay.sh
212026-04-13T16:10:55.940Zdownloading input: /input/build/work/scripts/test_up.sh
222026-04-13T16:10:55.973Zdownloaded input: /input/build/work/scripts/test_up.sh
232026-04-13T16:10:55.973Zdownloading input: /input/build/work/scripts/upstairs_info.d
242026-04-13T16:10:56.003Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252026-04-13T16:10:56.008Zdownloading input: /input/build/tmp/cargo-test-out.log
262026-04-13T16:10:56.754Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272026-04-13T16:10:56.754Zstarting task 0: "setup"
282026-04-13T16:10:56.759Z++ uname -s
292026-04-13T16:10:56.763Z+ kern=SunOS
302026-04-13T16:10:56.763Z+ build_user=build
312026-04-13T16:10:56.763Z+ build_uid=12345
322026-04-13T16:10:56.763Z+ work_dir=/work
332026-04-13T16:10:56.763Z+ input_dir=/input
342026-04-13T16:10:56.763Z+ [[ 0 == 12345 ]]
352026-04-13T16:10:56.763Z+ case "$kern" in
362026-04-13T16:10:56.763Z+ groupadd -g 12345 build
372026-04-13T16:10:56.763Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382026-04-13T16:10:58.769Z+ zfs create -o mountpoint=/work rpool/work
392026-04-13T16:10:59.112Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402026-04-13T16:10:59.115Z+ home_fs=zfs
412026-04-13T16:10:59.115Z+ [[ zfs == autofs ]]
422026-04-13T16:10:59.115Z+ mkdir -p /home/build
432026-04-13T16:10:59.115Z+ chown build:build /home/build /work
442026-04-13T16:11:00.116Z+ chmod 0700 /home/build /work
452026-04-13T16:11:00.119Zprocess exited: duration 3363 ms, exit code 0
 
462026-04-13T16:11:00.126Zstarting task 1: "authentication"
472026-04-13T16:11:00.143Zprocess exited: duration 16 ms, exit code 0
 
482026-04-13T16:11:00.150Zstarting task 2: "build"
492026-04-13T16:11:00.153Z+ banner cores
502026-04-13T16:11:00.156Z
512026-04-13T16:11:00.156Z #### #### ##### ###### ####
522026-04-13T16:11:00.156Z # # # # # # # #
532026-04-13T16:11:00.156Z # # # # # ##### ####
542026-04-13T16:11:00.156Z # # # ##### # #
552026-04-13T16:11:00.156Z # # # # # # # # #
562026-04-13T16:11:00.156Z #### #### # # ###### ####
572026-04-13T16:11:00.156Z
582026-04-13T16:11:00.157Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592026-04-13T16:11:00.161Z+ echo 'input bins dir contains:'
602026-04-13T16:11:00.164Zinput bins dir contains:
612026-04-13T16:11:00.164Z+ ls -ltr /input/build/work/bins
622026-04-13T16:11:00.164Ztotal 1036444
632026-04-13T16:11:00.164Z-rw-r--r-- 1 root root 157301608 Apr 13 16:10 crucible-downstairs.gz
642026-04-13T16:11:00.164Z-rw-r--r-- 1 root root 145686170 Apr 13 16:10 crucible-hammer.gz
652026-04-13T16:11:00.164Z-rw-r--r-- 1 root root 154840432 Apr 13 16:10 crutest.gz
662026-04-13T16:11:00.164Z-rw-r--r-- 1 root root 72474450 Apr 13 16:10 dsc.gz
672026-04-13T16:11:00.164Z+ banner unpack
682026-04-13T16:11:00.164Z
692026-04-13T16:11:00.164Z # # # # ##### ## #### # #
702026-04-13T16:11:00.164Z # # ## # # # # # # # # #
712026-04-13T16:11:00.164Z # # # # # # # # # # ####
722026-04-13T16:11:00.164Z # # # # # ##### ###### # # #
732026-04-13T16:11:00.164Z # # # ## # # # # # # #
742026-04-13T16:11:00.165Z #### # # # # # #### # #
752026-04-13T16:11:00.165Z
762026-04-13T16:11:00.165Z+ mkdir -p /var/tmp/bins
772026-04-13T16:11:00.168Z+ for t in "$input/bins/"*.gz
782026-04-13T16:11:00.168Z++ basename /input/build/work/bins/crucible-downstairs.gz
792026-04-13T16:11:00.168Z+ b=crucible-downstairs.gz
802026-04-13T16:11:00.168Z+ b=crucible-downstairs
812026-04-13T16:11:00.168Z+ gunzip
822026-04-13T16:11:02.801Z+ chmod +x /var/tmp/bins/crucible-downstairs
832026-04-13T16:11:02.804Z+ for t in "$input/bins/"*.gz
842026-04-13T16:11:02.804Z++ basename /input/build/work/bins/crucible-hammer.gz
852026-04-13T16:11:02.804Z+ b=crucible-hammer.gz
862026-04-13T16:11:02.805Z+ b=crucible-hammer
872026-04-13T16:11:02.805Z+ gunzip
882026-04-13T16:11:05.188Z+ chmod +x /var/tmp/bins/crucible-hammer
892026-04-13T16:11:05.192Z+ for t in "$input/bins/"*.gz
902026-04-13T16:11:05.192Z++ basename /input/build/work/bins/crutest.gz
912026-04-13T16:11:05.192Z+ b=crutest.gz
922026-04-13T16:11:05.192Z+ b=crutest
932026-04-13T16:11:05.193Z+ gunzip
942026-04-13T16:11:07.754Z+ chmod +x /var/tmp/bins/crutest
952026-04-13T16:11:07.760Z+ for t in "$input/bins/"*.gz
962026-04-13T16:11:07.760Z++ basename /input/build/work/bins/dsc.gz
972026-04-13T16:11:07.760Z+ b=dsc.gz
982026-04-13T16:11:07.760Z+ b=dsc
992026-04-13T16:11:07.760Z+ gunzip
1002026-04-13T16:11:08.938Z+ chmod +x /var/tmp/bins/dsc
1012026-04-13T16:11:08.942Z+ export BINDIR=/var/tmp/bins
1022026-04-13T16:11:08.942Z+ BINDIR=/var/tmp/bins
1032026-04-13T16:11:08.942Z+ export RUST_BACKTRACE=1
1042026-04-13T16:11:08.942Z+ RUST_BACKTRACE=1
1052026-04-13T16:11:08.942Z+ jobpid=1093
1062026-04-13T16:11:08.942Z+ echo 'Setup debug logging'
1072026-04-13T16:11:08.942Z+ mkdir /tmp/debug
1082026-04-13T16:11:08.942ZSetup debug logging
1092026-04-13T16:11:08.942Z+ sleep 3600
1102026-04-13T16:11:08.942Z+ psrinfo -v
1112026-04-13T16:11:08.947Z+ df -h
1122026-04-13T16:11:08.951Z+ prstat -d d -mLc 1
1132026-04-13T16:11:08.951Z+ iostat -T d -xn 1
1142026-04-13T16:11:08.951Z+ mpstat -T d 1
1152026-04-13T16:11:08.951Z+ vmstat -T d -p 1
1162026-04-13T16:11:08.951Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1172026-04-13T16:11:08.951Z+ banner test_up_encrypted
1182026-04-13T16:11:08.951Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1192026-04-13T16:11:08.955Z
1202026-04-13T16:11:08.955Z ##### ###### #### ##### # # ##### ###### # #
1212026-04-13T16:11:08.955Z # # # # # # # # # ## #
1222026-04-13T16:11:08.955Z # ##### #### # # # # # ##### # # #
1232026-04-13T16:11:08.955Z # # # # # # ##### # # # #
1242026-04-13T16:11:08.955Z # # # # # # # # # # ##
1252026-04-13T16:11:08.955Z # ###### #### # ####### #### # ####### ###### # #
1262026-04-13T16:11:08.955Z
1272026-04-13T16:11:08.955Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1282026-04-13T16:11:08.960Z/input/build/work
1292026-04-13T16:11:08.969ZTurn off color for downstairs dump
1302026-04-13T16:11:08.995ZUpstairs using key: obYoKLi5jbVcilN6UbZYCxo0ijzPBF1EDqUwiSJkQr0=
1312026-04-13T16:11:08.999Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1322026-04-13T16:11:08.999ZCreating 3 downstairs regions
1332026-04-13T16:11:09.199ZStarting 3 downstairs
1342026-04-13T16:11:09.205Zdsc started at PID: 1139
1352026-04-13T16:11:14.249ZDisable automatic restart on all downstairs
1362026-04-13T16:11:14.262Z
1372026-04-13T16:11:14.262ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1382026-04-13T16:11:14.265ZRunning test: span
1392026-04-13T16:11:18.341ZCompleted test: span
1402026-04-13T16:11:23.345ZRunning test: big
1412026-04-13T16:11:27.506ZCompleted test: big
1422026-04-13T16:11:32.512ZRunning test: dep
1432026-04-13T16:12:03.733ZCompleted test: dep
1442026-04-13T16:12:08.737ZRunning test: balloon
1452026-04-13T16:12:33.862ZCompleted test: balloon
1462026-04-13T16:12:38.867ZRunning test: deactivate
1472026-04-13T16:12:43.191ZCompleted test: deactivate
1482026-04-13T16:12:48.196ZRunning hammer
1492026-04-13T16:12:55.796ZRun repair tests
1502026-04-13T16:12:55.799Z/var/tmp/bins/crutest fill -g 31 -q --key obYoKLi5jbVcilN6UbZYCxo0ijzPBF1EDqUwiSJkQr0= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1512026-04-13T16:12:55.817Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.717384339Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"task":"crutest"}
1522026-04-13T16:12:55.822Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.717604909Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"task":"crutest"}
1532026-04-13T16:12:55.822Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718223069Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"task":"crutest"}
1542026-04-13T16:12:55.823Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718465777Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
1552026-04-13T16:12:55.823Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"4447695ee834b474ed6363602aeea0a9bc2447c2\",\n git_commit_timestamp: \"2026-04-13T15:56:24.000000000Z\",\n git_branch: \"alan/verify-after-repair\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718504056Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
1562026-04-13T16:12:55.823Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718513755Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
1572026-04-13T16:12:55.823Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718525815Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
1582026-04-13T16:12:55.823Z{"msg":"Crucible 67dbf258-364c-468e-ae6a-c9e24c620323 has session id: 492d0dbd-9d7e-4996-b912-801597497757","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718919146Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1592026-04-13T16:12:55.823Z{"msg":"Upstairs opts: Upstairs UUID: 67dbf258-364c-468e-ae6a-c9e24c620323, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718961874Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1602026-04-13T16:12:55.823Z{"msg":"Crucible stats registered with UUID: 67dbf258-364c-468e-ae6a-c9e24c620323","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.718973403Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1612026-04-13T16:12:55.823Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:12:54.718983153Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1622026-04-13T16:12:55.823Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719086298Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1632026-04-13T16:12:55.823Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719129006Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1642026-04-13T16:12:55.823Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719140465Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1652026-04-13T16:12:55.823Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719279429Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"task":"crutest"}
1662026-04-13T16:12:55.823Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719293048Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
1672026-04-13T16:12:55.823Z{"msg":"67dbf258-364c-468e-ae6a-c9e24c620323 active request set","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719314567Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1682026-04-13T16:12:55.823Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719324156Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1692026-04-13T16:12:55.823Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719334716Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1702026-04-13T16:12:55.823Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719344375Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1712026-04-13T16:12:55.823Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719354655Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1722026-04-13T16:12:55.823Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719365544Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1732026-04-13T16:12:55.823Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719379824Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1742026-04-13T16:12:55.823Z{"msg":"ds_connection connected from Ok(127.0.0.1:38864)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719446961Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1752026-04-13T16:12:55.823Z{"msg":"ds_connection connected from Ok(127.0.0.1:37599)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.71946239Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1762026-04-13T16:12:55.823Z{"msg":"ds_connection connected from Ok(127.0.0.1:33565)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.719473049Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1772026-04-13T16:12:55.823Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.72009036Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1782026-04-13T16:12:55.823Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720139197Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1792026-04-13T16:12:55.823Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720151897Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1802026-04-13T16:12:55.823Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.72030155Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1812026-04-13T16:12:55.823Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720321839Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1822026-04-13T16:12:55.823Z{"msg":"[0]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720395525Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1832026-04-13T16:12:55.823Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720407025Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1842026-04-13T16:12:55.823Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720417934Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1852026-04-13T16:12:55.823Z{"msg":"[1]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720428714Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1862026-04-13T16:12:55.823Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720439263Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1872026-04-13T16:12:55.823Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720450003Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1882026-04-13T16:12:55.823Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720460712Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1892026-04-13T16:12:55.823Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720471022Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1902026-04-13T16:12:55.823Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720481541Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1912026-04-13T16:12:55.824Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720491601Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1922026-04-13T16:12:55.824Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.72050195Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1932026-04-13T16:12:55.824Z{"msg":"Next flush: 1502","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.72051131Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1942026-04-13T16:12:55.824Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720521699Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"":"downstairs","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1952026-04-13T16:12:55.824Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720532149Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1962026-04-13T16:12:55.824Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720541768Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"0","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1972026-04-13T16:12:55.824Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720551888Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"1","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
1982026-04-13T16:12:55.824ZWait for a query_work_queue command to finish before sending IO
1992026-04-13T16:12:55.824Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720565827Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"client":"2","":"downstairs","session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
2002026-04-13T16:12:55.824Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720576317Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
2012026-04-13T16:12:55.824Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720586086Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
2022026-04-13T16:12:55.824Z{"msg":"67dbf258-364c-468e-ae6a-c9e24c620323 is now active with session: 492d0dbd-9d7e-4996-b912-801597497757","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720596936Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
2032026-04-13T16:12:55.824Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720606645Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
2042026-04-13T16:12:55.824Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720615155Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176,"session_id":"492d0dbd-9d7e-4996-b912-801597497757"}
2052026-04-13T16:12:55.824Z{"msg":"Activated sub_volume 67dbf258-364c-468e-ae6a-c9e24c620323","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:54.720625204Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1176}
2062026-04-13T16:12:55.824ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2072026-04-13T16:12:55.824ZFill test
2082026-04-13T16:12:55.844ZRead and Verify all blocks (0..50 range:false)
2092026-04-13T16:12:55.868ZWrote out file "/var/tmp/test_up-build/verify_file"
2102026-04-13T16:12:55.868ZCLIENT: Tests done. All submitted work has been ACK'd
2112026-04-13T16:12:55.871Z----------------------------------------------------------------
2122026-04-13T16:12:55.871Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2132026-04-13T16:12:55.871ZStates: Active Active Active
2142026-04-13T16:12:55.871ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2152026-04-13T16:12:55.871Z 1002 Acked Read 50 Done Done Done false
2162026-04-13T16:12:55.871Z STATES DS:0 DS:1 DS:2 TOTAL
2172026-04-13T16:12:55.871Z Sent 0 0 0 0
2182026-04-13T16:12:55.871Z Done 1 1 1 3
2192026-04-13T16:12:55.871Z Skipped 0 0 0 0
2202026-04-13T16:12:55.871Z Error 0 0 0 0
2212026-04-13T16:12:55.871ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2222026-04-13T16:12:55.871ZDownstairs last five completed: 1001 1000
2232026-04-13T16:12:55.871ZUpstairs last five completed: 1002 1001 1000
2242026-04-13T16:12:55.871ZCLIENT: Up:0 ds:1 act:3
2252026-04-13T16:12:59.870Z----------------------------------------------------------------
2262026-04-13T16:12:59.870Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2272026-04-13T16:12:59.870ZDownstairs last five completed: 1003 1002 1001 1000
2282026-04-13T16:12:59.870ZUpstairs last five completed: 1003 1002 1001 1000
2292026-04-13T16:12:59.870ZCLIENT: Up:0 ds:0 act:3
2302026-04-13T16:12:59.870ZCLIENT: All crucible jobs finished, exiting program
2312026-04-13T16:12:59.877ZRepair setup passed
2322026-04-13T16:12:59.880ZCopy the region for /var/tmp/test_up-build/8830
2332026-04-13T16:12:59.880Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2342026-04-13T16:12:59.883Z/var/tmp/bins/crutest fill -g 32 -q --key obYoKLi5jbVcilN6UbZYCxo0ijzPBF1EDqUwiSJkQr0= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2352026-04-13T16:12:59.900Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.800594706Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"task":"crutest"}
2362026-04-13T16:12:59.905Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.800849254Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"task":"crutest"}
2372026-04-13T16:12:59.905Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.80157119Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"task":"crutest"}
2382026-04-13T16:12:59.905Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.801814508Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2392026-04-13T16:12:59.905Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"4447695ee834b474ed6363602aeea0a9bc2447c2\",\n git_commit_timestamp: \"2026-04-13T15:56:24.000000000Z\",\n git_branch: \"alan/verify-after-repair\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.801844587Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2402026-04-13T16:12:59.905Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.801857836Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2412026-04-13T16:12:59.905Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.801870125Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2422026-04-13T16:12:59.905Z{"msg":"Crucible 090d8870-122c-4c50-9cd2-4496e9e70fcf has session id: 88443671-2c6f-4c8d-bf8e-7471520a7499","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802233838Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2432026-04-13T16:12:59.905Z{"msg":"Upstairs opts: Upstairs UUID: 090d8870-122c-4c50-9cd2-4496e9e70fcf, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802260257Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2442026-04-13T16:12:59.905Z{"msg":"Crucible stats registered with UUID: 090d8870-122c-4c50-9cd2-4496e9e70fcf","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802270446Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2452026-04-13T16:12:59.905Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:12:58.802284126Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2462026-04-13T16:12:59.905Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802415349Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2472026-04-13T16:12:59.905Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802443988Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2482026-04-13T16:12:59.905Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802454317Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2492026-04-13T16:12:59.905Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802630289Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"task":"crutest"}
2502026-04-13T16:12:59.905Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802643848Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2512026-04-13T16:12:59.906Z{"msg":"090d8870-122c-4c50-9cd2-4496e9e70fcf active request set","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802685126Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2522026-04-13T16:12:59.906Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802699156Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2532026-04-13T16:12:59.906Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802708975Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2542026-04-13T16:12:59.906Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802722965Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2552026-04-13T16:12:59.906Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802733124Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2562026-04-13T16:12:59.906Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802743404Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2572026-04-13T16:12:59.906Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802753653Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2582026-04-13T16:12:59.906Z{"msg":"ds_connection connected from Ok(127.0.0.1:64065)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802790351Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2592026-04-13T16:12:59.906Z{"msg":"ds_connection connected from Ok(127.0.0.1:53296)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.802805571Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2602026-04-13T16:12:59.906Z{"msg":"ds_connection connected from Ok(127.0.0.1:46791)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.80281581Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"io task","client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2612026-04-13T16:12:59.906Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803545095Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2622026-04-13T16:12:59.906Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803582563Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2632026-04-13T16:12:59.906Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803595223Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2642026-04-13T16:12:59.906Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803757395Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2652026-04-13T16:12:59.906Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803808973Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2662026-04-13T16:12:59.906Z{"msg":"[0]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803832531Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2672026-04-13T16:12:59.906Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803844471Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2682026-04-13T16:12:59.906Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.80385539Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2692026-04-13T16:12:59.906Z{"msg":"[1]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.8038662Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2702026-04-13T16:12:59.906Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803884189Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2712026-04-13T16:12:59.906Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803894439Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2722026-04-13T16:12:59.906Z{"msg":"[2]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803904968Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2732026-04-13T16:12:59.906Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803914968Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2742026-04-13T16:12:59.906Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803928877Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2752026-04-13T16:12:59.906Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803938276Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2762026-04-13T16:12:59.906Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803952046Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2772026-04-13T16:12:59.906Z{"msg":"Next flush: 1503","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803961545Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2782026-04-13T16:12:59.906Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803971095Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"":"downstairs","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2792026-04-13T16:12:59.906Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.803985054Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2802026-04-13T16:12:59.906ZWait for a query_work_queue command to finish before sending IO
2812026-04-13T16:12:59.906Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804001853Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"0","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2822026-04-13T16:12:59.906Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804015853Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"1","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2832026-04-13T16:12:59.906Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804025752Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"client":"2","":"downstairs","session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2842026-04-13T16:12:59.906Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804039732Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2852026-04-13T16:12:59.906Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804049031Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2862026-04-13T16:12:59.906Z{"msg":"090d8870-122c-4c50-9cd2-4496e9e70fcf is now active with session: 88443671-2c6f-4c8d-bf8e-7471520a7499","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804059381Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2872026-04-13T16:12:59.910Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.80407259Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182,"session_id":"88443671-2c6f-4c8d-bf8e-7471520a7499"}
2882026-04-13T16:12:59.910Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.80408257Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2892026-04-13T16:12:59.910Z{"msg":"Activated sub_volume 090d8870-122c-4c50-9cd2-4496e9e70fcf","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:12:58.804090959Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1182}
2902026-04-13T16:12:59.910ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2912026-04-13T16:12:59.910ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2922026-04-13T16:12:59.910ZFill test
2932026-04-13T16:12:59.928ZRead and Verify all blocks (0..50 range:false)
2942026-04-13T16:12:59.951ZWrote out file "/var/tmp/test_up-build/verify_file"
2952026-04-13T16:12:59.951ZCLIENT: Tests done. All submitted work has been ACK'd
2962026-04-13T16:12:59.955Z----------------------------------------------------------------
2972026-04-13T16:12:59.955Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
2982026-04-13T16:12:59.955ZStates: Active Active Active
2992026-04-13T16:12:59.955ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3002026-04-13T16:12:59.955Z 1002 Acked Read 50 Done Done Done false
3012026-04-13T16:12:59.955Z STATES DS:0 DS:1 DS:2 TOTAL
3022026-04-13T16:12:59.955Z Sent 0 0 0 0
3032026-04-13T16:12:59.955Z Done 1 1 1 3
3042026-04-13T16:12:59.955Z Skipped 0 0 0 0
3052026-04-13T16:12:59.955Z Error 0 0 0 0
3062026-04-13T16:12:59.955ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
3072026-04-13T16:12:59.955ZDownstairs last five completed: 1001 1000
3082026-04-13T16:12:59.956ZUpstairs last five completed: 1002 1001 1000
3092026-04-13T16:12:59.956ZCLIENT: Up:0 ds:1 act:3
3102026-04-13T16:13:03.953Z----------------------------------------------------------------
3112026-04-13T16:13:03.953Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3122026-04-13T16:13:03.953ZDownstairs last five completed: 1003 1002 1001 1000
3132026-04-13T16:13:03.953ZUpstairs last five completed: 1003 1002 1001 1000
3142026-04-13T16:13:03.953ZCLIENT: Up:0 ds:0 act:3
3152026-04-13T16:13:03.953ZCLIENT: All crucible jobs finished, exiting program
3162026-04-13T16:13:03.957ZRepair part 1 passed
3172026-04-13T16:13:03.960Z
3182026-04-13T16:13:03.960ZKill the current downstairs
3192026-04-13T16:13:04.000ZDownstairs 2 stopped
3202026-04-13T16:13:04.001Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3212026-04-13T16:13:04.004ZNow put back the original so we have a mismatch
3222026-04-13T16:13:04.004Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3232026-04-13T16:13:04.004ZRestart downstairs with old directory
3242026-04-13T16:13:04.016Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
3252026-04-13T16:13:04.028Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:02.92780671Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1189}
3262026-04-13T16:13:04.032Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:02.929545077Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1189}
3272026-04-13T16:13:04.032Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:02.930253363Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1189}
3282026-04-13T16:13:04.032ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3292026-04-13T16:13:04.032Z 0 000-009 32 32 31 1503 1503 1502 F F F <---
3302026-04-13T16:13:04.032Z 1 010-019 32 32 31 1503 1503 1502 F F F <---
3312026-04-13T16:13:04.032Z 2 020-029 32 32 31 1503 1503 1502 F F F <---
3322026-04-13T16:13:04.032Z 3 030-039 32 32 31 1503 1503 1502 F F F <---
3332026-04-13T16:13:04.032Z 4 040-049 32 32 31 1503 1503 1502 F F F <---
3342026-04-13T16:13:04.032ZMax gen: 32, Max flush: 1503
3352026-04-13T16:13:04.257ZError: Difference in extent metadata found!
3362026-04-13T16:13:04.257Z
3372026-04-13T16:13:04.257ZStack backtrace:
3382026-04-13T16:13:04.257Z 0: anyhow::error::<impl anyhow::Error>::msg
3392026-04-13T16:13:04.257Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/backtrace.rs:10:14
3402026-04-13T16:13:04.257Z 1: anyhow::__private::format_err
3412026-04-13T16:13:04.257Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/lib.rs:687:13
3422026-04-13T16:13:04.278Zdump test found error as expected
3432026-04-13T16:13:04.278Z
3442026-04-13T16:13:04.278Z
3452026-04-13T16:13:04.281Z/var/tmp/bins/crutest verify --range -g 33 -q --key obYoKLi5jbVcilN6UbZYCxo0ijzPBF1EDqUwiSJkQr0= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3462026-04-13T16:13:04.298Z{"msg":"Use this region info from dsc: RegionExtentInfo { block_size: 4096, blocks_per_extent: 10, extent_count: 5 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.197538808Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"task":"crutest"}
3472026-04-13T16:13:04.301Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.197866473Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"task":"crutest"}
3482026-04-13T16:13:04.301Z{"msg":"SV 0 has targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.19855288Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"task":"crutest"}
3492026-04-13T16:13:04.301Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.198828897Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
3502026-04-13T16:13:04.301Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"4447695ee834b474ed6363602aeea0a9bc2447c2\",\n git_commit_timestamp: \"2026-04-13T15:56:24.000000000Z\",\n git_branch: \"alan/verify-after-repair\",\n rustc_semver: \"1.90.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"1159e78c4747b02ef996e55082b704c09b970588\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.198861375Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
3512026-04-13T16:13:04.301Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.198874944Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
3522026-04-13T16:13:04.301Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.198887624Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
3532026-04-13T16:13:04.301Z{"msg":"Crucible 2a542c11-8239-4c74-b06e-b111da2bc139 has session id: 48045824-d498-44a0-a315-5ee06c9dad28","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199319423Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3542026-04-13T16:13:04.301Z{"msg":"Upstairs opts: Upstairs UUID: 2a542c11-8239-4c74-b06e-b111da2bc139, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199343882Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3552026-04-13T16:13:04.301Z{"msg":"Crucible stats registered with UUID: 2a542c11-8239-4c74-b06e-b111da2bc139","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199354761Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3562026-04-13T16:13:04.302Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:13:03.199364601Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3572026-04-13T16:13:04.302Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199501864Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3582026-04-13T16:13:04.302Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199538193Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3592026-04-13T16:13:04.302Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199549912Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3602026-04-13T16:13:04.302Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199722024Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"task":"crutest"}
3612026-04-13T16:13:04.302Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199731883Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
3622026-04-13T16:13:04.302Z{"msg":"2a542c11-8239-4c74-b06e-b111da2bc139 active request set","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199768942Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3632026-04-13T16:13:04.302Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199816419Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3642026-04-13T16:13:04.302Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199833119Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3652026-04-13T16:13:04.302Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199843308Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3662026-04-13T16:13:04.302Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199857227Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3672026-04-13T16:13:04.302Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199867527Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3682026-04-13T16:13:04.302Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199881776Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3692026-04-13T16:13:04.302Z{"msg":"ds_connection connected from Ok(127.0.0.1:50459)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199896836Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3702026-04-13T16:13:04.302Z{"msg":"ds_connection connected from Ok(127.0.0.1:36144)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.199907905Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3712026-04-13T16:13:04.302Z{"msg":"ds_connection connect to 127.0.0.1:8830 failure: Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:13:03.199984491Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3722026-04-13T16:13:04.302Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:13:03.200054188Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3732026-04-13T16:13:04.302Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:13:03.200084907Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3742026-04-13T16:13:04.302Z{"msg":"sleeping for 10s before connecting","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200095216Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3752026-04-13T16:13:04.302Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200105886Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3762026-04-13T16:13:04.302Z{"msg":"downstairs client at Some(127.0.0.1:8820) has region UUID 12345678-0000-0000-0000-000000008820","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200686318Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3772026-04-13T16:13:04.302Z{"msg":"downstairs client at Some(127.0.0.1:8810) has region UUID 12345678-0000-0000-0000-000000008810","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200711057Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3782026-04-13T16:13:04.302Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200870349Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3792026-04-13T16:13:04.302Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:03.200880559Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3802026-04-13T16:13:14.303Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.202020684Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3812026-04-13T16:13:14.303Z{"msg":"ds_connection connected from Ok(127.0.0.1:42134)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.20211169Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"io task","client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3822026-04-13T16:13:14.309Z{"msg":"downstairs client at Some(127.0.0.1:8830) has region UUID 12345678-0000-0000-0000-000000008830","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.202991748Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3832026-04-13T16:13:14.309Z{"msg":"[0]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203262965Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3842026-04-13T16:13:14.309Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203278134Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3852026-04-13T16:13:14.309Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203288463Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3862026-04-13T16:13:14.309Z{"msg":"[1]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203303083Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3872026-04-13T16:13:14.309Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203313222Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3882026-04-13T16:13:14.309Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203327832Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3892026-04-13T16:13:14.309Z{"msg":"[2]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203338051Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3902026-04-13T16:13:14.309Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.20335209Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3912026-04-13T16:13:14.309Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.20336197Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3922026-04-13T16:13:14.309Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203375449Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3932026-04-13T16:13:14.309Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203385789Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3942026-04-13T16:13:14.309Z{"msg":"Next flush: 1504","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203399198Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3952026-04-13T16:13:14.309Z{"msg":"extent 0 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203413557Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3962026-04-13T16:13:14.309Z{"msg":"extent:0 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203432797Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3972026-04-13T16:13:14.309Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203444036Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3982026-04-13T16:13:14.309Z{"msg":"extent 1 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203462895Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
3992026-04-13T16:13:14.309Z{"msg":"extent:1 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203481464Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4002026-04-13T16:13:14.309Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203492334Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4012026-04-13T16:13:14.309Z{"msg":"extent 2 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203506613Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4022026-04-13T16:13:14.309Z{"msg":"extent:2 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203525672Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4032026-04-13T16:13:14.309Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203536222Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4042026-04-13T16:13:14.309Z{"msg":"extent 3 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203550251Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4052026-04-13T16:13:14.309Z{"msg":"extent:3 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.20356865Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4062026-04-13T16:13:14.309Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.20357983Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4072026-04-13T16:13:14.309Z{"msg":"extent 4 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203598179Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4082026-04-13T16:13:14.309Z{"msg":"extent:4 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1503, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1502, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203612658Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4092026-04-13T16:13:14.309Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203623147Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"mend","":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4102026-04-13T16:13:14.309Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203644366Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4112026-04-13T16:13:14.310Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203657996Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4122026-04-13T16:13:14.310Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203668325Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4132026-04-13T16:13:14.310Z{"msg":"Full repair list: {ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203766501Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4142026-04-13T16:13:14.310Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), extent_id: ExtentId(4), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), extent_id: ExtentId(3), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), extent_id: ExtentId(1), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), extent_id: ExtentId(2), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1504, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), extent_id: ExtentId(0), source_client_id: ClientId(0), source_repair_address: 0.0.0.0:12810, dest_clients: [ClientId(2)] }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203914134Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4152026-04-13T16:13:14.310Z{"msg":"starting reconciliation e34d4180-dfe8-4539-b1d9-ca4effa42481: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203926863Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4162026-04-13T16:13:14.310Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.203936682Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4172026-04-13T16:13:14.315Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.214555575Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4182026-04-13T16:13:14.318Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.216621626Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4192026-04-13T16:13:14.321Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.2186357Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4202026-04-13T16:13:14.321Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.220607206Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4212026-04-13T16:13:14.325Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222429469Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"":"downstairs","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4222026-04-13T16:13:14.325Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222440608Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"0","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4232026-04-13T16:13:14.325Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222450428Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"1","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4242026-04-13T16:13:14.325Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222460467Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"client":"2","":"downstairs","session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4252026-04-13T16:13:14.325Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222474696Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4262026-04-13T16:13:14.325Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222484276Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4272026-04-13T16:13:14.325Z{"msg":"2a542c11-8239-4c74-b06e-b111da2bc139 is now active with session: 48045824-d498-44a0-a315-5ee06c9dad28","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222495186Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190,"session_id":"48045824-d498-44a0-a315-5ee06c9dad28"}
4282026-04-13T16:13:14.325Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222504875Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
4292026-04-13T16:13:14.325Z{"msg":"Activated sub_volume 2a542c11-8239-4c74-b06e-b111da2bc139","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:13.222518554Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
4302026-04-13T16:13:14.325ZWait for a query_work_queue command to finish before sending IO
4312026-04-13T16:13:14.325ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4322026-04-13T16:13:14.325ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4332026-04-13T16:13:14.325ZRead and Verify all blocks (0..50 range:true)
4342026-04-13T16:13:14.347ZWrote out file "/var/tmp/test_up-build/verify_file"
4352026-04-13T16:13:14.347ZVerify test completed
4362026-04-13T16:13:14.351ZWrote out file "/var/tmp/test_up-build/verify_file"
4372026-04-13T16:13:14.351ZCLIENT: Tests done. All submitted work has been ACK'd
4382026-04-13T16:13:14.351Z----------------------------------------------------------------
4392026-04-13T16:13:14.351Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4402026-04-13T16:13:14.351ZStates: Active Active Active
4412026-04-13T16:13:14.351ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4422026-04-13T16:13:14.351Z 1000 Acked Read 50 Done Done Done false
4432026-04-13T16:13:14.351Z STATES DS:0 DS:1 DS:2 TOTAL
4442026-04-13T16:13:14.351Z Sent 0 0 0 0
4452026-04-13T16:13:14.351Z Done 1 1 1 3
4462026-04-13T16:13:14.351Z Skipped 0 0 0 0
4472026-04-13T16:13:14.351Z Error 0 0 0 0
4482026-04-13T16:13:14.351ZLast Flush: None None None
4492026-04-13T16:13:14.351ZDownstairs last five completed:
4502026-04-13T16:13:14.351ZUpstairs last five completed: 1000
4512026-04-13T16:13:14.351ZCLIENT: Up:0 ds:1 act:3
4522026-04-13T16:13:18.349Z----------------------------------------------------------------
4532026-04-13T16:13:18.349Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4542026-04-13T16:13:18.349ZDownstairs last five completed: 1001 1000
4552026-04-13T16:13:18.349ZUpstairs last five completed: 1001 1000
4562026-04-13T16:13:18.349ZCLIENT: Up:0 ds:0 act:3
4572026-04-13T16:13:18.349ZCLIENT: All crucible jobs finished, exiting program
4582026-04-13T16:13:18.353Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2026-04-13T16:13:17.248549074Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1190}
4592026-04-13T16:13:18.356ZRepair part 2 passed
4602026-04-13T16:13:18.356Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830
4612026-04-13T16:13:18.367Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.266273317Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1192}
4622026-04-13T16:13:18.371Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.267998435Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1192}
4632026-04-13T16:13:18.371Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.268899202Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1192}
4642026-04-13T16:13:18.371ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4652026-04-13T16:13:18.371Z 0 000-009 32 32 32 1503 1503 1503 F F F
4662026-04-13T16:13:18.371Z 1 010-019 32 32 32 1503 1503 1503 F F F
4672026-04-13T16:13:18.371Z 2 020-029 32 32 32 1503 1503 1503 F F F
4682026-04-13T16:13:18.371Z 3 030-039 32 32 32 1503 1503 1503 F F F
4692026-04-13T16:13:18.371Z 4 040-049 32 32 32 1503 1503 1503 F F F
4702026-04-13T16:13:18.371ZMax gen: 32, Max flush: 1503
4712026-04-13T16:13:18.374Zdump test passed
4722026-04-13T16:13:18.374Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -e 1
4732026-04-13T16:13:18.385Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.284268077Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4742026-04-13T16:13:18.388Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.285807514Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4752026-04-13T16:13:18.388Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30 Extent 1
4762026-04-13T16:13:18.389Z,"time":"2026-04-13T16:13:17.28672212Z","GEN hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4772026-04-13T16:13:18.389Z 32 32 32
4782026-04-13T16:13:18.389ZFLUSH_ID 1503 1503 1503
4792026-04-13T16:13:18.389ZDIRTY
4802026-04-13T16:13:18.389Z
4812026-04-13T16:13:18.389ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4822026-04-13T16:13:18.392Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.288205549Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4832026-04-13T16:13:18.392Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.289634811Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4842026-04-13T16:13:18.392Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.290831953Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4852026-04-13T16:13:18.392Z010 A A A A A A
4862026-04-13T16:13:18.395Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.292233676Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4872026-04-13T16:13:18.395Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.293485997Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4882026-04-13T16:13:18.395Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.294487559Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4892026-04-13T16:13:18.395Z011 A A A A A A
4902026-04-13T16:13:18.399Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.29549961Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4912026-04-13T16:13:18.399Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.296455065Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4922026-04-13T16:13:18.399Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.297505635Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4932026-04-13T16:13:18.399Z012 A A A A A A
4942026-04-13T16:13:18.402Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.298545045Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4952026-04-13T16:13:18.402Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.299298849Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4962026-04-13T16:13:18.402Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.300260973Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4972026-04-13T16:13:18.402Z013 A A A A A A
4982026-04-13T16:13:18.402Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.301237626Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
4992026-04-13T16:13:18.405Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.3019905Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5002026-04-13T16:13:18.405Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.302988632Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5012026-04-13T16:13:18.405Z014 A A A A A A
5022026-04-13T16:13:18.405Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.303963896Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5032026-04-13T16:13:18.409Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.304995957Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5042026-04-13T16:13:18.409Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.305957981Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5052026-04-13T16:13:18.409Z015 A A A A A A
5062026-04-13T16:13:18.409Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.306936484Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5072026-04-13T16:13:18.409Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.307958755Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5082026-04-13T16:13:18.413Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.3086855Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5092026-04-13T16:13:18.413Z016 A A A A A A
5102026-04-13T16:13:18.413Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.309861284Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5112026-04-13T16:13:18.413Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.310863926Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5122026-04-13T16:13:18.413Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.311757873Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5132026-04-13T16:13:18.413Z017 A A A A A A
5142026-04-13T16:13:18.417Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.312793144Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5152026-04-13T16:13:18.417Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.313747148Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5162026-04-13T16:13:18.417Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.314267163Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5172026-04-13T16:13:18.417Z018 A A A A A A
5182026-04-13T16:13:18.417Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.315272585Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5192026-04-13T16:13:18.417Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.315894686Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5202026-04-13T16:13:18.421Z{"msg":"019 validated 5 extents on startup" A A A A A A ,
5212026-04-13T16:13:18.421Z"v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.316474888Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1193}
5222026-04-13T16:13:18.421Zdump extent test passed
5232026-04-13T16:13:18.421Z/var/tmp/bins/crucible-downstairs dump --no-color -d /var/tmp/test_up-build/8810 -d /var/tmp/test_up-build/8820 -d /var/tmp/test_up-build/8830 -b 20
5242026-04-13T16:13:18.432Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.33108552Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5252026-04-13T16:13:18.435Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.332414466Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5262026-04-13T16:13:18.435Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.333202108Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5272026-04-13T16:13:18.435ZExtent 2 Block in extent 0 Actual block 20
5282026-04-13T16:13:18.435Z
5292026-04-13T16:13:18.435Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.334292626Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5302026-04-13T16:13:18.439Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.3356789Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5312026-04-13T16:13:18.439Z{"msg":"validated 5 extents on startup","v":0,"name":"crucible","level":30,"time":"2026-04-13T16:13:17.336672793Z","hostname":"w-01KP3SP6W39KKHJSY4SVY5BPWE","pid":1194}
5322026-04-13T16:13:18.439Z DATA SHA256 VER
5332026-04-13T16:13:18.439Z------ ---------------------------------------------------------------- ---
5342026-04-13T16:13:18.439Z 0 a01dcf86c5fcf78e7464786681d6d5e08901be90dff2528491d75d9bb73c2dd7 A
5352026-04-13T16:13:18.439Z 1 a01dcf86c5fcf78e7464786681d6d5e08901be90dff2528491d75d9bb73c2dd7 A
5362026-04-13T16:13:18.439Z 2 a01dcf86c5fcf78e7464786681d6d5e08901be90dff2528491d75d9bb73c2dd7 A
5372026-04-13T16:13:18.439Z
5382026-04-13T16:13:18.439ZNONCES 0 1 2 DIFF
5392026-04-13T16:13:18.439Z------ ------------------------ ------------------------ ------------------------ -----
5402026-04-13T16:13:18.439Z 0 91f7fccec4f9c49a0617ceaf 91f7fccec4f9c49a0617ceaf 91f7fccec4f9c49a0617ceaf
5412026-04-13T16:13:18.439Z
5422026-04-13T16:13:18.439Z TAGS 0 1 2 DIFF
5432026-04-13T16:13:18.439Z------ -------------------------------- -------------------------------- -------------------------------- -----
5442026-04-13T16:13:18.439Z 0 3073dce2ed1c1279551322484403bbaa 3073dce2ed1c1279551322484403bbaa 3073dce2ed1c1279551322484403bbaa
5452026-04-13T16:13:18.439Z
5462026-04-13T16:13:18.439ZHASHES 0 1 2 DIFF
5472026-04-13T16:13:18.439Z------ ---------------- ---------------- ---------------- -----
5482026-04-13T16:13:18.439Z
5492026-04-13T16:13:18.443Zdump block test passed
5502026-04-13T16:13:18.443ZInitial upstairs tests have completed, stopping all downstairs
5512026-04-13T16:13:23.460ZCreating 4 larger downstairs regions
5522026-04-13T16:13:23.579ZStarting 4 downstairs
5532026-04-13T16:13:28.584Zdsc restarted at PID: 1203
5542026-04-13T16:13:28.643ZNow do the replace-reconcile test
5552026-04-13T16:13:28.656ZUsing 8840 for the replacement port
5562026-04-13T16:17:00.983ZCompleted test: replace-reconcile
5572026-04-13T16:17:00.986ZNow do the replace-before-active test
5582026-04-13T16:20:17.911ZCompleted test: replace-before-active
5592026-04-13T16:20:17.911ZAll tests have completed, stopping all downstairs
5602026-04-13T16:20:17.927Z
5612026-04-13T16:20:17.927ZAll Tests have passed
5622026-04-13T16:20:17.931Z9:09 Test duration
5632026-04-13T16:20:17.931Z
5642026-04-13T16:20:17.931Zreal 9:08.943794834
5652026-04-13T16:20:17.931Zuser 6:47.709979402
5662026-04-13T16:20:17.931Zsys 5.717621862
5672026-04-13T16:20:17.931Ztrap 0.184162027
5682026-04-13T16:20:17.931Ztflt 0.028825630
5692026-04-13T16:20:17.931Zdflt 0.028149799
5702026-04-13T16:20:17.931Zkflt 0.011895826
5712026-04-13T16:20:17.931Zlock 5:45:21.425967211
5722026-04-13T16:20:17.931Zslp 26:33.675292007
5732026-04-13T16:20:17.931Zlat 30.487708072
5742026-04-13T16:20:17.931Zstop 0.013983152
5752026-04-13T16:20:17.931Z+ echo 'test-up-encrypted ends'
5762026-04-13T16:20:17.931Ztest-up-encrypted ends
5772026-04-13T16:20:22.932Zprocess exited: duration 557748 ms, exit code 0
5782026-04-13T16:20:22.932Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5792026-04-13T16:21:22.960Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5802026-04-13T16:21:22.960Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5812026-04-13T16:21:22.972Zfound 14 output files
5822026-04-13T16:21:22.973Zuploading: /tmp/test_up-build/dsc-out.txt (47600 bytes)
5832026-04-13T16:21:23.986Zuploaded: /tmp/test_up-build/dsc-out.txt
5842026-04-13T16:21:23.986Zuploading: /tmp/test_up-build/test_up_out.txt (22564233 bytes)
5852026-04-13T16:21:25.141Zuploaded: /tmp/test_up-build/test_up_out.txt
5862026-04-13T16:21:25.141Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2670 bytes)
5872026-04-13T16:21:26.153Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5882026-04-13T16:21:26.153Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (548534 bytes)
5892026-04-13T16:21:27.179Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5902026-04-13T16:21:27.182Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (978865 bytes)
5912026-04-13T16:21:28.204Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5922026-04-13T16:21:28.204Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (543222 bytes)
5932026-04-13T16:21:29.228Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5942026-04-13T16:21:29.231Zuploading: /tmp/debug/df.txt (1270 bytes)
5952026-04-13T16:21:30.241Zuploaded: /tmp/debug/df.txt
5962026-04-13T16:21:30.241Zuploading: /tmp/debug/dtrace.txt (614987 bytes)
5972026-04-13T16:21:31.264Zuploaded: /tmp/debug/dtrace.txt
5982026-04-13T16:21:31.264Zuploading: /tmp/debug/iostat.txt (183142 bytes)
5992026-04-13T16:21:31.278Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 183142 -> 185824
6002026-04-13T16:21:32.285Zuploaded: /tmp/debug/iostat.txt
6012026-04-13T16:21:32.285Zuploading: /tmp/debug/mpstat.txt (446551 bytes)
6022026-04-13T16:21:32.303Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 446551 -> 453821
6032026-04-13T16:21:33.311Zuploaded: /tmp/debug/mpstat.txt
6042026-04-13T16:21:33.311Zuploading: /tmp/debug/paging.txt (79178 bytes)
6052026-04-13T16:21:33.321Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 79178 -> 80579
6062026-04-13T16:21:34.329Zuploaded: /tmp/debug/paging.txt
6072026-04-13T16:21:34.329Zuploading: /tmp/debug/prstat.txt (850513 bytes)
6082026-04-13T16:21:34.347Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 850513 -> 864789
6092026-04-13T16:21:35.354Zuploaded: /tmp/debug/prstat.txt
6102026-04-13T16:21:35.354Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
6112026-04-13T16:21:36.364Zuploaded: /tmp/debug/psrinfo.txt
6122026-04-13T16:21:36.364Zuploading: /tmp/debug/upstairs-info.txt (66521 bytes)
6132026-04-13T16:21:37.378Zuploaded: /tmp/debug/upstairs-info.txt