01JPK1XVJB4G3HWCM3FW8PX16X: 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: 01JPK1YQ61389ASWW467YKJT9N

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-03-17T22:14:50.082Zjob dependencies complete; ready to run (waiting for 14 m 21 s)
22025-03-17T22:15:46.603Zjob assigned to worker 01JPK2S5V2VR2R2FAMT5JK9PW7 [factory aws, i-0b17ba10de1b25282] (queued for 56 s)
32025-03-17T22:15:54.370Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-03-17T22:15:56.399Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-03-17T22:15:56.400Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-03-17T22:15:57.484Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-03-17T22:15:57.484Zdownloading input: /input/build/work/bins/crutest.gz
82025-03-17T22:15:58.654Zdownloaded input: /input/build/work/bins/crutest.gz
92025-03-17T22:15:58.654Zdownloading input: /input/build/work/bins/dsc.gz
102025-03-17T22:15:59.378Zdownloaded input: /input/build/work/bins/dsc.gz
112025-03-17T22:15:59.381Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-03-17T22:15:59.399Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-03-17T22:15:59.399Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-03-17T22:15:59.416Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-03-17T22:15:59.416Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-03-17T22:15:59.434Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-03-17T22:15:59.435Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-03-17T22:15:59.453Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-03-17T22:15:59.453Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-03-17T22:15:59.473Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-03-17T22:15:59.473Zdownloading input: /input/build/work/scripts/test_up.sh
222025-03-17T22:15:59.490Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-03-17T22:15:59.490Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-03-17T22:15:59.525Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-03-17T22:15:59.529Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-03-17T22:16:00.224Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-03-17T22:16:00.224Zstarting task 0: "setup"
282025-03-17T22:16:00.231Z++ uname -s
292025-03-17T22:16:00.234Z+ kern=SunOS
302025-03-17T22:16:00.235Z+ build_user=build
312025-03-17T22:16:00.235Z+ build_uid=12345
322025-03-17T22:16:00.235Z+ work_dir=/work
332025-03-17T22:16:00.235Z+ input_dir=/input
342025-03-17T22:16:00.235Z+ [[ 0 == 12345 ]]
352025-03-17T22:16:00.235Z+ case "$kern" in
362025-03-17T22:16:00.235Z+ groupadd -g 12345 build
372025-03-17T22:16:00.240Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
382025-03-17T22:16:02.244Z+ zfs create -o mountpoint=/work rpool/work
392025-03-17T22:16:02.550Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
402025-03-17T22:16:02.553Z+ home_fs=zfs
412025-03-17T22:16:02.553Z+ [[ zfs == autofs ]]
422025-03-17T22:16:02.553Z+ mkdir -p /home/build
432025-03-17T22:16:02.556Z+ chown build:build /home/build /work
442025-03-17T22:16:03.556Z+ chmod 0700 /home/build /work
452025-03-17T22:16:03.564Zprocess exited: duration 3334 ms, exit code 0
 
462025-03-17T22:16:03.571Zstarting task 1: "authentication"
472025-03-17T22:16:03.591Zprocess exited: duration 17 ms, exit code 0
 
482025-03-17T22:16:03.600Zstarting task 2: "build"
492025-03-17T22:16:03.606Z+ banner cores
502025-03-17T22:16:03.618Z
512025-03-17T22:16:03.618Z #### #### ##### ###### ####
522025-03-17T22:16:03.618Z # # # # # # # #
532025-03-17T22:16:03.618Z # # # # # ##### ####
542025-03-17T22:16:03.618Z # # # ##### # #
552025-03-17T22:16:03.618Z # # # # # # # # #
562025-03-17T22:16:03.618Z #### #### # # ###### ####
572025-03-17T22:16:03.618Z
582025-03-17T22:16:03.624Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
592025-03-17T22:16:03.628Z+ echo 'input bins dir contains:'
602025-03-17T22:16:03.628Zinput bins dir contains:
612025-03-17T22:16:03.628Z+ ls -ltr /input/build/work/bins
622025-03-17T22:16:03.632Ztotal 793815
632025-03-17T22:16:03.632Z-rw-r--r-- 1 root root 118363763 Mar 17 22:15 crucible-downstairs.gz
642025-03-17T22:16:03.632Z-rw-r--r-- 1 root root 106111342 Mar 17 22:15 crucible-hammer.gz
652025-03-17T22:16:03.632Z-rw-r--r-- 1 root root 115364466 Mar 17 22:15 crutest.gz
662025-03-17T22:16:03.632Z-rw-r--r-- 1 root root 66333615 Mar 17 22:15 dsc.gz
672025-03-17T22:16:03.632Z+ banner unpack
682025-03-17T22:16:03.632Z
692025-03-17T22:16:03.632Z # # # # ##### ## #### # #
702025-03-17T22:16:03.632Z # # ## # # # # # # # # #
712025-03-17T22:16:03.632Z # # # # # # # # # # ####
722025-03-17T22:16:03.632Z # # # # # ##### ###### # # #
732025-03-17T22:16:03.632Z # # # ## # # # # # # #
742025-03-17T22:16:03.632Z #### # # # # # #### # #
752025-03-17T22:16:03.632Z
762025-03-17T22:16:03.632Z+ mkdir -p /var/tmp/bins
772025-03-17T22:16:03.636Z+ for t in "$input/bins/"*.gz
782025-03-17T22:16:03.636Z++ basename /input/build/work/bins/crucible-downstairs.gz
792025-03-17T22:16:03.636Z+ b=crucible-downstairs.gz
802025-03-17T22:16:03.636Z+ b=crucible-downstairs
812025-03-17T22:16:03.636Z+ gunzip
822025-03-17T22:16:06.057Z+ chmod +x /var/tmp/bins/crucible-downstairs
832025-03-17T22:16:06.061Z+ for t in "$input/bins/"*.gz
842025-03-17T22:16:06.061Z++ basename /input/build/work/bins/crucible-hammer.gz
852025-03-17T22:16:06.064Z+ b=crucible-hammer.gz
862025-03-17T22:16:06.064Z+ b=crucible-hammer
872025-03-17T22:16:06.064Z+ gunzip
882025-03-17T22:16:08.282Z+ chmod +x /var/tmp/bins/crucible-hammer
892025-03-17T22:16:08.285Z+ for t in "$input/bins/"*.gz
902025-03-17T22:16:08.288Z++ basename /input/build/work/bins/crutest.gz
912025-03-17T22:16:08.288Z+ b=crutest.gz
922025-03-17T22:16:08.288Z+ b=crutest
932025-03-17T22:16:08.288Z+ gunzip
942025-03-17T22:16:10.644Z+ chmod +x /var/tmp/bins/crutest
952025-03-17T22:16:10.647Z+ for t in "$input/bins/"*.gz
962025-03-17T22:16:10.647Z++ basename /input/build/work/bins/dsc.gz
972025-03-17T22:16:10.650Z+ b=dsc.gz
982025-03-17T22:16:10.651Z+ b=dsc
992025-03-17T22:16:10.651Z+ gunzip
1002025-03-17T22:16:12.061Z+ chmod +x /var/tmp/bins/dsc
1012025-03-17T22:16:12.065Z+ export BINDIR=/var/tmp/bins
1022025-03-17T22:16:12.065Z+ BINDIR=/var/tmp/bins
1032025-03-17T22:16:12.065Z+ export RUST_BACKTRACE=1
1042025-03-17T22:16:12.065Z+ RUST_BACKTRACE=1
1052025-03-17T22:16:12.065Z+ jobpid=1145
1062025-03-17T22:16:12.065Z+ echo 'Setup debug logging'
1072025-03-17T22:16:12.065Z+ mkdir /tmp/debug
1082025-03-17T22:16:12.065ZSetup debug logging
1092025-03-17T22:16:12.065Z+ sleep 7200
1102025-03-17T22:16:12.068Z+ psrinfo -v
1112025-03-17T22:16:12.071Z+ df -h
1122025-03-17T22:16:12.077Z+ prstat -d d -mLc 1
1132025-03-17T22:16:12.081Z+ iostat -T d -xn 1
1142025-03-17T22:16:12.081Z+ mpstat -T d 1
1152025-03-17T22:16:12.081Z+ vmstat -T d -p 1
1162025-03-17T22:16:12.081Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1172025-03-17T22:16:12.084Z+ banner test_up_unencrypted
1182025-03-17T22:16:12.084Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1192025-03-17T22:16:12.084Z
1202025-03-17T22:16:12.084Z ##### ###### #### ##### # # ##### # # # #
1212025-03-17T22:16:12.084Z # # # # # # # # # # ## #
1222025-03-17T22:16:12.084Z # ##### #### # # # # # # # # # #
1232025-03-17T22:16:12.084Z # # # # # # ##### # # # # #
1242025-03-17T22:16:12.084Z # # # # # # # # # # # ##
1252025-03-17T22:16:12.084Z # ###### #### # ####### #### # ####### #### # #
1262025-03-17T22:16:12.084Z
1272025-03-17T22:16:12.084Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N unencrypted
1282025-03-17T22:16:12.095Z/input/build/work
1292025-03-17T22:16:12.119ZTurn off color for downstairs dump
1302025-03-17T22:16:12.122Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1312025-03-17T22:16:12.122ZCreating 3 downstairs regions
1322025-03-17T22:16:12.422ZStarting 3 downstairs
1332025-03-17T22:16:12.426Zdsc started at PID: 1190
1342025-03-17T22:16:17.605ZDisable automatic restart on all downstairs
1352025-03-17T22:16:17.659Z
1362025-03-17T22:16:17.659ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1372025-03-17T22:16:17.663ZRunning test: span
1382025-03-17T22:16:21.765ZCompleted test: span
1392025-03-17T22:16:26.773ZRunning test: big
1402025-03-17T22:16:30.918ZCompleted test: big
1412025-03-17T22:16:35.926ZRunning test: dep
1422025-03-17T22:16:48.859ZCompleted test: dep
1432025-03-17T22:16:53.865ZRunning test: balloon
1442025-03-17T22:17:03.543ZCompleted test: balloon
1452025-03-17T22:17:08.543ZRunning test: deactivate
1462025-03-17T22:18:02.753ZCompleted test: deactivate
1472025-03-17T22:18:07.761ZRunning hammer
1482025-03-17T22:18:10.770ZRun repair tests
1492025-03-17T22:18:10.774Z/var/tmp/bins/crutest fill -g 31 -q --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1502025-03-17T22:18:10.831Z{"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":"2025-03-17T22:18:09.432215196Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"task":"crutest"}
1512025-03-17T22:18:10.834Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.432848591Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"task":"crutest"}
1522025-03-17T22:18:10.834Z{"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":"2025-03-17T22:18:09.434651782Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"task":"crutest"}
1532025-03-17T22:18:10.834Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43484255Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
1542025-03-17T22:18:10.834Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f72bfdb36aa576722b377a737f26a9b5ef54faf2\",\n git_commit_timestamp: \"2025-03-17T21:58:36.000000000Z\",\n git_branch: \"renovate/tempfile-3.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.434891142Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
1552025-03-17T22:18:10.835Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.434914798Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
1562025-03-17T22:18:10.835Z{"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":"2025-03-17T22:18:09.434930936Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
1572025-03-17T22:18:10.835Z{"msg":"Crucible 63ae8978-1f7c-4b30-bdee-e573b5f675bd has session id: 69f1d18a-7ad6-4ef7-be3e-18463e180f73","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.435511059Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1582025-03-17T22:18:10.835Z{"msg":"Upstairs opts: Upstairs UUID: 63ae8978-1f7c-4b30-bdee-e573b5f675bd, 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":"2025-03-17T22:18:09.43556673Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1592025-03-17T22:18:10.835Z{"msg":"Crucible stats registered with UUID: 63ae8978-1f7c-4b30-bdee-e573b5f675bd","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.435592806Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1602025-03-17T22:18:10.835Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:09.435621301Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1612025-03-17T22:18:10.839Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436523831Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"task":"crutest"}
1622025-03-17T22:18:10.840Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436614576Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
1632025-03-17T22:18:10.840Z{"msg":"63ae8978-1f7c-4b30-bdee-e573b5f675bd active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43664864Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1642025-03-17T22:18:10.840Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436671957Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1652025-03-17T22:18:10.840Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436727787Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1662025-03-17T22:18:10.840Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436755983Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1672025-03-17T22:18:10.840Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436800395Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1682025-03-17T22:18:10.840Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436851147Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1692025-03-17T22:18:10.840Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436879622Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1702025-03-17T22:18:10.840Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436916276Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1712025-03-17T22:18:10.840Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436941702Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1722025-03-17T22:18:10.840Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.436982225Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1732025-03-17T22:18:10.840Z{"msg":"ds_connection connected from Ok(127.0.0.1:57753)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.437021119Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1742025-03-17T22:18:10.840Z{"msg":"ds_connection connected from Ok(127.0.0.1:49752)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43707245Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1752025-03-17T22:18:10.840Z{"msg":"ds_connection connected from Ok(127.0.0.1:50843)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.437097766Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"io task","client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1762025-03-17T22:18:10.840Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.437563609Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1772025-03-17T22:18:10.840Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.437599703Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1782025-03-17T22:18:10.840Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.437619779Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1792025-03-17T22:18:10.840Z{"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":"2025-03-17T22:18:09.438214361Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1802025-03-17T22:18:10.840Z{"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":"2025-03-17T22:18:09.438252665Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1812025-03-17T22:18:10.840Z{"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":"2025-03-17T22:18:09.438316304Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1822025-03-17T22:18:10.840Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438659257Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1832025-03-17T22:18:10.840Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43870417Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1842025-03-17T22:18:10.840Z{"msg":"[0]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438728666Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1852025-03-17T22:18:10.840Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43876448Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1862025-03-17T22:18:10.840Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438800114Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1872025-03-17T22:18:10.840Z{"msg":"[1]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438836338Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1882025-03-17T22:18:10.840Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438872572Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1892025-03-17T22:18:10.840Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438900197Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1902025-03-17T22:18:10.840Z{"msg":"[2]R flush_numbers: [1503, 1503, 1503, 1503, 1503]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438935941Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1912025-03-17T22:18:10.840Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.438972975Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1922025-03-17T22:18:10.840ZWait for a query_work_queue command to finish before sending IO
1932025-03-17T22:18:10.840Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439018278Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1942025-03-17T22:18:10.840Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439054781Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1952025-03-17T22:18:10.840Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439080937Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1962025-03-17T22:18:10.840Z{"msg":"Next flush: 1504","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439115961Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1972025-03-17T22:18:10.841Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439152755Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"":"downstairs","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1982025-03-17T22:18:10.841Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439179851Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
1992025-03-17T22:18:10.841Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439212685Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"0","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2002025-03-17T22:18:10.841ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2012025-03-17T22:18:10.841Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439253979Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"1","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2022025-03-17T22:18:10.841Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"Fill test
2032025-03-17T22:18:10.841Z2025-03-17T22:18:09.439274715Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"client":"2","":"downstairs","session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2042025-03-17T22:18:10.841Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439290342Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2052025-03-17T22:18:10.841Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439310909Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2062025-03-17T22:18:10.841Z{"msg":"63ae8978-1f7c-4b30-bdee-e573b5f675bd is now active with session: 69f1d18a-7ad6-4ef7-be3e-18463e180f73","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439324297Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2072025-03-17T22:18:10.841Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439336285Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227,"session_id":"69f1d18a-7ad6-4ef7-be3e-18463e180f73"}
2082025-03-17T22:18:10.841Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.439356382Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
2092025-03-17T22:18:10.841Z{"msg":"Activated sub_volume 63ae8978-1f7c-4b30-bdee-e573b5f675bd","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:09.43936822Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
2102025-03-17T22:18:10.845ZRead and Verify all blocks (0..50 range:false)
2112025-03-17T22:18:10.850ZWrote out file "/var/tmp/test_up-build/verify_file"
2122025-03-17T22:18:10.850ZCLIENT: Tests done. All submitted work has been ACK'd
2132025-03-17T22:18:10.853Z----------------------------------------------------------------
2142025-03-17T22:18:10.853Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2152025-03-17T22:18:10.853ZStates: Active Active Active
2162025-03-17T22:18:10.853ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2172025-03-17T22:18:10.853Z 1002 Acked Read 50 Done Done Done false
2182025-03-17T22:18:10.853Z STATES DS:0 DS:1 DS:2 TOTAL
2192025-03-17T22:18:10.854Z Sent 0 0 0 0
2202025-03-17T22:18:10.854Z Done 1 1 1 3
2212025-03-17T22:18:10.854Z Skipped 0 0 0 0
2222025-03-17T22:18:10.854Z Error 0 0 0 0
2232025-03-17T22:18:10.854ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
2242025-03-17T22:18:10.854ZDownstairs last five completed: 1001 1000
2252025-03-17T22:18:10.854ZUpstairs last five completed: 1002 1001 1000
2262025-03-17T22:18:10.854ZCLIENT: Up:0 ds:1 act:3
2272025-03-17T22:18:14.852Z----------------------------------------------------------------
2282025-03-17T22:18:14.852Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2292025-03-17T22:18:14.852ZDownstairs last five completed: 1003 1002 1001 1000
2302025-03-17T22:18:14.852ZUpstairs last five completed: 1003 1002 1001 1000
2312025-03-17T22:18:14.852ZCLIENT: Up:0 ds:0 act:3
2322025-03-17T22:18:14.852ZCLIENT: All crucible jobs finished, exiting program
2332025-03-17T22:18:14.856Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:13.452514777Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1227}
2342025-03-17T22:18:14.863ZRepair setup passed
2352025-03-17T22:18:14.867ZCopy the region for /var/tmp/test_up-build/8830
2362025-03-17T22:18:14.871Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2372025-03-17T22:18:14.875Z/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
2382025-03-17T22:18:14.933Z{"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":"2025-03-17T22:18:13.532515168Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"task":"crutest"}
2392025-03-17T22:18:14.937Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.533076155Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"task":"crutest"}
2402025-03-17T22:18:14.937Z{"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":"2025-03-17T22:18:13.534837023Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"task":"crutest"}
2412025-03-17T22:18:14.937Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.53509344Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2422025-03-17T22:18:14.937Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f72bfdb36aa576722b377a737f26a9b5ef54faf2\",\n git_commit_timestamp: \"2025-03-17T21:58:36.000000000Z\",\n git_branch: \"renovate/tempfile-3.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.535176126Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2432025-03-17T22:18:14.937Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.535222519Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2442025-03-17T22:18:14.937Z{"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":"2025-03-17T22:18:13.535259513Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2452025-03-17T22:18:14.937Z{"msg":"Crucible 5290521b-764b-4f0b-8abd-e9358c47d40f has session id: e1d3dbd8-0412-47fa-8386-12661af16b34","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.535859853Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2462025-03-17T22:18:14.937Z{"msg":"Upstairs opts: Upstairs UUID: 5290521b-764b-4f0b-8abd-e9358c47d40f, 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":"2025-03-17T22:18:13.535900046Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2472025-03-17T22:18:14.937Z{"msg":"Crucible stats registered with UUID: 5290521b-764b-4f0b-8abd-e9358c47d40f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.535916414Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2482025-03-17T22:18:14.937Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:13.535932811Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2492025-03-17T22:18:14.944Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537289116Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"task":"crutest"}
2502025-03-17T22:18:14.944Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537320341Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2512025-03-17T22:18:14.944Z{"msg":"5290521b-764b-4f0b-8abd-e9358c47d40f active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537380911Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2522025-03-17T22:18:14.944Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537413726Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2532025-03-17T22:18:14.944Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537453279Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2542025-03-17T22:18:14.944Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537489633Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2552025-03-17T22:18:14.944Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537520258Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2562025-03-17T22:18:14.944Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.53756363Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2572025-03-17T22:18:14.944Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537601484Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2582025-03-17T22:18:14.944Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537641968Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2592025-03-17T22:18:14.944Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537668503Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2602025-03-17T22:18:14.944Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537715695Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2612025-03-17T22:18:14.944Z{"msg":"ds_connection connected from Ok(127.0.0.1:36720)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537750259Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2622025-03-17T22:18:14.944Z{"msg":"ds_connection connected from Ok(127.0.0.1:37026)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537862621Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2632025-03-17T22:18:14.944Z{"msg":"ds_connection connected from Ok(127.0.0.1:51201)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.537902434Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"io task","client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2642025-03-17T22:18:14.944Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.538699842Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2652025-03-17T22:18:14.944Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.538741635Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2662025-03-17T22:18:14.944Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.53883443Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2672025-03-17T22:18:14.944Z{"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":"2025-03-17T22:18:13.539438419Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2682025-03-17T22:18:14.944Z{"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":"2025-03-17T22:18:13.539491431Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2692025-03-17T22:18:14.944Z{"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":"2025-03-17T22:18:13.539537713Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2702025-03-17T22:18:14.944Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.539884026Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2712025-03-17T22:18:14.945Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.539992918Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2722025-03-17T22:18:14.945Z{"msg":"[0]R flush_numbers: [1504, 1504, 1504, 1504, 1504]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.54003767Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2732025-03-17T22:18:14.945Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540062556Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2742025-03-17T22:18:14.945Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540077564Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2752025-03-17T22:18:14.945Z{"msg":"[1]R flush_numbers: [1504, 1504, 1504, 1504, 1504]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.54009814Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2762025-03-17T22:18:14.945Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540111448Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2772025-03-17T22:18:14.945Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540124566Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2782025-03-17T22:18:14.945Z{"msg":"[2]R flush_numbers: [1504, 1504, 1504, 1504, 1504]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540151221Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2792025-03-17T22:18:14.945Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540174717Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2802025-03-17T22:18:14.945Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540206322Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2812025-03-17T22:18:14.945Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540229958Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2822025-03-17T22:18:14.945Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540257934Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2832025-03-17T22:18:14.946Z{"msg":"Next flush: 1505","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.54027976Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","Wait for a query_work_queue command to finish before sending IO
2842025-03-17T22:18:14.946Z":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2852025-03-17T22:18:14.946Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540320463Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"":"downstairs","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2862025-03-17T22:18:14.946Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540343089Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2872025-03-17T22:18:14.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540368795Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"0","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2882025-03-17T22:18:14.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540391732Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"1","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2892025-03-17T22:18:14.946Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540418567Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"client":"2","":"downstairs","session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2902025-03-17T22:18:14.946Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540440883Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2912025-03-17T22:18:14.946Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540467959Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2922025-03-17T22:18:14.946Z{"msg":"5290521b-764b-4f0b-8abd-e9358c47d40f is now active with session: e1d3dbd8-0412-47fa-8386-12661af16b34","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540489975Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2932025-03-17T22:18:14.946Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540516781Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233,"session_id":"e1d3dbd8-0412-47fa-8386-12661af16b34"}
2942025-03-17T22:18:14.946Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540538127Z","Disk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2952025-03-17T22:18:14.946Zhostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2962025-03-17T22:18:14.946Z{"msg":"Activated sub_volume 5290521b-764b-4f0b-8abd-e9358c47d40f","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:13.540569352Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1233}
2972025-03-17T22:18:14.946ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2982025-03-17T22:18:14.946ZFill test
2992025-03-17T22:18:14.952ZRead and Verify all blocks (0..50 range:false)
3002025-03-17T22:18:14.956ZWrote out file "/var/tmp/test_up-build/verify_file"
3012025-03-17T22:18:14.956ZCLIENT: Tests done. All submitted work has been ACK'd
3022025-03-17T22:18:14.956Z----------------------------------------------------------------
3032025-03-17T22:18:14.956Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
3042025-03-17T22:18:14.956ZStates: Active Active Active
3052025-03-17T22:18:14.956ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3062025-03-17T22:18:14.956Z 1002 Acked Read 50 Done Done Done false
3072025-03-17T22:18:14.956Z STATES DS:0 DS:1 DS:2 TOTAL
3082025-03-17T22:18:14.956Z Sent 0 0 0 0
3092025-03-17T22:18:14.956Z Done 1 1 1 3
3102025-03-17T22:18:14.957Z Skipped 0 0 0 0
3112025-03-17T22:18:14.957Z Error 0 0 0 0
3122025-03-17T22:18:14.957ZLast Flush: Some(JobId(1001)) Some(JobId(1001)) Some(JobId(1001))
3132025-03-17T22:18:14.957ZDownstairs last five completed: 1001 1000
3142025-03-17T22:18:14.957ZUpstairs last five completed: 1002 1001 1000
3152025-03-17T22:18:14.957ZCLIENT: Up:0 ds:1 act:3
3162025-03-17T22:18:18.955Z----------------------------------------------------------------
3172025-03-17T22:18:18.955Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3182025-03-17T22:18:18.955ZDownstairs last five completed: 1003 1002 1001 1000
3192025-03-17T22:18:18.955ZUpstairs last five completed: 1003 1002 1001 1000
3202025-03-17T22:18:18.955ZCLIENT: Up:0 ds:0 act:3
3212025-03-17T22:18:18.955ZCLIENT: All crucible jobs finished, exiting program
3222025-03-17T22:18:18.960ZRepair part 1 passed
3232025-03-17T22:18:18.964Z
3242025-03-17T22:18:18.964ZKill the current downstairs
3252025-03-17T22:18:19.131ZDownstairs 2 stopped
3262025-03-17T22:18:19.131Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3272025-03-17T22:18:19.134ZNow put back the original so we have a mismatch
3282025-03-17T22:18:19.134Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3292025-03-17T22:18:19.137ZRestart downstairs with old directory
3302025-03-17T22:18:19.189Z/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
3312025-03-17T22:18:19.206ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3322025-03-17T22:18:19.209Z 0 000-009 32 32 31 1505 1505 1504 F F F <---
3332025-03-17T22:18:19.209Z 1 010-019 32 32 31 1505 1505 1504 F F F <---
3342025-03-17T22:18:19.209Z 2 020-029 32 32 31 1505 1505 1504 F F F <---
3352025-03-17T22:18:19.209Z 3 030-039 32 32 31 1505 1505 1504 F F F <---
3362025-03-17T22:18:19.209Z 4 040-049 32 32 31 1505 1505 1504 F F F <---
3372025-03-17T22:18:19.209ZMax gen: 32, Max flush: 1505
3382025-03-17T22:18:19.426ZError: Difference in extent metadata found!
3392025-03-17T22:18:19.426Z
3402025-03-17T22:18:19.426ZStack backtrace:
3412025-03-17T22:18:19.426Z 0: anyhow::error::<impl anyhow::Error>::msg
3422025-03-17T22:18:19.426Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.96/src/backtrace.rs:27:14
3432025-03-17T22:18:19.426Z 1: anyhow::__private::format_err
3442025-03-17T22:18:19.426Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.96/src/lib.rs:691:13
3452025-03-17T22:18:19.445Zdump test found error as expected
3462025-03-17T22:18:19.445Z
3472025-03-17T22:18:19.445Z
3482025-03-17T22:18:19.449Z/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
3492025-03-17T22:18:19.502Z{"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":"2025-03-17T22:18:18.101683312Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"task":"crutest"}
3502025-03-17T22:18:19.505Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.102188768Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"task":"crutest"}
3512025-03-17T22:18:19.505Z{"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":"2025-03-17T22:18:18.103858771Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"task":"crutest"}
3522025-03-17T22:18:19.505Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.104084934Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
3532025-03-17T22:18:19.505Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"f72bfdb36aa576722b377a737f26a9b5ef54faf2\",\n git_commit_timestamp: \"2025-03-17T21:58:36.000000000Z\",\n git_branch: \"renovate/tempfile-3.x-lockfile\",\n rustc_semver: \"1.84.0\",\n rustc_channel: \"stable\",\n rustc_host_triple: \"x86_64-unknown-illumos\",\n rustc_commit_sha: \"9fc6b43126469e3858e2fe86cafb4f0fd5068869\",\n cargo_triple: \"x86_64-unknown-illumos\",\n debug: true,\n opt_level: 0,\n}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.104132546Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
3542025-03-17T22:18:19.506Z{"msg":"Upstairs <-> Downstairs Message Version: 13","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.104155392Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
3552025-03-17T22:18:19.506Z{"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":"2025-03-17T22:18:18.10417045Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
3562025-03-17T22:18:19.506Z{"msg":"Crucible 1d416101-b3b9-4469-92e3-43b6c7215d23 has session id: 2724c282-f85b-4d99-92b9-acd0a5a3be3d","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.104644531Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3572025-03-17T22:18:19.506Z{"msg":"Upstairs opts: Upstairs UUID: 1d416101-b3b9-4469-92e3-43b6c7215d23, 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":"2025-03-17T22:18:18.104691233Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3582025-03-17T22:18:19.506Z{"msg":"Crucible stats registered with UUID: 1d416101-b3b9-4469-92e3-43b6c7215d23","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.104717109Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3592025-03-17T22:18:19.506Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:18.104745224Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3602025-03-17T22:18:19.511Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105712794Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"task":"crutest"}
3612025-03-17T22:18:19.511Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105767605Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
3622025-03-17T22:18:19.511Z{"msg":"1d416101-b3b9-4469-92e3-43b6c7215d23 active request set","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105832754Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3632025-03-17T22:18:19.511Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105889674Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3642025-03-17T22:18:19.511Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105952054Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3652025-03-17T22:18:19.511Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.105986329Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3662025-03-17T22:18:19.511Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106010394Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3672025-03-17T22:18:19.511Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106032801Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3682025-03-17T22:18:19.511Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106067715Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3692025-03-17T22:18:19.511Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106093501Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3702025-03-17T22:18:19.511Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106126465Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3712025-03-17T22:18:19.511Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106152611Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3722025-03-17T22:18:19.511Z{"msg":"ds_connection connected from Ok(127.0.0.1:58039)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106191384Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3732025-03-17T22:18:19.511Z{"msg":"ds_connection connected from Ok(127.0.0.1:57889)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.10622071Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3742025-03-17T22:18:19.511Z{"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":"2025-03-17T22:18:18.106252514Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3752025-03-17T22:18:19.511Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:18.10628117Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3762025-03-17T22:18:19.511Z{"msg":"downstairs task for 2 stopped due to ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" })","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:18.106308215Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3772025-03-17T22:18:19.511Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106454261Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3782025-03-17T22:18:19.511Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.10688373Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3792025-03-17T22:18:19.511Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.106923363Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3802025-03-17T22:18:19.511Z{"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":"2025-03-17T22:18:18.107415981Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3812025-03-17T22:18:19.511Z{"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":"2025-03-17T22:18:18.107525603Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3822025-03-17T22:18:19.512Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.107765203Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3832025-03-17T22:18:19.512Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:18.10784437Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3842025-03-17T22:18:29.510Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.107041714Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3852025-03-17T22:18:29.510Z{"msg":"ds_connection connected from Ok(127.0.0.1:52190)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.10712721Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"io task","client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3862025-03-17T22:18:29.516Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.108190923Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3872025-03-17T22:18:29.516Z{"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":"2025-03-17T22:18:28.108819859Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3882025-03-17T22:18:29.516Z{"msg":"[0]R flush_numbers: [1505, 1505, 1505, 1505, 1505]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109256617Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3892025-03-17T22:18:29.516Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109289781Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3902025-03-17T22:18:29.516Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109305528Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3912025-03-17T22:18:29.516Z{"msg":"[1]R flush_numbers: [1505, 1505, 1505, 1505, 1505]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109320716Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3922025-03-17T22:18:29.516Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109343042Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3932025-03-17T22:18:29.516Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.10935754Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3942025-03-17T22:18:29.516Z{"msg":"[2]R flush_numbers: [1504, 1504, 1504, 1504, 1504]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109378106Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3952025-03-17T22:18:29.516Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109391664Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3962025-03-17T22:18:29.516Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109412251Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3972025-03-17T22:18:29.516Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109425338Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3982025-03-17T22:18:29.516Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109446045Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
3992025-03-17T22:18:29.516Z{"msg":"Next flush: 1506","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109459513Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4002025-03-17T22:18:29.516Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 31, flush: 1504, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109481989Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4012025-03-17T22:18:29.516Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 31, flush: 1504, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109499656Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4022025-03-17T22:18:29.516Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109521233Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4032025-03-17T22:18:29.516Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 31, flush: 1504, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.1095369Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4042025-03-17T22:18:29.517Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 31, flush: 1504, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109554007Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4052025-03-17T22:18:29.517Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109568095Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4062025-03-17T22:18:29.517Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 31, flush: 1504, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.1095977Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4072025-03-17T22:18:29.517Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 31, flush: 1504, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109616567Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4082025-03-17T22:18:29.517Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109630484Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4092025-03-17T22:18:29.517Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 31, flush: 1504, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109645542Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4102025-03-17T22:18:29.517Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 31, flush: 1504, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109670268Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4112025-03-17T22:18:29.517Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109684786Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4122025-03-17T22:18:29.517Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 32, flush: 1505, dirty: false } ExtentMetadata { gen: 31, flush: 1504, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109700583Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4132025-03-17T22:18:29.517Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 32, flush: 1505, dirty: false }, ExtentMetadata { gen: 31, flush: 1504, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.10971598Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4142025-03-17T22:18:29.517Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109737707Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"mend","":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4152025-03-17T22:18:29.517Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109761563Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4162025-03-17T22:18:29.517Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109785149Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4172025-03-17T22:18:29.517Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109799216Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4182025-03-17T22:18:29.517Z{"msg":"Full repair list: {ExtentId(0): 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(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(4): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109833061Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4192025-03-17T22:18:29.517Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(0), client_id: ClientId(0), flush_number: 1506, 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: 1506, 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(2), client_id: ClientId(0), flush_number: 1506, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(9), op: ExtentClose { repair_id: ReconciliationId(9), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(10), op: ExtentRepair { repair_id: ReconciliationId(10), 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(11), op: ExtentReopen { repair_id: ReconciliationId(11), extent_id: ExtentId(2) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(12), op: ExtentFlush { repair_id: ReconciliationId(12), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1506, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1506, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.109979946Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4202025-03-17T22:18:29.517Z{"msg":"starting reconciliation 9155ae80-b2f3-491e-992b-7f44fcfbcac1: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.110022779Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4212025-03-17T22:18:29.518Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.110151748Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4222025-03-17T22:18:29.523Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.120124264Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4232025-03-17T22:18:29.526Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.123657378Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4242025-03-17T22:18:29.530Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.127314741Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4252025-03-17T22:18:29.533Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.130908825Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4262025-03-17T22:18:29.536Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.13389365Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"":"downstairs","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4272025-03-17T22:18:29.536Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.133929044Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"0","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4282025-03-17T22:18:29.536Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.133945471Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"1","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4292025-03-17T22:18:29.536Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.133959339Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"client":"2","":"downstairs","session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4302025-03-17T22:18:29.536Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.133972697Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4312025-03-17T22:18:29.537Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.133992364Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4322025-03-17T22:18:29.537Z{"msg":"1d416101-b3b9-4469-92e3-43b6c7215d23 is now active with session: 2724c282-f85b-4d99-92b9-acd0a5a3be3d","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.134005712Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241,"session_id":"2724c282-f85b-4d99-92b9-acd0a5a3be3d"}
4332025-03-17T22:18:29.537Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.134018679Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
4342025-03-17T22:18:29.537Z{"msg":"Activated sub_volume 1d416101-b3b9-4469-92e3-43b6c7215d23","v":0,"name":"crucible","level":30,"time":"2025-03-17T22:18:28.134092147Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
4352025-03-17T22:18:29.537ZWait for a query_work_queue command to finish before sending IO
4362025-03-17T22:18:29.552ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4372025-03-17T22:18:29.552ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4382025-03-17T22:18:29.552ZRead and Verify all blocks (0..50 range:true)
4392025-03-17T22:18:29.559ZWrote out file "/var/tmp/test_up-build/verify_file"
4402025-03-17T22:18:29.560ZVerify test completed
4412025-03-17T22:18:29.560ZWrote out file "/var/tmp/test_up-build/verify_file"
4422025-03-17T22:18:29.560ZCLIENT: Tests done. All submitted work has been ACK'd
4432025-03-17T22:18:29.560Z----------------------------------------------------------------
4442025-03-17T22:18:29.560Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4452025-03-17T22:18:29.560ZStates: Active Active Active
4462025-03-17T22:18:29.560ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4472025-03-17T22:18:29.560Z 1000 Acked Read 50 Done Done Done false
4482025-03-17T22:18:29.560Z STATES DS:0 DS:1 DS:2 TOTAL
4492025-03-17T22:18:29.560Z Sent 0 0 0 0
4502025-03-17T22:18:29.560Z Done 1 1 1 3
4512025-03-17T22:18:29.560Z Skipped 0 0 0 0
4522025-03-17T22:18:29.560Z Error 0 0 0 0
4532025-03-17T22:18:29.560ZLast Flush: None None None
4542025-03-17T22:18:29.560ZDownstairs last five completed:
4552025-03-17T22:18:29.560ZUpstairs last five completed: 1000
4562025-03-17T22:18:29.560ZCLIENT: Up:0 ds:1 act:3
4572025-03-17T22:18:33.558Z----------------------------------------------------------------
4582025-03-17T22:18:33.558Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4592025-03-17T22:18:33.558ZDownstairs last five completed: 1001 1000
4602025-03-17T22:18:33.558ZUpstairs last five completed: 1001 1000
4612025-03-17T22:18:33.558ZCLIENT: Up:0 ds:0 act:3
4622025-03-17T22:18:33.558ZCLIENT: All crucible jobs finished, exiting program
4632025-03-17T22:18:33.569Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-03-17T22:18:32.143724738Z","hostname":"w-01JPK2S5V2VR2R2FAMT5JK9PW7","pid":1241}
4642025-03-17T22:18:33.569ZRepair part 2 passed
4652025-03-17T22:18:33.569Z/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
4662025-03-17T22:18:33.596ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4672025-03-17T22:18:33.596Z 0 000-009 32 32 32 1505 1505 1505 F F F
4682025-03-17T22:18:33.596Z 1 010-019 32 32 32 1505 1505 1505 F F F
4692025-03-17T22:18:33.596Z 2 020-029 32 32 32 1505 1505 1505 F F F
4702025-03-17T22:18:33.596Z 3 030-039 32 32 32 1505 1505 1505 F F F
4712025-03-17T22:18:33.596Z 4 040-049 32 32 32 1505 1505 1505 F F F
4722025-03-17T22:18:33.596ZMax gen: 32, Max flush: 1505
4732025-03-17T22:18:33.596Zdump test passed
4742025-03-17T22:18:33.596Z/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
4752025-03-17T22:18:33.618Z Extent 1
4762025-03-17T22:18:33.618ZGEN 32 32 32
4772025-03-17T22:18:33.619ZFLUSH_ID 1505 1505 1505
4782025-03-17T22:18:33.619ZDIRTY
4792025-03-17T22:18:33.619Z
4802025-03-17T22:18:33.619ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4812025-03-17T22:18:33.619Z010 A A A A A A
4822025-03-17T22:18:33.619Z011 A A A A A A
4832025-03-17T22:18:33.619Z012 A A A A A A
4842025-03-17T22:18:33.619Z013 A A A A A A
4852025-03-17T22:18:33.619Z014 A A A A A A
4862025-03-17T22:18:33.619Z015 A A A A A A
4872025-03-17T22:18:33.619Z016 A A A A A A
4882025-03-17T22:18:33.619Z017 A A A A A A
4892025-03-17T22:18:33.619Z018 A A A A A A
4902025-03-17T22:18:33.619Z019 A A A A A A
4912025-03-17T22:18:33.634Zdump extent test passed
4922025-03-17T22:18:33.634Z/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
4932025-03-17T22:18:33.634ZExtent 2 Block in extent 0 Actual block 20
4942025-03-17T22:18:33.634Z
4952025-03-17T22:18:33.658Z DATA SHA256 VER
4962025-03-17T22:18:33.658Z------ ---------------------------------------------------------------- ---
4972025-03-17T22:18:33.658Z 0 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
4982025-03-17T22:18:33.658Z 1 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
4992025-03-17T22:18:33.658Z 2 ad3d0e88276af7eb1f904413516e1a8c1f9c2fa8b17b86b2d842d08303e90aa2 A
5002025-03-17T22:18:33.658Z
5012025-03-17T22:18:33.658ZNONCES 0 1 2 DIFF
5022025-03-17T22:18:33.658Z------ ------------------------ ------------------------ ------------------------ -----
5032025-03-17T22:18:33.658Z
5042025-03-17T22:18:33.658Z TAGS 0 1 2 DIFF
5052025-03-17T22:18:33.658Z------ -------------------------------- -------------------------------- -------------------------------- -----
5062025-03-17T22:18:33.659Z
5072025-03-17T22:18:33.659ZHASHES 0 1 2 DIFF
5082025-03-17T22:18:33.659Z------ ---------------- ---------------- ---------------- -----
5092025-03-17T22:18:33.659Z 0 42916ab6fa364c70 42916ab6fa364c70 42916ab6fa364c70
5102025-03-17T22:18:33.659Z
5112025-03-17T22:18:33.659Zdump block test passed
5122025-03-17T22:18:33.659ZInitial upstairs tests have completed, stopping all downstairs
5132025-03-17T22:18:38.698ZCreating 4 larger downstairs regions
5142025-03-17T22:18:38.815ZStarting 4 downstairs
5152025-03-17T22:18:43.824Zdsc restarted at PID: 1254
5162025-03-17T22:18:44.062ZNow do the replace-reconcile test
5172025-03-17T22:18:44.123ZUsing 8840 for the replacement port
5182025-03-17T22:21:17.508ZCompleted test: replace-reconcile
5192025-03-17T22:21:17.511ZNow do the replace-before-active test
5202025-03-17T22:24:01.934ZCompleted test: replace-before-active
5212025-03-17T22:24:01.935ZAll tests have completed, stopping all downstairs
5222025-03-17T22:24:01.971Z
5232025-03-17T22:24:01.971ZAll Tests have passed
5242025-03-17T22:24:01.976Z7:50 Test duration
5252025-03-17T22:24:01.976Z
5262025-03-17T22:24:01.976Zreal 7:49.795213116
5272025-03-17T22:24:01.976Zuser 1:04.199388760
5282025-03-17T22:24:01.976Zsys 10.102496390
5292025-03-17T22:24:01.976Ztrap 0.085785723
5302025-03-17T22:24:01.976Ztflt 0.018952413
5312025-03-17T22:24:01.976Zdflt 0.026728570
5322025-03-17T22:24:01.977Zkflt 0.001200676
5332025-03-17T22:24:01.977Zlock 5:43:12.987275844
5342025-03-17T22:24:01.977Zslp 24:31.681916081
5352025-03-17T22:24:01.977Zlat 7.545781104
5362025-03-17T22:24:01.977Zstop 0.129732225
5372025-03-17T22:24:01.977Z+ echo 'test-up-unencrypted ends'
5382025-03-17T22:24:01.977Ztest-up-unencrypted ends
5392025-03-17T22:24:06.979Zprocess exited: duration 478283 ms, exit code 0
5402025-03-17T22:24:06.979Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5412025-03-17T22:25:07.032Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5422025-03-17T22:25:07.033Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5432025-03-17T22:25:07.049Zfound 14 output files
5442025-03-17T22:25:07.049Zuploading: /tmp/test_up-build/dsc-out.txt (37343 bytes)
5452025-03-17T22:25:08.065Zuploaded: /tmp/test_up-build/dsc-out.txt
5462025-03-17T22:25:08.076Zuploading: /tmp/test_up-build/test_up_out.txt (8004999 bytes)
5472025-03-17T22:25:09.265Zuploaded: /tmp/test_up-build/test_up_out.txt
5482025-03-17T22:25:09.269Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (253609 bytes)
5492025-03-17T22:25:10.299Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5502025-03-17T22:25:10.303Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144654 bytes)
5512025-03-17T22:25:11.328Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5522025-03-17T22:25:11.328Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251003 bytes)
5532025-03-17T22:25:12.366Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5542025-03-17T22:25:12.366Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139430 bytes)
5552025-03-17T22:25:13.655Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5562025-03-17T22:25:13.655Zuploading: /tmp/debug/df.txt (1270 bytes)
5572025-03-17T22:25:14.669Zuploaded: /tmp/debug/df.txt
5582025-03-17T22:25:14.669Zuploading: /tmp/debug/dtrace.txt (373901 bytes)
5592025-03-17T22:25:14.707Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 373901 -> 453545
5602025-03-17T22:25:15.718Zuploaded: /tmp/debug/dtrace.txt
5612025-03-17T22:25:15.718Zuploading: /tmp/debug/iostat.txt (159441 bytes)
5622025-03-17T22:25:15.741Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 159441 -> 162123
5632025-03-17T22:25:16.750Zuploaded: /tmp/debug/iostat.txt
5642025-03-17T22:25:16.750Zuploading: /tmp/debug/mpstat.txt (388952 bytes)
5652025-03-17T22:25:16.786Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 388952 -> 396222
5662025-03-17T22:25:17.798Zuploaded: /tmp/debug/mpstat.txt
5672025-03-17T22:25:17.798Zuploading: /tmp/debug/paging.txt (68987 bytes)
5682025-03-17T22:25:17.812Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 68987 -> 70388
5692025-03-17T22:25:18.823Zuploaded: /tmp/debug/paging.txt
5702025-03-17T22:25:18.827Zuploading: /tmp/debug/prstat.txt (731823 bytes)
5712025-03-17T22:25:18.875Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 731823 -> 747303
5722025-03-17T22:25:19.882Zuploaded: /tmp/debug/prstat.txt
5732025-03-17T22:25:19.886Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
5742025-03-17T22:25:20.895Zuploaded: /tmp/debug/psrinfo.txt
5752025-03-17T22:25:20.895Zuploading: /tmp/debug/upstairs-info.txt (49830 bytes)
5762025-03-17T22:25:21.915Zuploaded: /tmp/debug/upstairs-info.txt