01KYN0BSFEVEQ1NYCZFEP5QJWZ: test-up-unencrypted

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: 01KYN0CACMWQZCYGR619XG82AG

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12026-07-28T18:51:44.313Zjob dependencies complete; ready to run (waiting for 12 m 25 s)
22026-07-28T18:53:16.683Zjob assigned to worker 01KYN14MY168WSHBQTETDQGPEM [factory aws, i-06103323ceea1478a] (queued for 1 m 32 s)
32026-07-28T18:53:26.609Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42026-07-28T18:53:28.166Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52026-07-28T18:53:28.171Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62026-07-28T18:53:29.676Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72026-07-28T18:53:29.683Zdownloading input: /input/build/work/bins/crutest.gz
82026-07-28T18:53:31.290Zdownloaded input: /input/build/work/bins/crutest.gz
92026-07-28T18:53:31.296Zdownloading input: /input/build/work/bins/dsc.gz
102026-07-28T18:53:32.070Zdownloaded input: /input/build/work/bins/dsc.gz
112026-07-28T18:53:32.079Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122026-07-28T18:53:32.104Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132026-07-28T18:53:32.107Zdownloading input: /input/build/work/scripts/test_ds.sh
142026-07-28T18:53:32.178Zdownloaded input: /input/build/work/scripts/test_ds.sh
152026-07-28T18:53:32.181Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162026-07-28T18:53:32.207Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172026-07-28T18:53:32.208Zdownloading input: /input/build/work/scripts/test_repair.sh
182026-07-28T18:53:32.235Zdownloaded input: /input/build/work/scripts/test_repair.sh
192026-07-28T18:53:32.235Zdownloading input: /input/build/work/scripts/test_replay.sh
202026-07-28T18:53:32.262Zdownloaded input: /input/build/work/scripts/test_replay.sh
212026-07-28T18:53:32.262Zdownloading input: /input/build/work/scripts/test_up.sh
222026-07-28T18:53:32.289Zdownloaded input: /input/build/work/scripts/test_up.sh
232026-07-28T18:53:32.290Zdownloading input: /input/build/work/scripts/upstairs_info.d
242026-07-28T18:53:32.315Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252026-07-28T18:53:32.318Zdownloading input: /input/build/tmp/cargo-test-out.log
262026-07-28T18:53:32.851Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272026-07-28T18:53:32.851Zstarting task 0: "setup"
282026-07-28T18:53:32.857Z++ uname -s
292026-07-28T18:53:32.861Z+ kern=SunOS
302026-07-28T18:53:32.861Z+ build_user=build
312026-07-28T18:53:32.861Z+ build_uid=12345
322026-07-28T18:53:32.861Z+ work_dir=/work
332026-07-28T18:53:32.861Z+ input_dir=/input
342026-07-28T18:53:32.861Z+ [[ 0 == 12345 ]]
352026-07-28T18:53:32.861Z+ case "$kern" in
362026-07-28T18:53:32.861Z+ groupadd -g 12345 build
372026-07-28T18:53:32.861Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382026-07-28T18:53:34.866Z+ zfs create -o mountpoint=/work rpool/work
392026-07-28T18:53:35.608Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402026-07-28T18:53:35.614Z+ home_fs=zfs
412026-07-28T18:53:35.614Z+ [[ zfs == autofs ]]
422026-07-28T18:53:35.614Z+ mkdir -p /home/build
432026-07-28T18:53:35.614Z+ chown build:build /home/build /work
442026-07-28T18:53:36.612Z+ chmod 0700 /home/build /work
452026-07-28T18:53:36.616Zprocess exited: duration 3761 ms, exit code 0
 
462026-07-28T18:53:36.625Zstarting task 1: "authentication"
472026-07-28T18:53:36.644Zprocess exited: duration 16 ms, exit code 0
 
482026-07-28T18:53:36.653Zstarting task 2: "build"
492026-07-28T18:53:36.656Z+ banner cores
502026-07-28T18:53:36.661Z
512026-07-28T18:53:36.661Z #### #### ##### ###### ####
522026-07-28T18:53:36.662Z # # # # # # # #
532026-07-28T18:53:36.662Z # # # # # ##### ####
542026-07-28T18:53:36.662Z # # # ##### # #
552026-07-28T18:53:36.662Z # # # # # # # # #
562026-07-28T18:53:36.662Z #### #### # # ###### ####
572026-07-28T18:53:36.662Z
582026-07-28T18:53:36.662Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592026-07-28T18:53:36.666Z+ echo 'input bins dir contains:'
602026-07-28T18:53:36.666Zinput bins dir contains:
612026-07-28T18:53:36.666Z+ ls -ltr /input/build/work/bins
622026-07-28T18:53:36.666Ztotal 1014826
632026-07-28T18:53:36.666Z-rw-r--r-- 1 root root 152757137 Jul 28 18:53 crucible-downstairs.gz
642026-07-28T18:53:36.666Z-rw-r--r-- 1 root root 145715461 Jul 28 18:53 crucible-hammer.gz
652026-07-28T18:53:36.667Z-rw-r--r-- 1 root root 151811822 Jul 28 18:53 crutest.gz
662026-07-28T18:53:36.667Z-rw-r--r-- 1 root root 68964916 Jul 28 18:53 dsc.gz
672026-07-28T18:53:36.667Z+ banner unpack
682026-07-28T18:53:36.667Z
692026-07-28T18:53:36.667Z # # # # ##### ## #### # #
702026-07-28T18:53:36.667Z # # ## # # # # # # # # #
712026-07-28T18:53:36.667Z # # # # # # # # # # ####
722026-07-28T18:53:36.667Z # # # # # ##### ###### # # #
732026-07-28T18:53:36.667Z # # # ## # # # # # # #
742026-07-28T18:53:36.667Z #### # # # # # #### # #
752026-07-28T18:53:36.667Z
762026-07-28T18:53:36.675Z+ mkdir -p /var/tmp/bins
772026-07-28T18:53:36.675Z+ for t in "$input/bins/"*.gz
782026-07-28T18:53:36.675Z++ basename /input/build/work/bins/crucible-downstairs.gz
792026-07-28T18:53:36.675Z+ b=crucible-downstairs.gz
802026-07-28T18:53:36.675Z+ b=crucible-downstairs
812026-07-28T18:53:36.675Z+ gunzip
822026-07-28T18:53:39.230Z+ chmod +x /var/tmp/bins/crucible-downstairs
832026-07-28T18:53:39.239Z+ for t in "$input/bins/"*.gz
842026-07-28T18:53:39.239Z++ basename /input/build/work/bins/crucible-hammer.gz
852026-07-28T18:53:39.239Z+ b=crucible-hammer.gz
862026-07-28T18:53:39.239Z+ b=crucible-hammer
872026-07-28T18:53:39.239Z+ gunzip
882026-07-28T18:53:41.630Z+ chmod +x /var/tmp/bins/crucible-hammer
892026-07-28T18:53:41.638Z+ for t in "$input/bins/"*.gz
902026-07-28T18:53:41.638Z++ basename /input/build/work/bins/crutest.gz
912026-07-28T18:53:41.638Z+ b=crutest.gz
922026-07-28T18:53:41.638Z+ b=crutest
932026-07-28T18:53:41.639Z+ gunzip
942026-07-28T18:53:44.147Z+ chmod +x /var/tmp/bins/crutest
952026-07-28T18:53:44.156Z+ for t in "$input/bins/"*.gz
962026-07-28T18:53:44.156Z++ basename /input/build/work/bins/dsc.gz
972026-07-28T18:53:44.156Z+ b=dsc.gz
982026-07-28T18:53:44.156Z+ b=dsc
992026-07-28T18:53:44.156Z+ gunzip
1002026-07-28T18:53:45.281Z+ chmod +x /var/tmp/bins/dsc
1012026-07-28T18:53:45.310Z+ export BINDIR=/var/tmp/bins
1022026-07-28T18:53:45.310Z+ BINDIR=/var/tmp/bins
1032026-07-28T18:53:45.310Z+ export RUST_BACKTRACE=1
1042026-07-28T18:53:45.310Z+ RUST_BACKTRACE=1
1052026-07-28T18:53:45.310Z+ jobpid=1088
1062026-07-28T18:53:45.310Z+ echo 'Setup debug logging'
1072026-07-28T18:53:45.310ZSetup debug logging
1082026-07-28T18:53:45.310Z+ mkdir /tmp/debug
1092026-07-28T18:53:45.310Z+ sleep 7200
1102026-07-28T18:53:45.310Z+ psrinfo -v
1112026-07-28T18:53:45.310Z+ df -h
1122026-07-28T18:53:45.310Z+ prstat -d d -mLc 1
1132026-07-28T18:53:45.310Z+ iostat -T d -xn 1
1142026-07-28T18:53:45.353Z+ mpstat -T d 1
1152026-07-28T18:53:45.353Z+ vmstat -T d -p 1
1162026-07-28T18:53:45.353Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1172026-07-28T18:53:45.353Z+ banner test_up_unencrypted
1182026-07-28T18:53:45.353Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1192026-07-28T18:53:45.353Z
1202026-07-28T18:53:45.353Z ##### ###### #### ##### # # ##### # # # #
1212026-07-28T18:53:45.353Z # # # # # # # # # # ## #
1222026-07-28T18:53:45.353Z # ##### #### # # # # # # # # # #
1232026-07-28T18:53:45.353Z # # # # # # ##### # # # # #
1242026-07-28T18:53:45.353Z # # # # # # # # # # # ##
1252026-07-28T18:53:45.353Z # ###### #### # ####### #### # ####### #### # #
1262026-07-28T18:53:45.353Z
1272026-07-28T18:53:45.353Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1282026-07-28T18:53:45.361Z/input/build/work
1292026-07-28T18:53:45.362ZTurn off color for downstairs dump
1302026-07-28T18:53:45.362Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1312026-07-28T18:53:45.362ZCreating 3 downstairs regions
1322026-07-28T18:53:45.534ZStarting 3 downstairs
1332026-07-28T18:53:45.543Zdsc started at PID: 1133
1342026-07-28T18:53:50.584ZDisable automatic restart on all downstairs
1352026-07-28T18:53:50.595Z
1362026-07-28T18:53:50.595ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1372026-07-28T18:53:50.599ZRunning test: span
1382026-07-28T18:53:54.692ZCompleted test: span
1392026-07-28T18:53:59.696ZRunning test: big
1402026-07-28T18:54:03.752ZCompleted test: big
1412026-07-28T18:54:08.758ZRunning test: dep
1422026-07-28T18:54:16.425ZCompleted test: dep
1432026-07-28T18:54:21.282ZRunning test: balloon
1442026-07-28T18:54:27.771ZCompleted test: balloon
1452026-07-28T18:54:32.813ZRunning test: deactivate
1462026-07-28T18:54:36.848ZCompleted test: deactivate
1472026-07-28T18:54:41.852ZRunning hammer
1482026-07-28T18:54:43.063ZRun repair tests
1492026-07-28T18:54:43.067Z/var/tmp/bins/crutest fill -g 31 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1502026-07-28T18:54:43.084Z{"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-07-28T18:54:41.54806103Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
1512026-07-28T18:54:43.088Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.548338311Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
1522026-07-28T18:54:43.088Z{"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-07-28T18:54:41.549288526Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
1532026-07-28T18:54:43.088Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.549516986Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
1542026-07-28T18:54:43.088Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"771537701e93e34aa28534fa5d7d0b08164218fe\",\n git_commit_timestamp: \"2026-07-28T18:37:56.000000000Z\",\n git_branch: \"alan/improve-a-log\",\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-07-28T18:54:41.549547201Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
1552026-07-28T18:54:43.088Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.549556649Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
1562026-07-28T18:54:43.088Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.549568957Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
1572026-07-28T18:54:43.088Z{"msg":"Crucible 79493762-f409-45b4-be3f-3d4b43e45a93 has session id: 1fe557b2-e266-4d05-864e-a8c330918007","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.549882462Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1582026-07-28T18:54:43.088Z{"msg":"Upstairs opts: Upstairs UUID: 79493762-f409-45b4-be3f-3d4b43e45a93, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-07-28T18:54:41.549918186Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1592026-07-28T18:54:43.089Z{"msg":"Crucible stats registered with UUID: 79493762-f409-45b4-be3f-3d4b43e45a93","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.549929364Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1602026-07-28T18:54:43.089Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:54:41.549938442Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1612026-07-28T18:54:43.089Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.55006607Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1622026-07-28T18:54:43.089Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550083747Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1632026-07-28T18:54:43.089Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550098864Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1642026-07-28T18:54:43.089Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550269055Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
1652026-07-28T18:54:43.089Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550282682Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
1662026-07-28T18:54:43.089Z{"msg":"79493762-f409-45b4-be3f-3d4b43e45a93 active request set","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550314067Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1672026-07-28T18:54:43.089Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550324365Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1682026-07-28T18:54:43.089Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550334393Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1692026-07-28T18:54:43.091Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550348621Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1702026-07-28T18:54:43.091Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550358349Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1712026-07-28T18:54:43.093Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550369007Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1722026-07-28T18:54:43.093Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550379486Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1732026-07-28T18:54:43.093Z{"msg":"ds_connection connected from Ok(127.0.0.1:54610)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.5504137Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1742026-07-28T18:54:43.093Z{"msg":"ds_connection connected from Ok(127.0.0.1:52004)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550426247Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1752026-07-28T18:54:43.093Z{"msg":"ds_connection connected from Ok(127.0.0.1:60078)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.550449483Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"io task","client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1762026-07-28T18:54:43.093Z{"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-07-28T18:54:41.551091392Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1772026-07-28T18:54:43.093Z{"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-07-28T18:54:41.551117907Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1782026-07-28T18:54:43.093Z{"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-07-28T18:54:41.551141983Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1792026-07-28T18:54:43.093Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551282108Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1802026-07-28T18:54:43.093Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551300845Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1812026-07-28T18:54:43.093Z{"msg":"[0]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551342938Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1822026-07-28T18:54:43.093Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551353676Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1832026-07-28T18:54:43.093Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551364544Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1842026-07-28T18:54:43.093Z{"msg":"[1]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551375292Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1852026-07-28T18:54:43.094Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.55138465Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1862026-07-28T18:54:43.094Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551408536Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1872026-07-28T18:54:43.094Z{"msg":"[2]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551419244Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1882026-07-28T18:54:43.097Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551429423Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1892026-07-28T18:54:43.098Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.5514437Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1902026-07-28T18:54:43.098Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551453748Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1912026-07-28T18:54:43.098Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551463347Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1922026-07-28T18:54:43.098Z{"msg":"Next flush: 1501","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551472965Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1932026-07-28T18:54:43.098Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551482943Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"":"downstairs","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1942026-07-28T18:54:43.098Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551493421Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1952026-07-28T18:54:43.098Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.55150253Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"0","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1962026-07-28T18:54:43.098Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551512908Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"1","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1972026-07-28T18:54:43.098Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551522956Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"client":"2","":"downstairs","session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1982026-07-28T18:54:43.098Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551533055Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
1992026-07-28T18:54:43.098Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551542923Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
2002026-07-28T18:54:43.099Z{"msg":"79493762-f409-45b4-be3f-3d4b43e45a93 is now active with session: 1fe557b2-e266-4d05-864e-a8c330918007","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551553531Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
2012026-07-28T18:54:43.099ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2022026-07-28T18:54:43.099Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551582376Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"session_id":"1fe557b2-e266-4d05-864e-a8c330918007"}
2032026-07-28T18:54:43.099Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551592184Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
2042026-07-28T18:54:43.099Z{"msg":"Activated sub_volume 79493762-f409-45b4-be3f-3d4b43e45a93","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551600763Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
2052026-07-28T18:54:43.099Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.551608801Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
2062026-07-28T18:54:43.099Z{"msg":"Fill test","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.55161689Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
2072026-07-28T18:54:43.099ZRead and Verify all blocks (0..50 range:false)
2082026-07-28T18:54:43.099Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30----------------------------------------------------------------
2092026-07-28T18:54:43.099Z,"time":"2026-07-28T18:54:41.557691941Z","hostname":" Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2102026-07-28T18:54:43.099Zw-01KYN14MY168WSHBQTETDQGPEM"States:,"pid": Active1170 Active Active
2112026-07-28T18:54:43.099Z,"JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2122026-07-28T18:54:43.099Ztask":"crutest"}
2132026-07-28T18:54:43.100Z 1002 Acked Read 50{ Done" Done Donemsg" false:"
2142026-07-28T18:54:43.100ZCLIENT: Tests done. All submitted work has been ACK'd","v":0,"name":" STATES DS:0 DS:1 DS:2 TOTAL
2152026-07-28T18:54:43.100Zcrucible" Sent ,"level 0 ": 0 30 0 0
2162026-07-28T18:54:43.101Z Done 1 1 1 3
2172026-07-28T18:54:43.101Z, Skipped " 0 time 0 " 0 : 0
2182026-07-28T18:54:43.101Z" Error 0 0 0 0
2192026-07-28T18:54:43.101Z2026-07-28T18:54:41.557724705Z"Last Flush: ,"Some(JobId(1001)) hostname"Some(JobId(1001)) :Some(JobId(1001)) "
2202026-07-28T18:54:43.101Zw-01KYN14MY168WSHBQTETDQGPEM"Downstairs last five completed:,"pid":1170,"task":"crutest" 1001} 1000
2212026-07-28T18:54:43.101Z
2222026-07-28T18:54:43.101ZUpstairs last five completed: 1002 1001 1000
2232026-07-28T18:54:43.101Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:41.557766118Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
2242026-07-28T18:54:47.096Z----------------------------------------------------------------
2252026-07-28T18:54:47.096Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2262026-07-28T18:54:47.096ZDownstairs last five completed: 1003 1002 1001 1000
2272026-07-28T18:54:47.096ZUpstairs last five completed: 1003 1002 1001 1000
2282026-07-28T18:54:47.100Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.558476338Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
2292026-07-28T18:54:47.100Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.558510472Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170,"task":"crutest"}
2302026-07-28T18:54:47.100Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:54:45.558520541Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1170}
2312026-07-28T18:54:47.103ZRepair setup passed
2322026-07-28T18:54:47.106ZCopy the region for /var/tmp/test_up-build/8830
2332026-07-28T18:54:47.106Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2342026-07-28T18:54:47.109Z/var/tmp/bins/crutest fill -g 32 -q --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-07-28T18:54:47.125Z{"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-07-28T18:54:45.588631503Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2362026-07-28T18:54:47.129Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.588968584Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2372026-07-28T18:54:47.129Z{"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-07-28T18:54:45.589665333Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2382026-07-28T18:54:47.129Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.589907901Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2392026-07-28T18:54:47.129Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"771537701e93e34aa28534fa5d7d0b08164218fe\",\n git_commit_timestamp: \"2026-07-28T18:37:56.000000000Z\",\n git_branch: \"alan/improve-a-log\",\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-07-28T18:54:45.589934786Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2402026-07-28T18:54:47.130Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.589948204Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2412026-07-28T18:54:47.130Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.589960411Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2422026-07-28T18:54:47.130Z{"msg":"Crucible 71dc0b10-925e-4dbd-a2f8-865952472736 has session id: e926f160-11ee-4351-bdfa-b38d1d46a3fb","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.59025332Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2432026-07-28T18:54:47.131Z{"msg":"Upstairs opts: Upstairs UUID: 71dc0b10-925e-4dbd-a2f8-865952472736, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-07-28T18:54:45.590304411Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2442026-07-28T18:54:47.131Z{"msg":"Crucible stats registered with UUID: 71dc0b10-925e-4dbd-a2f8-865952472736","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590319179Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2452026-07-28T18:54:47.132Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:54:45.590328527Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2462026-07-28T18:54:47.132Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590455935Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2472026-07-28T18:54:47.132Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590476631Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2482026-07-28T18:54:47.132Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.59048683Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2492026-07-28T18:54:47.132Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590673717Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2502026-07-28T18:54:47.132Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590690994Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2512026-07-28T18:54:47.132Z{"msg":"71dc0b10-925e-4dbd-a2f8-865952472736 active request set","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590705012Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2522026-07-28T18:54:47.132Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590718379Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2532026-07-28T18:54:47.132Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590728148Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2542026-07-28T18:54:47.132Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590741985Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2552026-07-28T18:54:47.132Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590751564Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2562026-07-28T18:54:47.132Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590761992Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2572026-07-28T18:54:47.132Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.5907727Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2582026-07-28T18:54:47.132Z{"msg":"ds_connection connected from Ok(127.0.0.1:42803)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590813573Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2592026-07-28T18:54:47.132Z{"msg":"ds_connection connected from Ok(127.0.0.1:49614)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590825191Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2602026-07-28T18:54:47.132Z{"msg":"ds_connection connected from Ok(127.0.0.1:39291)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.590836229Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"io task","client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2612026-07-28T18:54:47.132Z{"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-07-28T18:54:45.591615783Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2622026-07-28T18:54:47.132Z{"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-07-28T18:54:45.591650427Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2632026-07-28T18:54:47.133Z{"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-07-28T18:54:45.591666704Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2642026-07-28T18:54:47.133Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591815698Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2652026-07-28T18:54:47.133Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591829566Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2662026-07-28T18:54:47.133Z{"msg":"[0]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591864949Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2672026-07-28T18:54:47.133Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591880397Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2682026-07-28T18:54:47.133Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591890775Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2692026-07-28T18:54:47.133Z{"msg":"[1]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591905242Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2702026-07-28T18:54:47.133Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591915131Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2712026-07-28T18:54:47.133Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591929448Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2722026-07-28T18:54:47.133Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591939347Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2732026-07-28T18:54:47.133Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591953084Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2742026-07-28T18:54:47.134Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591962692Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2752026-07-28T18:54:47.134Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.59197637Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2762026-07-28T18:54:47.134Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591986208Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2772026-07-28T18:54:47.134Z{"msg":"Next flush: 1502","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.591999826Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2782026-07-28T18:54:47.134Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592009784Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"":"downstairs","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2792026-07-28T18:54:47.134Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592019802Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2802026-07-28T18:54:47.134Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592029411Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"0","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2812026-07-28T18:54:47.134Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592039409Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"1","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2822026-07-28T18:54:47.134Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592049547Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"client":"2","":"downstairs","session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2832026-07-28T18:54:47.134Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592059166Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2842026-07-28T18:54:47.134Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592069104Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2852026-07-28T18:54:47.139Z{"msg":"71dc0b10-925e-4dbd-a2f8-865952472736 is now active with session: e926f160-11ee-4351-bdfa-b38d1d46a3fb","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592079832Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2862026-07-28T18:54:47.139Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.59208917Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"session_id":"e926f160-11ee-4351-bdfa-b38d1d46a3fb"}
2872026-07-28T18:54:47.139Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592098269Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2882026-07-28T18:54:47.139Z{"msg":"Activated sub_volume 71dc0b10-925e-4dbd-a2f8-865952472736","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592106817Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176}
2892026-07-28T18:54:47.139Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592115076Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2902026-07-28T18:54:47.139ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2912026-07-28T18:54:47.139ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2922026-07-28T18:54:47.139Z{"msg":"Fill test","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.592509797Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2932026-07-28T18:54:47.139ZRead and Verify all blocks (0..50 range:false)
2942026-07-28T18:54:47.139Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.598111791Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
2952026-07-28T18:54:47.139Z----------------------------------------------------------------
2962026-07-28T18:54:47.139Z{"msg":"CLIENT: Tests done. All submitted work has been ACK'd","v":0, Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
2972026-07-28T18:54:47.140Z"States:name":"crucible Active" Active, Active"
2982026-07-28T18:54:47.140Zlevel"JOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2992026-07-28T18:54:47.140Z:30 1002 Acked Read 50," Donetime" Done: Done" false
3002026-07-28T18:54:47.140Z2026-07-28T18:54:45.598143895Z","hostname":" STATES DS:0 DS:1 DS:2 TOTAL
3012026-07-28T18:54:47.140Zw-01KYN14MY168WSHBQTETDQGPEM" Sent ," 0 pid" 0 : 0 1176 0
3022026-07-28T18:54:47.140Z," Done task" 1 : 1 " 1 3
3032026-07-28T18:54:47.140Zcrutest" Skipped 0 } 0
3042026-07-28T18:54:47.140Z 0 0
3052026-07-28T18:54:47.140Z Error 0 0 0 0
3062026-07-28T18:54:47.140ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
3072026-07-28T18:54:47.140ZDownstairs last five completed: 1001 1000
3082026-07-28T18:54:47.140ZUpstairs last five completed: 1002 1001 1000
3092026-07-28T18:54:47.141Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:45.598204745Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
3102026-07-28T18:54:51.136Z----------------------------------------------------------------
3112026-07-28T18:54:51.136Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3122026-07-28T18:54:51.136ZDownstairs last five completed: 1003 1002 1001 1000
3132026-07-28T18:54:51.136ZUpstairs last five completed: 1003 1002 1001 1000
3142026-07-28T18:54:51.140Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.599367775Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
3152026-07-28T18:54:51.140Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.599402649Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1176,"task":"crutest"}
3162026-07-28T18:54:51.143ZRepair part 1 passed
3172026-07-28T18:54:51.143Z
3182026-07-28T18:54:51.143ZKill the current downstairs
3192026-07-28T18:54:51.183ZDownstairs 2 stopped
3202026-07-28T18:54:51.183Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3212026-07-28T18:54:51.187ZNow put back the original so we have a mismatch
3222026-07-28T18:54:51.187Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3232026-07-28T18:54:51.187ZRestart downstairs with old directory
3242026-07-28T18:54:51.199Z/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-07-28T18:54:51.211ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3262026-07-28T18:54:51.214Z 0 000-009 32 32 31 1502 1502 1501 F F F <---
3272026-07-28T18:54:51.214Z 1 010-019 32 32 31 1502 1502 1501 F F F <---
3282026-07-28T18:54:51.214Z 2 020-029 32 32 31 1502 1502 1501 F F F <---
3292026-07-28T18:54:51.214Z 3 030-039 32 32 31 1502 1502 1501 F F F <---
3302026-07-28T18:54:51.214Z 4 040-049 32 32 31 1502 1502 1501 F F F <---
3312026-07-28T18:54:51.214ZMax gen: 32, Max flush: 1502
3322026-07-28T18:54:51.423ZError: Difference in extent metadata found!
3332026-07-28T18:54:51.423Z
3342026-07-28T18:54:51.423ZStack backtrace:
3352026-07-28T18:54:51.423Z 0: anyhow::error::<impl anyhow::Error>::msg
3362026-07-28T18:54:51.423Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/backtrace.rs:10:14
3372026-07-28T18:54:51.423Z 1: anyhow::__private::format_err
3382026-07-28T18:54:51.423Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/anyhow-1.0.102/src/lib.rs:687:13
3392026-07-28T18:54:51.442Zdump test found error as expected
3402026-07-28T18:54:51.447Z
3412026-07-28T18:54:51.447Z
3422026-07-28T18:54:51.447Z/var/tmp/bins/crutest verify --range -g 33 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3432026-07-28T18:54:51.464Z{"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-07-28T18:54:49.924669292Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
3442026-07-28T18:54:51.468Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.924925717Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
3452026-07-28T18:54:51.469Z{"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-07-28T18:54:49.925575534Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
3462026-07-28T18:54:51.469Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.92582677Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
3472026-07-28T18:54:51.469Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"771537701e93e34aa28534fa5d7d0b08164218fe\",\n git_commit_timestamp: \"2026-07-28T18:37:56.000000000Z\",\n git_branch: \"alan/improve-a-log\",\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-07-28T18:54:49.925854395Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
3482026-07-28T18:54:51.469Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.925867343Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
3492026-07-28T18:54:51.469Z{"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: false, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.925879281Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
3502026-07-28T18:54:51.469Z{"msg":"Crucible 4fdeb057-8feb-4c04-907d-b1b41d6003c4 has session id: 66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926234149Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3512026-07-28T18:54:51.469Z{"msg":"Upstairs opts: Upstairs UUID: 4fdeb057-8feb-4c04-907d-b1b41d6003c4, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: false, 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-07-28T18:54:49.926269383Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3522026-07-28T18:54:51.469Z{"msg":"Crucible stats registered with UUID: 4fdeb057-8feb-4c04-907d-b1b41d6003c4","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926284571Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3532026-07-28T18:54:51.469Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:54:49.926294119Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3542026-07-28T18:54:51.469Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926407759Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3552026-07-28T18:54:51.469Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926446222Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3562026-07-28T18:54:51.469Z{"msg":"client is waiting for oneshot","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.92645746Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3572026-07-28T18:54:51.469Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926638009Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
3582026-07-28T18:54:51.469Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926650037Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
3592026-07-28T18:54:51.470Z{"msg":"4fdeb057-8feb-4c04-907d-b1b41d6003c4 active request set","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926666344Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3602026-07-28T18:54:51.470Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926683091Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3612026-07-28T18:54:51.470Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926697379Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3622026-07-28T18:54:51.470Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926707027Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3632026-07-28T18:54:51.470Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926724714Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3642026-07-28T18:54:51.470Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926734602Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3652026-07-28T18:54:51.470Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.92674891Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3662026-07-28T18:54:51.470Z{"msg":"ds_connection connected from Ok(127.0.0.1:39280)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926821447Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3672026-07-28T18:54:51.470Z{"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-07-28T18:54:49.926838584Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3682026-07-28T18:54:51.471Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:54:49.926850682Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3692026-07-28T18:54:51.471Z{"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-07-28T18:54:49.926866769Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3702026-07-28T18:54:51.471Z{"msg":"sleeping for 10s before connecting","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926909982Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3712026-07-28T18:54:51.471Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.9269208Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3722026-07-28T18:54:51.471Z{"msg":"ds_connection connected from Ok(127.0.0.1:62812)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.926937277Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3732026-07-28T18:54:51.471Z{"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-07-28T18:54:49.927558848Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3742026-07-28T18:54:51.471Z{"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-07-28T18:54:49.92760835Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3752026-07-28T18:54:51.471Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.92778098Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3762026-07-28T18:54:51.471Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:49.927802456Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3772026-07-28T18:55:01.467Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.928082407Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3782026-07-28T18:55:01.467Z{"msg":"ds_connection connected from Ok(127.0.0.1:63257)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.928146286Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"io task","client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3792026-07-28T18:55:01.476Z{"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-07-28T18:54:59.929321951Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3802026-07-28T18:55:01.476Z{"msg":"[0]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929632727Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3812026-07-28T18:55:01.476Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929649014Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3822026-07-28T18:55:01.477Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929659362Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3832026-07-28T18:55:01.477Z{"msg":"[1]R flush_numbers: [1502, 1502, 1502, 1502, 1502]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.92967395Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3842026-07-28T18:55:01.477Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929683928Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3852026-07-28T18:55:01.477Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929698785Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3862026-07-28T18:55:01.477Z{"msg":"[2]R flush_numbers: [1501, 1501, 1501, 1501, 1501]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929708794Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3872026-07-28T18:55:01.477Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929722901Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3882026-07-28T18:55:01.477Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.92973289Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3892026-07-28T18:55:01.477Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929746627Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3902026-07-28T18:55:01.477Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929757055Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3912026-07-28T18:55:01.477Z{"msg":"Next flush: 1503","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929770673Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3922026-07-28T18:55:01.478Z{"msg":"extent 0 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.92978556Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3932026-07-28T18:55:01.478Z{"msg":"extent:0 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929804797Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3942026-07-28T18:55:01.478Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929816005Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3952026-07-28T18:55:01.478Z{"msg":"extent 1 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929834352Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3962026-07-28T18:55:01.478Z{"msg":"extent:1 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929848269Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3972026-07-28T18:55:01.478Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929859787Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3982026-07-28T18:55:01.478Z{"msg":"extent 2 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929873585Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
3992026-07-28T18:55:01.480Z{"msg":"extent:2 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929892322Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4002026-07-28T18:55:01.480Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.92990342Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4012026-07-28T18:55:01.480Z{"msg":"extent 3 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929917077Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4022026-07-28T18:55:01.480Z{"msg":"extent:3 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929935384Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4032026-07-28T18:55:01.480Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929946142Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4042026-07-28T18:55:01.480Z{"msg":"extent 4 needs reconciliation: ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })]))","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929964419Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4052026-07-28T18:55:01.480Z{"msg":"extent:4 ClientMap(ClientData([Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 32, flush: 1502, dirty: false }), Some(ExtentMetadata { generation: 31, flush: 1501, dirty: false })])) => 0","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929978317Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4062026-07-28T18:55:01.481Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.929993014Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"mend","":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4072026-07-28T18:55:01.481Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930007762Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4082026-07-28T18:55:01.481Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930022569Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4092026-07-28T18:55:01.481Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930032677Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4102026-07-28T18:55:01.481Z{"msg":"Full repair list: {ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(1): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(2): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930052384Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4112026-07-28T18:55:01.481Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(8), op: ExtentFlush { repair_id: ReconciliationId(8), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(2), client_id: ClientId(0), flush_number: 1503, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930219675Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4122026-07-28T18:55:01.481Z{"msg":"starting reconciliation bb82ffea-2346-4286-bb5a-7eef4dc62bc7: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930231563Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4132026-07-28T18:55:01.482Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.930270316Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4142026-07-28T18:55:01.486Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.942388644Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4152026-07-28T18:55:01.486Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.944351502Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4162026-07-28T18:55:01.486Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.946318769Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4172026-07-28T18:55:01.489Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.948293035Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4182026-07-28T18:55:01.489Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.949969633Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"":"downstairs","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4192026-07-28T18:55:01.490Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.949991679Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"0","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4202026-07-28T18:55:01.490Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950001757Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"1","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4212026-07-28T18:55:01.490Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950015975Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"client":"2","":"downstairs","session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4222026-07-28T18:55:01.490Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950025983Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4232026-07-28T18:55:01.490Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950039251Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4242026-07-28T18:55:01.490Z{"msg":"4fdeb057-8feb-4c04-907d-b1b41d6003c4 is now active with session: 66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950049179Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"session_id":"66ebbfff-8a7c-40e6-8ede-1fbd0fffdabc"}
4252026-07-28T18:55:01.490Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950062397Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
4262026-07-28T18:55:01.491Z{"msg":"Activated sub_volume 4fdeb057-8feb-4c04-907d-b1b41d6003c4","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.95009713Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
4272026-07-28T18:55:01.491Z{"msg":"Wait for a query_work_queue command to finish before sending IO","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.950169848Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4282026-07-28T18:55:01.491ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4292026-07-28T18:55:01.491ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4302026-07-28T18:55:01.491ZRead and Verify all blocks (0..50 range:true)
4312026-07-28T18:55:01.495Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.95400266Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4322026-07-28T18:55:01.495Z{"msg":"Verify test completed","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.954024686Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4332026-07-28T18:55:01.495Z{"msg":"Wrote out file \"/var/tmp/test_up-build/verify_file\"","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.954042023Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4342026-07-28T18:55:01.495Z{"msg":"CLIENT: Tests done. All submitted work has been ACK'd","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.954054821Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4352026-07-28T18:55:01.495Z----------------------------------------------------------------
4362026-07-28T18:55:01.495Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4372026-07-28T18:55:01.495ZStates: Active Active Active
4382026-07-28T18:55:01.495ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4392026-07-28T18:55:01.495Z 1000 Acked Read 50 Done Done Done false
4402026-07-28T18:55:01.496Z STATES DS:0 DS:1 DS:2 TOTAL
4412026-07-28T18:55:01.496Z Sent 0 0 0 0
4422026-07-28T18:55:01.496Z Done 1 1 1 3
4432026-07-28T18:55:01.496Z Skipped 0 0 0 0
4442026-07-28T18:55:01.496Z Error 0 0 0 0
4452026-07-28T18:55:01.496ZLast Flush: None None None
4462026-07-28T18:55:01.496ZDownstairs last five completed:
4472026-07-28T18:55:01.496ZUpstairs last five completed: 1000
4482026-07-28T18:55:01.496Z{"msg":"CLIENT: Up:0 ds:1 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:54:59.954155033Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4492026-07-28T18:55:05.502Z----------------------------------------------------------------
4502026-07-28T18:55:05.503Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4512026-07-28T18:55:05.503ZDownstairs last five completed: 1001 1000
4522026-07-28T18:55:05.503ZUpstairs last five completed: 1001 1000
4532026-07-28T18:55:05.510Z{"msg":"CLIENT: Up:0 ds:0 act:3","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:55:03.955018087Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4542026-07-28T18:55:05.511Z{"msg":"CLIENT: All crucible jobs finished, exiting program","v":0,"name":"crucible","level":30,"time":"2026-07-28T18:55:03.955044232Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184,"task":"crutest"}
4552026-07-28T18:55:05.511Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2026-07-28T18:55:03.955053521Z","hostname":"w-01KYN14MY168WSHBQTETDQGPEM","pid":1184}
4562026-07-28T18:55:05.511ZRepair part 2 passed
4572026-07-28T18:55:05.511Z/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
4582026-07-28T18:55:05.524ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4592026-07-28T18:55:05.525Z 0 000-009 32 32 32 1502 1502 1502 F F F
4602026-07-28T18:55:05.525Z 1 010-019 32 32 32 1502 1502 1502 F F F
4612026-07-28T18:55:05.525Z 2 020-029 32 32 32 1502 1502 1502 F F F
4622026-07-28T18:55:05.525Z 3 030-039 32 32 32 1502 1502 1502 F F F
4632026-07-28T18:55:05.525Z 4 040-049 32 32 32 1502 1502 1502 F F F
4642026-07-28T18:55:05.525ZMax gen: 32, Max flush: 1502
4652026-07-28T18:55:05.525Zdump test passed
4662026-07-28T18:55:05.526Z/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
4672026-07-28T18:55:05.535Z Extent 1
4682026-07-28T18:55:05.535ZGEN 32 32 32
4692026-07-28T18:55:05.535ZFLUSH_ID 1502 1502 1502
4702026-07-28T18:55:05.535ZDIRTY
4712026-07-28T18:55:05.535Z
4722026-07-28T18:55:05.535ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4732026-07-28T18:55:05.535Z010 A A A A A A
4742026-07-28T18:55:05.535Z011 A A A A A A
4752026-07-28T18:55:05.535Z012 A A A A A A
4762026-07-28T18:55:05.535Z013 A A A A A A
4772026-07-28T18:55:05.536Z014 A A A A A A
4782026-07-28T18:55:05.536Z015 A A A A A A
4792026-07-28T18:55:05.536Z016 A A A A A A
4802026-07-28T18:55:05.547Z017 A A A A A A
4812026-07-28T18:55:05.547Z018 A A A A A A
4822026-07-28T18:55:05.547Z019 A A A A A A
4832026-07-28T18:55:05.547Zdump extent test passed
4842026-07-28T18:55:05.547Z/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
4852026-07-28T18:55:05.553ZExtent 2 Block in extent 0 Actual block 20
4862026-07-28T18:55:05.554Z
4872026-07-28T18:55:05.554Z DATA SHA256 VER
4882026-07-28T18:55:05.554Z------ ---------------------------------------------------------------- ---
4892026-07-28T18:55:05.554Z 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
4902026-07-28T18:55:05.554Z 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
4912026-07-28T18:55:05.554Z 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
4922026-07-28T18:55:05.554Z
4932026-07-28T18:55:05.554ZNONCES 0 1 2 DIFF
4942026-07-28T18:55:05.555Z------ ------------------------ ------------------------ ------------------------ -----
4952026-07-28T18:55:05.555Z
4962026-07-28T18:55:05.555Z TAGS 0 1 2 DIFF
4972026-07-28T18:55:05.555Z------ -------------------------------- -------------------------------- -------------------------------- -----
4982026-07-28T18:55:05.555Z
4992026-07-28T18:55:05.555ZHASHES 0 1 2 DIFF
5002026-07-28T18:55:05.556Z------ ---------------- ---------------- ---------------- -----
5012026-07-28T18:55:05.556Z 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70
5022026-07-28T18:55:05.556Z
5032026-07-28T18:55:05.556Zdump block test passed
5042026-07-28T18:55:05.556ZInitial upstairs tests have completed, stopping all downstairs
5052026-07-28T18:55:10.570ZCreating 4 larger downstairs regions
5062026-07-28T18:55:10.687ZStarting 4 downstairs
5072026-07-28T18:55:15.692Zdsc restarted at PID: 1197
5082026-07-28T18:55:15.751ZNow do the replace-reconcile test
5092026-07-28T18:55:15.763ZUsing 8840 for the replacement port
5102026-07-28T18:58:46.651ZCompleted test: replace-reconcile
5112026-07-28T18:58:46.651ZNow do the replace-before-active test
5122026-07-28T19:01:34.720ZCompleted test: replace-before-active
5132026-07-28T19:01:34.720ZAll tests have completed, stopping all downstairs
5142026-07-28T19:01:34.737Z
5152026-07-28T19:01:34.737ZAll Tests have passed
5162026-07-28T19:01:34.741Z7:50 Test duration
5172026-07-28T19:01:34.741Z
5182026-07-28T19:01:34.741Zreal 7:49.359095702
5192026-07-28T19:01:34.741Zuser 40.566841595
5202026-07-28T19:01:34.741Zsys 5.050996345
5212026-07-28T19:01:34.741Ztrap 0.060800716
5222026-07-28T19:01:34.741Ztflt 0.025865521
5232026-07-28T19:01:34.741Zdflt 0.008495254
5242026-07-28T19:01:34.741Zkflt 0.002067240
5252026-07-28T19:01:34.741Zlock 4:06:51.682775597
5262026-07-28T19:01:34.741Zslp 20:38.836856012
5272026-07-28T19:01:34.741Zlat 3.835295992
5282026-07-28T19:01:34.742Zstop 0.011279404
5292026-07-28T19:01:34.742Z+ echo 'test-up-unencrypted ends'
5302026-07-28T19:01:34.742Ztest-up-unencrypted ends
5312026-07-28T19:01:39.740Zprocess exited: duration 478000 ms, exit code 0
5322026-07-28T19:01:39.740Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5332026-07-28T19:02:39.762Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5342026-07-28T19:02:39.762Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5352026-07-28T19:02:39.773Zfound 14 output files
5362026-07-28T19:02:39.773Zuploading: /tmp/test_up-build/dsc-out.txt (47165 bytes)
5372026-07-28T19:02:40.786Zuploaded: /tmp/test_up-build/dsc-out.txt
5382026-07-28T19:02:40.786Zuploading: /tmp/test_up-build/test_up_out.txt (21653846 bytes)
5392026-07-28T19:02:41.934Zuploaded: /tmp/test_up-build/test_up_out.txt
5402026-07-28T19:02:41.934Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2495 bytes)
5412026-07-28T19:02:42.943Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5422026-07-28T19:02:42.943Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (548329 bytes)
5432026-07-28T19:02:43.965Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5442026-07-28T19:02:43.966Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (978719 bytes)
5452026-07-28T19:02:44.992Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5462026-07-28T19:02:44.992Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (543047 bytes)
5472026-07-28T19:02:46.012Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5482026-07-28T19:02:46.012Zuploading: /tmp/debug/df.txt (1270 bytes)
5492026-07-28T19:02:47.020Zuploaded: /tmp/debug/df.txt
5502026-07-28T19:02:47.020Zuploading: /tmp/debug/dtrace.txt (489338 bytes)
5512026-07-28T19:02:47.034Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 489338 -> 587639
5522026-07-28T19:02:48.040Zuploaded: /tmp/debug/dtrace.txt
5532026-07-28T19:02:48.042Zuploading: /tmp/debug/iostat.txt (158907 bytes)
5542026-07-28T19:02:48.048Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 158907 -> 161283
5552026-07-28T19:02:49.056Zuploaded: /tmp/debug/iostat.txt
5562026-07-28T19:02:49.056Zuploading: /tmp/debug/mpstat.txt (388598 bytes)
5572026-07-28T19:02:49.067Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 388598 -> 395132
5582026-07-28T19:02:50.076Zuploaded: /tmp/debug/mpstat.txt
5592026-07-28T19:02:50.076Zuploading: /tmp/debug/paging.txt (68452 bytes)
5602026-07-28T19:02:50.083Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 68452 -> 69730
5612026-07-28T19:02:51.092Zuploaded: /tmp/debug/paging.txt
5622026-07-28T19:02:51.092Zuploading: /tmp/debug/prstat.txt (731014 bytes)
5632026-07-28T19:02:51.108Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 731014 -> 745264
5642026-07-28T19:02:52.116Zuploaded: /tmp/debug/prstat.txt
5652026-07-28T19:02:52.116Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
5662026-07-28T19:02:53.125Zuploaded: /tmp/debug/psrinfo.txt
5672026-07-28T19:02:53.125Zuploading: /tmp/debug/upstairs-info.txt (53550 bytes)
5682026-07-28T19:02:54.137Zuploaded: /tmp/debug/upstairs-info.txt