01JJ4QVH23Z44MY95ZQWZ5VG2J: test-up-encrypted

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

Buildomat Job: 01JJ4QVT7XPCYMH02JRFDK155T

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12025-01-21T15:45:36.784Zjob dependencies complete; ready to run (waiting for 13 m 38 s)
22025-01-21T15:46:43.957Zjob assigned to worker 01JJ4RN7KVHJGXEVWKR98C4HPT [factory aws, i-035bbc0028c430553] (queued for 1 m 7 s)
32025-01-21T15:46:51.774Zdownloading input: /input/build/work/bins/crucible-downstairs.gz
42025-01-21T15:46:52.884Zdownloaded input: /input/build/work/bins/crucible-downstairs.gz
52025-01-21T15:46:52.884Zdownloading input: /input/build/work/bins/crucible-hammer.gz
62025-01-21T15:46:53.968Zdownloaded input: /input/build/work/bins/crucible-hammer.gz
72025-01-21T15:46:53.968Zdownloading input: /input/build/work/bins/crutest.gz
82025-01-21T15:46:55.148Zdownloaded input: /input/build/work/bins/crutest.gz
92025-01-21T15:46:55.148Zdownloading input: /input/build/work/bins/dsc.gz
102025-01-21T15:46:55.821Zdownloaded input: /input/build/work/bins/dsc.gz
112025-01-21T15:46:55.824Zdownloading input: /input/build/work/scripts/perf-downstairs-tick.d
122025-01-21T15:46:55.840Zdownloaded input: /input/build/work/scripts/perf-downstairs-tick.d
132025-01-21T15:46:55.840Zdownloading input: /input/build/work/scripts/test_ds.sh
142025-01-21T15:46:55.864Zdownloaded input: /input/build/work/scripts/test_ds.sh
152025-01-21T15:46:55.864Zdownloading input: /input/build/work/scripts/test_live_repair.sh
162025-01-21T15:46:55.879Zdownloaded input: /input/build/work/scripts/test_live_repair.sh
172025-01-21T15:46:55.879Zdownloading input: /input/build/work/scripts/test_repair.sh
182025-01-21T15:46:55.897Zdownloaded input: /input/build/work/scripts/test_repair.sh
192025-01-21T15:46:55.897Zdownloading input: /input/build/work/scripts/test_replay.sh
202025-01-21T15:46:55.919Zdownloaded input: /input/build/work/scripts/test_replay.sh
212025-01-21T15:46:55.919Zdownloading input: /input/build/work/scripts/test_up.sh
222025-01-21T15:46:55.936Zdownloaded input: /input/build/work/scripts/test_up.sh
232025-01-21T15:46:55.936Zdownloading input: /input/build/work/scripts/upstairs_info.d
242025-01-21T15:46:55.950Zdownloaded input: /input/build/work/scripts/upstairs_info.d
252025-01-21T15:46:55.953Zdownloading input: /input/build/tmp/cargo-test-out.log
262025-01-21T15:46:56.680Zdownloaded input: /input/build/tmp/cargo-test-out.log
 
272025-01-21T15:46:56.680Zstarting task 0: "setup"
282025-01-21T15:46:56.693Z++ uname -s
292025-01-21T15:46:56.696Z+ kern=SunOS
302025-01-21T15:46:56.696Z+ case "$kern" in
312025-01-21T15:46:56.696Z+ groupadd -g 12345 build
322025-01-21T15:46:56.699Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
332025-01-21T15:46:58.707Z+ zfs create -o mountpoint=/work rpool/work
342025-01-21T15:46:58.846Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
352025-01-21T15:46:58.849Z+ home_fs=zfs
362025-01-21T15:46:58.849Z+ [[ zfs == autofs ]]
372025-01-21T15:46:58.849Z+ mkdir -p /home/build
382025-01-21T15:46:58.852Z+ chown build:build /home/build /work
392025-01-21T15:47:00.853Z+ chmod 0700 /home/build /work
402025-01-21T15:47:00.856Zprocess exited: duration 4175 ms, exit code 0
 
412025-01-21T15:47:00.862Zstarting task 1: "authentication"
422025-01-21T15:47:00.881Zprocess exited: duration 18 ms, exit code 0
 
432025-01-21T15:47:00.887Zstarting task 2: "build"
442025-01-21T15:47:00.892Z+ banner cores
452025-01-21T15:47:00.895Z
462025-01-21T15:47:00.895Z #### #### ##### ###### ####
472025-01-21T15:47:00.895Z # # # # # # # #
482025-01-21T15:47:00.895Z # # # # # ##### ####
492025-01-21T15:47:00.895Z # # # ##### # #
502025-01-21T15:47:00.895Z # # # # # # # # #
512025-01-21T15:47:00.895Z #### #### # # ###### ####
522025-01-21T15:47:00.895Z
532025-01-21T15:47:00.895Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
542025-01-21T15:47:00.904Z+ echo 'input bins dir contains:'
552025-01-21T15:47:00.904Zinput bins dir contains:
562025-01-21T15:47:00.907Z+ ls -ltr /input/build/work/bins
572025-01-21T15:47:00.907Ztotal 768756
582025-01-21T15:47:00.907Z-rw-r--r-- 1 root root 109552400 Jan 21 15:46 crucible-downstairs.gz
592025-01-21T15:47:00.907Z-rw-r--r-- 1 root root 104184191 Jan 21 15:46 crucible-hammer.gz
602025-01-21T15:47:00.907Z-rw-r--r-- 1 root root 113232272 Jan 21 15:46 crutest.gz
612025-01-21T15:47:00.907Z-rw-r--r-- 1 root root 66369466 Jan 21 15:46 dsc.gz
622025-01-21T15:47:00.907Z+ banner unpack
632025-01-21T15:47:00.910Z
642025-01-21T15:47:00.910Z # # # # ##### ## #### # #
652025-01-21T15:47:00.911Z # # ## # # # # # # # # #
662025-01-21T15:47:00.911Z # # # # # # # # # # ####
672025-01-21T15:47:00.911Z # # # # # ##### ###### # # #
682025-01-21T15:47:00.911Z # # # ## # # # # # # #
692025-01-21T15:47:00.911Z #### # # # # # #### # #
702025-01-21T15:47:00.911Z
712025-01-21T15:47:00.911Z+ mkdir -p /var/tmp/bins
722025-01-21T15:47:00.914Z+ for t in "$input/bins/"*.gz
732025-01-21T15:47:00.914Z++ basename /input/build/work/bins/crucible-downstairs.gz
742025-01-21T15:47:00.914Z+ b=crucible-downstairs.gz
752025-01-21T15:47:00.914Z+ b=crucible-downstairs
762025-01-21T15:47:00.914Z+ gunzip
772025-01-21T15:47:03.181Z+ chmod +x /var/tmp/bins/crucible-downstairs
782025-01-21T15:47:03.184Z+ for t in "$input/bins/"*.gz
792025-01-21T15:47:03.187Z++ basename /input/build/work/bins/crucible-hammer.gz
802025-01-21T15:47:03.187Z+ b=crucible-hammer.gz
812025-01-21T15:47:03.187Z+ b=crucible-hammer
822025-01-21T15:47:03.187Z+ gunzip
832025-01-21T15:47:05.325Z+ chmod +x /var/tmp/bins/crucible-hammer
842025-01-21T15:47:05.328Z+ for t in "$input/bins/"*.gz
852025-01-21T15:47:05.331Z++ basename /input/build/work/bins/crutest.gz
862025-01-21T15:47:05.331Z+ b=crutest.gz
872025-01-21T15:47:05.331Z+ b=crutest
882025-01-21T15:47:05.331Z+ gunzip
892025-01-21T15:47:07.747Z+ chmod +x /var/tmp/bins/crutest
902025-01-21T15:47:07.751Z+ for t in "$input/bins/"*.gz
912025-01-21T15:47:07.751Z++ basename /input/build/work/bins/dsc.gz
922025-01-21T15:47:07.756Z+ b=dsc.gz
932025-01-21T15:47:07.756Z+ b=dsc
942025-01-21T15:47:07.756Z+ gunzip
952025-01-21T15:47:09.129Z+ chmod +x /var/tmp/bins/dsc
962025-01-21T15:47:09.132Z+ export BINDIR=/var/tmp/bins
972025-01-21T15:47:09.132Z+ BINDIR=/var/tmp/bins
982025-01-21T15:47:09.132Z+ export RUST_BACKTRACE=1
992025-01-21T15:47:09.132Z+ RUST_BACKTRACE=1
1002025-01-21T15:47:09.133Z+ jobpid=1141
1012025-01-21T15:47:09.133Z+ echo 'Setup debug logging'
1022025-01-21T15:47:09.133ZSetup debug logging
1032025-01-21T15:47:09.133Z+ mkdir /tmp/debug
1042025-01-21T15:47:09.136Z+ sleep 3600
1052025-01-21T15:47:09.136Z+ psrinfo -v
1062025-01-21T15:47:09.139Z+ df -h
1072025-01-21T15:47:09.145Z+ prstat -d d -mLc 1
1082025-01-21T15:47:09.148Z+ iostat -T d -xn 1
1092025-01-21T15:47:09.148Z+ mpstat -T d 1
1102025-01-21T15:47:09.148Z+ vmstat -T d -p 1
1112025-01-21T15:47:09.152Z+ pfexec dtrace -Z -s /input/build/work/scripts/perf-downstairs-tick.d
1122025-01-21T15:47:09.152Z+ banner test_up_encrypted
1132025-01-21T15:47:09.152Z+ pfexec dtrace -Z -s /input/build/work/scripts/upstairs_info.d
1142025-01-21T15:47:09.152Z
1152025-01-21T15:47:09.152Z ##### ###### #### ##### # # ##### ###### # #
1162025-01-21T15:47:09.152Z # # # # # # # # # ## #
1172025-01-21T15:47:09.152Z # ##### #### # # # # # ##### # # #
1182025-01-21T15:47:09.152Z # # # # # # ##### # # # #
1192025-01-21T15:47:09.152Z # # # # # # # # # # ##
1202025-01-21T15:47:09.152Z # ###### #### # ####### #### # ####### ###### # #
1212025-01-21T15:47:09.152Z
1222025-01-21T15:47:09.156Z+ ptime -m bash /input/build/work/scripts/test_up.sh -N encrypted
1232025-01-21T15:47:09.165Z/input/build/work
1242025-01-21T15:47:09.177ZTurn off color for downstairs dump
1252025-01-21T15:47:09.193ZUpstairs using key: jIapirSWB+7oEO6gG39oxsmcreMWdwvodycNgMTQ7ik=
1262025-01-21T15:47:09.196Zdsc output goes to /tmp/test_up-build/dsc-out.txt
1272025-01-21T15:47:09.196ZCreating 3 downstairs regions
1282025-01-21T15:47:09.527ZStarting 3 downstairs
1292025-01-21T15:47:09.530Zdsc started at PID: 1187
1302025-01-21T15:47:14.719ZDisable automatic restart on all downstairs
1312025-01-21T15:47:14.776Z
1322025-01-21T15:47:14.776ZBegin tests, output goes to /tmp/test_up-build/test_up_out.txt
1332025-01-21T15:47:14.780ZRunning test: span
1342025-01-21T15:47:18.927ZCompleted test: span
1352025-01-21T15:47:23.934ZRunning test: big
1362025-01-21T15:47:28.253ZCompleted test: big
1372025-01-21T15:47:33.261ZRunning test: dep
1382025-01-21T15:48:25.705ZCompleted test: dep
1392025-01-21T15:48:30.713ZRunning test: balloon
1402025-01-21T15:49:11.899ZCompleted test: balloon
1412025-01-21T15:49:16.907ZRunning test: deactivate
1422025-01-21T15:50:11.576ZCompleted test: deactivate
1432025-01-21T15:50:16.584ZRunning hammer
1442025-01-21T15:50:29.671ZRun repair tests
1452025-01-21T15:50:29.675Z/var/tmp/bins/crutest fill -g 31 -q --key jIapirSWB+7oEO6gG39oxsmcreMWdwvodycNgMTQ7ik= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file
1462025-01-21T15:50:29.738Z{"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-01-21T15:50:28.175270558Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"task":"crutest"}
1472025-01-21T15:50:29.741Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.175868816Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"task":"crutest"}
1482025-01-21T15:50:29.741Z{"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-01-21T15:50:28.177660499Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"task":"crutest"}
1492025-01-21T15:50:29.741Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.17787759Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
1502025-01-21T15:50:29.741Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-01-21T15:50:28.177937635Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
1512025-01-21T15:50:29.741Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.177960953Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
1522025-01-21T15:50:29.741Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.177986221Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
1532025-01-21T15:50:29.744Z{"msg":"Crucible b2248916-b31f-4da5-8dac-0b5ad3ae06aa has session id: 91bd4f30-0a57-4205-b9d7-e6b4d0a69b04","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.178552371Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1542025-01-21T15:50:29.744Z{"msg":"Upstairs opts: Upstairs UUID: b2248916-b31f-4da5-8dac-0b5ad3ae06aa, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.178666971Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1552025-01-21T15:50:29.744Z{"msg":"Crucible stats registered with UUID: b2248916-b31f-4da5-8dac-0b5ad3ae06aa","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.178714397Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1562025-01-21T15:50:29.744Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:28.178738645Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1572025-01-21T15:50:29.744Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179763365Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"task":"crutest"}
1582025-01-21T15:50:29.744Z{"msg":"The guest has requested activation with gen:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179798792Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
1592025-01-21T15:50:29.745Z{"msg":"b2248916-b31f-4da5-8dac-0b5ad3ae06aa active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179877475Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1602025-01-21T15:50:29.745Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179908873Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1612025-01-21T15:50:29.745Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179957668Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1622025-01-21T15:50:29.745Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.179985406Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1632025-01-21T15:50:29.745Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180020973Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1642025-01-21T15:50:29.745Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.18005644Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1652025-01-21T15:50:29.745Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180092757Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1662025-01-21T15:50:29.745Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180117225Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1672025-01-21T15:50:29.745Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180150002Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1682025-01-21T15:50:29.745Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.18017538Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1692025-01-21T15:50:29.745Z{"msg":"ds_connection connected from Ok(127.0.0.1:49420)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180212236Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1702025-01-21T15:50:29.745Z{"msg":"ds_connection connected from Ok(127.0.0.1:44087)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180235684Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1712025-01-21T15:50:29.745Z{"msg":"ds_connection connected from Ok(127.0.0.1:64808)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180267211Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"io task","client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1722025-01-21T15:50:29.745Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.180952001Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1732025-01-21T15:50:29.745Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.181176282Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1742025-01-21T15:50:29.745Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.181290552Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1752025-01-21T15:50:29.748Z{"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-01-21T15:50:28.181777929Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1762025-01-21T15:50:29.748Z{"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-01-21T15:50:28.181821445Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1772025-01-21T15:50:29.748Z{"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-01-21T15:50:28.182059025Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1782025-01-21T15:50:29.748Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182195703Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1792025-01-21T15:50:29.748Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182290535Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1802025-01-21T15:50:29.748Z{"msg":"[0]R flush_numbers: [1498, 1498, 1498, 1498, 1498]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182415404Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1812025-01-21T15:50:29.749Z{"msg":"[0]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182441671Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1822025-01-21T15:50:29.749Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.18245635Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1832025-01-21T15:50:29.749Z{"msg":"[1]R flush_numbers: [1498, 1498, 1498, 1498, 1498]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182469939Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1842025-01-21T15:50:29.749Z{"msg":"[1]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182491167Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1852025-01-21T15:50:29.749Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182504506Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1862025-01-21T15:50:29.749Z{"msg":"[2]R flush_numbers: [1498, 1498, 1498, 1498, 1498]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182517305Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1872025-01-21T15:50:29.749Z{"msg":"[2]R generation: [25, 25, 25, 25, 25]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182530823Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1882025-01-21T15:50:29.749Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182543692Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1892025-01-21T15:50:29.749Z{"msg":"Max found gen is 26","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182557821Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1902025-01-21T15:50:29.749Z{"msg":"Generation requested: 31 >= found:26","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.1825708Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1912025-01-21T15:50:29.749ZWait for a query_work_queue command to finish before sending IO
1922025-01-21T15:50:29.749Z{"msg":"Next flush: 1499","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182596258Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1932025-01-21T15:50:29.750Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182609457Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"":"downstairs","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1942025-01-21T15:50:29.750Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182628985Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1952025-01-21T15:50:29.750Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182641184Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"0","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1962025-01-21T15:50:29.750Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182654073Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"1","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1972025-01-21T15:50:29.750Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182673841Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"client":"2","":"downstairs","session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1982025-01-21T15:50:29.750Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.18268694Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
1992025-01-21T15:50:29.750Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182699219Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
2002025-01-21T15:50:29.750Z{"msg":"b2248916-b31f-4da5-8dac-0b5ad3ae06aa is now active with session: 91bd4f30-0a57-4205-b9d7-e6b4d0a69b04","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182718877Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
2012025-01-21T15:50:29.750Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182730846Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224,"session_id":"91bd4f30-0a57-4205-b9d7-e6b4d0a69b04"}
2022025-01-21T15:50:29.750Z{"msg":"The guest has finished waiting for activation with:31","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:28.182742665Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
2032025-01-21T15:50:29.750ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2042025-01-21T15:50:29.750ZFill test
2052025-01-21T15:50:29.786ZRead and Verify all blocks (0..50 range:false)
2062025-01-21T15:50:29.826ZWrote out file "/var/tmp/test_up-build/verify_file"
2072025-01-21T15:50:29.826ZCLIENT: Tests done. All submitted work has been ACK'd
2082025-01-21T15:50:29.829Z----------------------------------------------------------------
2092025-01-21T15:50:29.829Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:1
2102025-01-21T15:50:29.829ZStates: Active Active Active
2112025-01-21T15:50:29.829ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
2122025-01-21T15:50:29.829Z 1002 Acked Read 50 Done Done Done false
2132025-01-21T15:50:29.829Z STATES DS:0 DS:1 DS:2 TOTAL
2142025-01-21T15:50:29.829Z Sent 0 0 0 0
2152025-01-21T15:50:29.829Z Done 1 1 1 3
2162025-01-21T15:50:29.829Z Skipped 0 0 0 0
2172025-01-21T15:50:29.829Z Error 0 0 0 0
2182025-01-21T15:50:29.829ZLast Flush: 1001 1001 1001
2192025-01-21T15:50:29.829ZDownstairs last five completed: 1001 1000
2202025-01-21T15:50:29.829ZUpstairs last five completed: 1002 1001 1000
2212025-01-21T15:50:29.829ZCLIENT: Up:0 ds:1 act:3
2222025-01-21T15:50:33.828Z----------------------------------------------------------------
2232025-01-21T15:50:33.828Z Crucible gen:31 GIO:true work queues: Upstairs:0 downstairs:0
2242025-01-21T15:50:33.828ZDownstairs last five completed: 1003 1002 1001 1000
2252025-01-21T15:50:33.828ZUpstairs last five completed: 1003 1002 1001 1000
2262025-01-21T15:50:33.828ZCLIENT: Up:0 ds:0 act:3
2272025-01-21T15:50:33.828ZCLIENT: All crucible jobs finished, exiting program
2282025-01-21T15:50:33.831Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:32.264595481Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1224}
2292025-01-21T15:50:33.839ZRepair setup passed
2302025-01-21T15:50:33.843ZCopy the region for /var/tmp/test_up-build/8830
2312025-01-21T15:50:33.846Zcp -r /var/tmp/test_up-build/8830 /var/tmp/test_up-build/previous
2322025-01-21T15:50:33.849Z/var/tmp/bins/crutest fill -g 32 -q --key jIapirSWB+7oEO6gG39oxsmcreMWdwvodycNgMTQ7ik= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
2332025-01-21T15:50:33.908Z{"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-01-21T15:50:32.344296784Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"task":"crutest"}
2342025-01-21T15:50:33.911Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.344934688Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"task":"crutest"}
2352025-01-21T15:50:33.911Z{"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-01-21T15:50:32.346652458Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"task":"crutest"}
2362025-01-21T15:50:33.911Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.346878758Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2372025-01-21T15:50:33.911Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-01-21T15:50:32.346924534Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2382025-01-21T15:50:33.911Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.346948592Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2392025-01-21T15:50:33.911Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.346964741Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2402025-01-21T15:50:33.911Z{"msg":"Crucible c77db476-0f80-43b6-bea6-8d2954a24925 has session id: b8baa6de-2c70-4e20-9950-e3bc4c8a2460","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.347579387Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2412025-01-21T15:50:33.914Z{"msg":"Upstairs opts: Upstairs UUID: c77db476-0f80-43b6-bea6-8d2954a24925, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.347719635Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2422025-01-21T15:50:33.914Z{"msg":"Crucible stats registered with UUID: c77db476-0f80-43b6-bea6-8d2954a24925","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.347789089Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2432025-01-21T15:50:33.914Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:32.347827045Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2442025-01-21T15:50:33.914Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349021131Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"task":"crutest"}
2452025-01-21T15:50:33.914Z{"msg":"The guest has requested activation with gen:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349059537Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2462025-01-21T15:50:33.914Z{"msg":"c77db476-0f80-43b6-bea6-8d2954a24925 active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349114893Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2472025-01-21T15:50:33.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349170328Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2482025-01-21T15:50:33.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.34925946Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2492025-01-21T15:50:33.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349295257Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2502025-01-21T15:50:33.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349318205Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2512025-01-21T15:50:33.914Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349340093Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2522025-01-21T15:50:33.914Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.34937233Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2532025-01-21T15:50:33.915Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349395338Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2542025-01-21T15:50:33.915Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349426315Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2552025-01-21T15:50:33.915Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349448753Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2562025-01-21T15:50:33.915Z{"msg":"ds_connection connected from Ok(127.0.0.1:54769)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349480041Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2572025-01-21T15:50:33.915Z{"msg":"ds_connection connected from Ok(127.0.0.1:41822)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349513458Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2582025-01-21T15:50:33.915Z{"msg":"ds_connection connected from Ok(127.0.0.1:51076)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.349672754Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"io task","client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2592025-01-21T15:50:33.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.350217016Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2602025-01-21T15:50:33.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.350253293Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2612025-01-21T15:50:33.915Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.350270272Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2622025-01-21T15:50:33.918Z{"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-01-21T15:50:32.350897417Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2632025-01-21T15:50:33.918Z{"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-01-21T15:50:32.350950922Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2642025-01-21T15:50:33.918Z{"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-01-21T15:50:32.351042314Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2652025-01-21T15:50:33.918Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351361996Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2662025-01-21T15:50:33.918Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351418401Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2672025-01-21T15:50:33.918Z{"msg":"[0]R flush_numbers: [1499, 1499, 1499, 1499, 1499]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351454348Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2682025-01-21T15:50:33.918Z{"msg":"[0]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351488325Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2692025-01-21T15:50:33.918Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351505833Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2702025-01-21T15:50:33.919Z{"msg":"[1]R flush_numbers: [1499, 1499, 1499, 1499, 1499]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351526022Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2712025-01-21T15:50:33.919Z{"msg":"[1]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351554239Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2722025-01-21T15:50:33.919Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351569608Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2732025-01-21T15:50:33.919Z{Wait for a query_work_queue command to finish before sending IO
2742025-01-21T15:50:33.919Z"msg":"[2]R flush_numbers: [1499, 1499, 1499, 1499, 1499]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351607815Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2752025-01-21T15:50:33.919Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351638412Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2762025-01-21T15:50:33.919Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351669999Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2772025-01-21T15:50:33.919Z{"msg":"Max found gen is 32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351701347Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2782025-01-21T15:50:33.919Z{"msg":"Generation requested: 32 >= found:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351722925Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2792025-01-21T15:50:33.919Z{"msg":"Next flush: 1500","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351743163Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2802025-01-21T15:50:33.919Z{"msg":"All extents match","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351798468Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"":"downstairs","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2812025-01-21T15:50:33.919Z{"msg":"No downstairs reconciliation required","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351817226Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2822025-01-21T15:50:33.919Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351843954Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"0","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2832025-01-21T15:50:33.919ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
2842025-01-21T15:50:33.919Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351864052Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"1","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2852025-01-21T15:50:33.919Z{"msg":"Transition from WaitQuorum to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.3518929Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"client":"2","":"downstairs","session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2862025-01-21T15:50:33.919Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351907688Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2872025-01-21T15:50:33.919Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351937256Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2882025-01-21T15:50:33.919Z{"msg":"c77db476-0f80-43b6-bea6-8d2954a24925 is now active with session: b8baa6de-2c70-4e20-9950-e3bc4c8a2460","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351957404Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2892025-01-21T15:50:33.919Z{"msg":"Set Active after no reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.351996551Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230,"session_id":"b8baa6de-2c70-4e20-9950-e3bc4c8a2460"}
2902025-01-21T15:50:33.919Z{"msg":"The guest has finished waiting for activation with:32","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:32.352010289Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
2912025-01-21T15:50:33.919ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
2922025-01-21T15:50:33.919ZFill test
2932025-01-21T15:50:33.955ZRead and Verify all blocks (0..50 range:false)
2942025-01-21T15:50:33.994ZWrote out file "/var/tmp/test_up-build/verify_file"
2952025-01-21T15:50:33.994ZCLIENT: Tests done. All submitted work has been ACK'd
2962025-01-21T15:50:33.995Z----------------------------------------------------------------
2972025-01-21T15:50:33.995Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:1
2982025-01-21T15:50:33.995ZStates: Active Active Active
2992025-01-21T15:50:33.995ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
3002025-01-21T15:50:33.995Z 1002 Acked Read 50 Done Done Done false
3012025-01-21T15:50:33.995Z STATES DS:0 DS:1 DS:2 TOTAL
3022025-01-21T15:50:33.995Z Sent 0 0 0 0
3032025-01-21T15:50:33.995Z Done 1 1 1 3
3042025-01-21T15:50:33.995Z Skipped 0 0 0 0
3052025-01-21T15:50:33.995Z Error 0 0 0 0
3062025-01-21T15:50:33.995ZLast Flush: 1001 1001 1001
3072025-01-21T15:50:33.995ZDownstairs last five completed: 1001 1000
3082025-01-21T15:50:33.995ZUpstairs last five completed: 1002 1001 1000
3092025-01-21T15:50:33.998ZCLIENT: Up:0 ds:1 act:3
3102025-01-21T15:50:37.997Z----------------------------------------------------------------
3112025-01-21T15:50:37.997Z Crucible gen:32 GIO:true work queues: Upstairs:0 downstairs:0
3122025-01-21T15:50:37.997ZDownstairs last five completed: 1003 1002 1001 1000
3132025-01-21T15:50:37.997ZUpstairs last five completed: 1003 1002 1001 1000
3142025-01-21T15:50:37.997ZCLIENT: Up:0 ds:0 act:3
3152025-01-21T15:50:37.997ZCLIENT: All crucible jobs finished, exiting program
3162025-01-21T15:50:38.000Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:36.432591345Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1230}
3172025-01-21T15:50:38.003ZRepair part 1 passed
3182025-01-21T15:50:38.006Z
3192025-01-21T15:50:38.006ZKill the current downstairs
3202025-01-21T15:50:38.181ZDownstairs 2 stopped
3212025-01-21T15:50:38.181Zmv /var/tmp/test_up-build/8830 /var/tmp/test_up-build/new
3222025-01-21T15:50:38.184ZNow put back the original so we have a mismatch
3232025-01-21T15:50:38.184Zmv /var/tmp/test_up-build/previous /var/tmp/test_up-build/8830
3242025-01-21T15:50:38.186ZRestart downstairs with old directory
3252025-01-21T15:50:38.244Z/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
3262025-01-21T15:50:38.262ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
3272025-01-21T15:50:38.265Z 0 000-009 32 32 31 1500 1500 1499 F F F <---
3282025-01-21T15:50:38.265Z 1 010-019 32 32 31 1500 1500 1499 F F F <---
3292025-01-21T15:50:38.265Z 2 020-029 32 32 31 1500 1500 1499 F F F <---
3302025-01-21T15:50:38.265Z 3 030-039 32 32 31 1500 1500 1499 F F F <---
3312025-01-21T15:50:38.265Z 4 040-049 32 32 31 1500 1500 1499 F F F <---
3322025-01-21T15:50:38.265ZMax gen: 32, Max flush: 1500
3332025-01-21T15:50:38.479ZError: Difference in extent metadata found!
3342025-01-21T15:50:38.479Z
3352025-01-21T15:50:38.479ZStack backtrace:
3362025-01-21T15:50:38.479Z 0: anyhow::error::<impl anyhow::Error>::msg
3372025-01-21T15:50:38.479Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.92/src/backtrace.rs:27:14
3382025-01-21T15:50:38.479Z 1: anyhow::__private::format_err
3392025-01-21T15:50:38.479Z at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.92/src/lib.rs:691:13
3402025-01-21T15:50:38.498Zdump test found error as expected
3412025-01-21T15:50:38.498Z
3422025-01-21T15:50:38.498Z
3432025-01-21T15:50:38.501Z/var/tmp/bins/crutest verify --range -g 33 -q --key jIapirSWB+7oEO6gG39oxsmcreMWdwvodycNgMTQ7ik= --dsc 127.0.0.1:9998 --verify-out /var/tmp/test_up-build/verify_file --verify-in /var/tmp/test_up-build/verify_file
3442025-01-21T15:50:38.560Z{"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-01-21T15:50:36.995255276Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"task":"crutest"}
3452025-01-21T15:50:38.563Z{"msg":"dsc has 3 regions. This means 1 sub_volumes","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.995851444Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"task":"crutest"}
3462025-01-21T15:50:38.563Z{"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-01-21T15:50:36.997544556Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"task":"crutest"}
3472025-01-21T15:50:38.563Z{"msg":"Upstairs starts","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.997768047Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
3482025-01-21T15:50:38.563Z{"msg":"Crucible Version: BuildInfo {\n version: \"0.0.1\",\n git_sha: \"5c2b227300b758c153f33da870809d67a5160dae\",\n git_commit_timestamp: \"2025-01-21T15:31:20.000000000Z\",\n git_branch: \"mkeeter/always-check-live-repair\",\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-01-21T15:50:36.997817103Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
3492025-01-21T15:50:38.563Z{"msg":"Upstairs <-> Downstairs Message Version: 12","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.997841801Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
3502025-01-21T15:50:38.563Z{"msg":"Using region definition RegionDefinition { block_size: 4096, extent_size: Block { value: 10, shift: 12 }, extent_count: 5, uuid: 00000000-0000-0000-0000-000000000000, encrypted: true, database_read_version: 1, database_write_version: 1 }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.997861679Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
3512025-01-21T15:50:38.563Z{"msg":"Crucible 3a688872-e103-492e-adbc-0fee5e4808fe has session id: b7a9dbcc-c57b-4811-9eca-2649a68c466b","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.998495763Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3522025-01-21T15:50:38.563Z{"msg":"Upstairs opts: Upstairs UUID: 3a688872-e103-492e-adbc-0fee5e4808fe, Targets: [127.0.0.1:8810, 127.0.0.1:8820, 127.0.0.1:8830], lossy: false, flush_timeout: None, key populated: true, cert_pem populated: false, key_pem populated: false, root_cert_pem populated: false, Control: None, read_only: false","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.99853928Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3532025-01-21T15:50:38.563Z{"msg":"Crucible stats registered with UUID: 3a688872-e103-492e-adbc-0fee5e4808fe","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.998574697Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3542025-01-21T15:50:38.563Z{"msg":"could not find Downstairs address for Nexus","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:36.998590205Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3552025-01-21T15:50:38.566Z{"msg":"Downstairs in volume = 3","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.999818928Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"task":"crutest"}
3562025-01-21T15:50:38.566Z{"msg":"The guest has requested activation with gen:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.999866164Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
3572025-01-21T15:50:38.566Z{"msg":"3a688872-e103-492e-adbc-0fee5e4808fe active request set","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.99990552Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3582025-01-21T15:50:38.566Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.999942077Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3592025-01-21T15:50:38.566Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:36.999997082Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3602025-01-21T15:50:38.566Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.00002463Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3612025-01-21T15:50:38.567Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000051427Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3622025-01-21T15:50:38.567Z{"msg":"sending connect oneshot to client","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000085904Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3632025-01-21T15:50:38.567Z{"msg":"client set_active_request while in Connecting { state: Start { auto_promote: true }, mode: New }; waiting...","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000122051Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3642025-01-21T15:50:38.567Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000144629Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3652025-01-21T15:50:38.567Z{"msg":"connecting to 127.0.0.1:8810","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000168557Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3662025-01-21T15:50:38.567Z{"msg":"connecting to 127.0.0.1:8820","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000201174Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3672025-01-21T15:50:38.567Z{"msg":"ds_connection connected from Ok(127.0.0.1:37631)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000226662Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3682025-01-21T15:50:38.567Z{"msg":"ds_connection connected from Ok(127.0.0.1:35476)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000261109Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3692025-01-21T15:50:38.567Z{"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-01-21T15:50:37.000506837Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3702025-01-21T15:50:38.567Z{"msg":"client task is sending Done(ConnectionFailed(Os { code: 146, kind: ConnectionRefused, message: \"Connection refused\" }))","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:37.000549844Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3712025-01-21T15:50:38.567Z{"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-01-21T15:50:37.000582001Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3722025-01-21T15:50:38.567Z{"msg":"client task is exiting","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000616988Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3732025-01-21T15:50:38.567Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.000951339Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3742025-01-21T15:50:38.567Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.001344214Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3752025-01-21T15:50:38.567Z{"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-01-21T15:50:37.00173141Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3762025-01-21T15:50:38.567Z{"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-01-21T15:50:37.002095429Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3772025-01-21T15:50:38.567Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.002147704Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3782025-01-21T15:50:38.570Z{"msg":"Waiting for more clients to be ready","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:37.002507673Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3792025-01-21T15:50:48.569Z{"msg":"connecting to 127.0.0.1:8830","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.002812046Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3802025-01-21T15:50:48.569Z{"msg":"ds_connection connected from Ok(127.0.0.1:53639)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.002919676Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"io task","client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3812025-01-21T15:50:48.575Z{"msg":"version negotiation from state Connecting { state: WaitForPromote, mode: New }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.004091344Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3822025-01-21T15:50:48.575Z{"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-01-21T15:50:47.004677923Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3832025-01-21T15:50:48.575Z{"msg":"[0]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005121154Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3842025-01-21T15:50:48.575Z{"msg":"[0]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005156591Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3852025-01-21T15:50:48.575Z{"msg":"[0]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005176119Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3862025-01-21T15:50:48.575Z{"msg":"[1]R flush_numbers: [1500, 1500, 1500, 1500, 1500]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005201767Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3872025-01-21T15:50:48.575Z{"msg":"[1]R generation: [32, 32, 32, 32, 32]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005218516Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3882025-01-21T15:50:48.575Z{"msg":"[1]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005237114Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3892025-01-21T15:50:48.575Z{"msg":"[2]R flush_numbers: [1499, 1499, 1499, 1499, 1499]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005264232Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3902025-01-21T15:50:48.575Z{"msg":"[2]R generation: [31, 31, 31, 31, 31]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.0052813Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3912025-01-21T15:50:48.575Z{"msg":"[2]R dirty: [false, false, false, false, false]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005307448Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3922025-01-21T15:50:48.575Z{"msg":"Max found gen is 33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005323746Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3932025-01-21T15:50:48.575Z{"msg":"Generation requested: 33 >= found:33","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005347784Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3942025-01-21T15:50:48.575Z{"msg":"Next flush: 1501","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005364063Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3952025-01-21T15:50:48.575Z{"msg":"extent 0 needs reconciliation: ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 31, flush: 1499, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.00539158Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3962025-01-21T15:50:48.575Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 31, flush: 1499, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005413388Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3972025-01-21T15:50:48.575Z{"msg":"found dest for source 0 for extent at index 0 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005439336Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3982025-01-21T15:50:48.575Z{"msg":"extent 1 needs reconciliation: ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 31, flush: 1499, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005474003Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
3992025-01-21T15:50:48.575Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 31, flush: 1499, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.00551295Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4002025-01-21T15:50:48.575Z{"msg":"found dest for source 0 for extent at index 1 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005532268Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4012025-01-21T15:50:48.575Z{"msg":"extent 2 needs reconciliation: ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 31, flush: 1499, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005559536Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4022025-01-21T15:50:48.575Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 31, flush: 1499, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005579764Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4032025-01-21T15:50:48.575Z{"msg":"found dest for source 0 for extent at index 2 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005609381Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4042025-01-21T15:50:48.575Z{"msg":"extent 3 needs reconciliation: ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 31, flush: 1499, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005636469Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4052025-01-21T15:50:48.575Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 31, flush: 1499, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005667196Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4062025-01-21T15:50:48.575Z{"msg":"found dest for source 0 for extent at index 3 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005700563Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4072025-01-21T15:50:48.575Z{"msg":"extent 4 needs reconciliation: ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 32, flush: 1500, dirty: false } ExtentMetadata { gen: 31, flush: 1499, dirty: false }","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.00574044Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4082025-01-21T15:50:48.575Z{"msg":"extent:0 [ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 32, flush: 1500, dirty: false }, ExtentMetadata { gen: 31, flush: 1499, dirty: false }] => 0","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005791075Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4092025-01-21T15:50:48.576Z{"msg":"found dest for source 0 for extent at index 4 => [ClientId(2)]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005840941Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"mend","":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4102025-01-21T15:50:48.576Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005904436Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4112025-01-21T15:50:48.576Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.005956041Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4122025-01-21T15:50:48.576Z{"msg":"Transition from Connecting { state: WaitQuorum, mode: New } to Reconcile","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.006003957Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4132025-01-21T15:50:48.576Z{"msg":"Full repair list: {ExtentId(1): 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)] }, ExtentId(0): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }, ExtentId(3): ExtentFix { source: ClientId(0), dest: [ClientId(2)] }}","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.006039814Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4142025-01-21T15:50:48.576Z{"msg":"Task list: [ReconcileIO { id: ReconciliationId(0), op: ExtentFlush { repair_id: ReconciliationId(0), extent_id: ExtentId(1), client_id: ClientId(0), flush_number: 1501, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(1), op: ExtentClose { repair_id: ReconciliationId(1), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(2), op: ExtentRepair { repair_id: ReconciliationId(2), 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(3), op: ExtentReopen { repair_id: ReconciliationId(3), extent_id: ExtentId(1) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(4), op: ExtentFlush { repair_id: ReconciliationId(4), extent_id: ExtentId(4), client_id: ClientId(0), flush_number: 1501, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(5), op: ExtentClose { repair_id: ReconciliationId(5), extent_id: ExtentId(4) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(6), op: ExtentRepair { repair_id: ReconciliationId(6), 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(7), op: ExtentReopen { repair_id: ReconciliationId(7), extent_id: ExtentId(4) }, 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: 1501, 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(0), client_id: ClientId(0), flush_number: 1501, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(13), op: ExtentClose { repair_id: ReconciliationId(13), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(14), op: ExtentRepair { repair_id: ReconciliationId(14), 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(15), op: ExtentReopen { repair_id: ReconciliationId(15), extent_id: ExtentId(0) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(16), op: ExtentFlush { repair_id: ReconciliationId(16), extent_id: ExtentId(3), client_id: ClientId(0), flush_number: 1501, gen_number: 33 }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(17), op: ExtentClose { repair_id: ReconciliationId(17), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }, ReconcileIO { id: ReconciliationId(18), op: ExtentRepair { repair_id: ReconciliationId(18), 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(19), op: ExtentReopen { repair_id: ReconciliationId(19), extent_id: ExtentId(3) }, state: ClientData([New, New, New]) }]","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.006157283Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4152025-01-21T15:50:48.579Z{"msg":"starting reconciliation 254e3ca6-8f54-48a3-b19e-15b5579bbc82: found 20 extents that need repair","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.006181651Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4162025-01-21T15:50:48.579Z{"msg":"sending reconcile request ReconciliationId(2)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.0061963Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4172025-01-21T15:50:48.583Z{"msg":"sending reconcile request ReconciliationId(6)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.017506371Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4182025-01-21T15:50:48.587Z{"msg":"sending reconcile request ReconciliationId(10)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.02151798Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4192025-01-21T15:50:48.591Z{"msg":"sending reconcile request ReconciliationId(14)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.025289291Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4202025-01-21T15:50:48.595Z{"msg":"sending reconcile request ReconciliationId(18)","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.029039633Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4212025-01-21T15:50:48.598Z{"msg":"done with reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032151961Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"":"downstairs","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4222025-01-21T15:50:48.598Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032197267Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"0","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4232025-01-21T15:50:48.598Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032214065Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"1","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4242025-01-21T15:50:48.598Z{"msg":"Transition from Reconcile to Active","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032227974Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"client":"2","":"downstairs","session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4252025-01-21T15:50:48.598Z{"msg":"All required reconciliation work is completed","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032242053Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4262025-01-21T15:50:48.601Z{"msg":"Set Downstairs and Upstairs active after reconciliation","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032254622Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4272025-01-21T15:50:48.601Z{"msg":"3a688872-e103-492e-adbc-0fee5e4808fe is now active with session: b7a9dbcc-c57b-4811-9eca-2649a68c466b","v":0,"name":"crucible","level":30,"time":"2025-01-21T15:50:47.032268441Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238,"session_id":"b7a9dbcc-c57b-4811-9eca-2649a68c466b"}
4282025-01-21T15:50:48.601Z{"msg":"The guest has finished waiting for activation with:33","v":0,"name":"crucible","level":30Wait for a query_work_queue command to finish before sending IO
4292025-01-21T15:50:48.601Z,"time":"2025-01-21T15:50:47.03228171Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
4302025-01-21T15:50:48.601ZDisk: sv:1 bs:4096 ts:204800 tb:50 max_io:50 or 204800
4312025-01-21T15:50:48.601ZLoading write count information from file "/var/tmp/test_up-build/verify_file"
4322025-01-21T15:50:48.601ZRead and Verify all blocks (0..50 range:true)
4332025-01-21T15:50:48.639ZWrote out file "/var/tmp/test_up-build/verify_file"
4342025-01-21T15:50:48.639ZVerify test completed
4352025-01-21T15:50:48.642ZWrote out file "/var/tmp/test_up-build/verify_file"
4362025-01-21T15:50:48.642ZCLIENT: Tests done. All submitted work has been ACK'd
4372025-01-21T15:50:48.642Z----------------------------------------------------------------
4382025-01-21T15:50:48.642Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:1
4392025-01-21T15:50:48.642ZStates: Active Active Active
4402025-01-21T15:50:48.642ZJOBID ACK TYPE BKS/EXT DS:0 DS:1 DS:2 REPLAY
4412025-01-21T15:50:48.642Z 1000 Acked Read 50 Done Done Done false
4422025-01-21T15:50:48.642Z STATES DS:0 DS:1 DS:2 TOTAL
4432025-01-21T15:50:48.642Z Sent 0 0 0 0
4442025-01-21T15:50:48.642Z Done 1 1 1 3
4452025-01-21T15:50:48.642Z Skipped 0 0 0 0
4462025-01-21T15:50:48.642Z Error 0 0 0 0
4472025-01-21T15:50:48.642ZLast Flush: 0 0 0
4482025-01-21T15:50:48.642ZDownstairs last five completed:
4492025-01-21T15:50:48.642ZUpstairs last five completed: 1000
4502025-01-21T15:50:48.642ZCLIENT: Up:0 ds:1 act:3
4512025-01-21T15:50:52.641Z----------------------------------------------------------------
4522025-01-21T15:50:52.641Z Crucible gen:33 GIO:true work queues: Upstairs:0 downstairs:0
4532025-01-21T15:50:52.641ZDownstairs last five completed: 1001 1000
4542025-01-21T15:50:52.641ZUpstairs last five completed: 1001 1000
4552025-01-21T15:50:52.641ZCLIENT: Up:0 ds:0 act:3
4562025-01-21T15:50:52.641ZCLIENT: All crucible jobs finished, exiting program
4572025-01-21T15:50:52.645Z{"msg":"Guest handle has been dropped","v":0,"name":"crucible","level":40,"time":"2025-01-21T15:50:51.074283768Z","hostname":"w-01JJ4RN7KVHJGXEVWKR98C4HPT","pid":1238}
4582025-01-21T15:50:52.648ZRepair part 2 passed
4592025-01-21T15:50:52.651Z/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
4602025-01-21T15:50:52.667ZEXT BLOCKS GEN0 GEN1 GEN2 FL0 FL1 FL2 D0 D1 D2 DIFF
4612025-01-21T15:50:52.667Z 0 000-009 32 32 32 1500 1500 1500 F F F
4622025-01-21T15:50:52.667Z 1 010-019 32 32 32 1500 1500 1500 F F F
4632025-01-21T15:50:52.667Z 2 020-029 32 32 32 1500 1500 1500 F F F
4642025-01-21T15:50:52.667Z 3 030-039 32 32 32 1500 1500 1500 F F F
4652025-01-21T15:50:52.667Z 4 040-049 32 32 32 1500 1500 1500 F F F
4662025-01-21T15:50:52.667ZMax gen: 32, Max flush: 1500
4672025-01-21T15:50:52.672Zdump test passed
4682025-01-21T15:50:52.674Z/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
4692025-01-21T15:50:52.689Z Extent 1
4702025-01-21T15:50:52.692ZGEN 32 32 32
4712025-01-21T15:50:52.692ZFLUSH_ID 1500 1500 1500
4722025-01-21T15:50:52.692ZDIRTY
4732025-01-21T15:50:52.692Z
4742025-01-21T15:50:52.692ZBLOCK D0 D1 D2 C0 C1 C2 DIFF
4752025-01-21T15:50:52.692Z010 A A A A A A
4762025-01-21T15:50:52.696Z011 A A A A A A
4772025-01-21T15:50:52.696Z012 A A A A A A
4782025-01-21T15:50:52.699Z013 A A A A A A
4792025-01-21T15:50:52.699Z014 A A A A A A
4802025-01-21T15:50:52.699Z015 A A A A A A
4812025-01-21T15:50:52.702Z016 A A A A A A
4822025-01-21T15:50:52.702Z017 A A A A A A
4832025-01-21T15:50:52.705Z018 A A A A A A
4842025-01-21T15:50:52.705Z019 A A A A A A
4852025-01-21T15:50:52.709Zdump extent test passed
4862025-01-21T15:50:52.711Z/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
4872025-01-21T15:50:52.726ZExtent 2 Block in extent 0 Actual block 20
4882025-01-21T15:50:52.726Z
4892025-01-21T15:50:52.729Z DATA SHA256 VER
4902025-01-21T15:50:52.729Z------ ---------------------------------------------------------------- ---
4912025-01-21T15:50:52.732Z 0 abd93b400ad841a96a22e1d4846efa571b7a127c26540fc9677cb32331179d44 A
4922025-01-21T15:50:52.732Z 1 abd93b400ad841a96a22e1d4846efa571b7a127c26540fc9677cb32331179d44 A
4932025-01-21T15:50:52.732Z 2 abd93b400ad841a96a22e1d4846efa571b7a127c26540fc9677cb32331179d44 A
4942025-01-21T15:50:52.732Z
4952025-01-21T15:50:52.732ZNONCES 0 1 2 DIFF
4962025-01-21T15:50:52.732Z------ ------------------------ ------------------------ ------------------------ -----
4972025-01-21T15:50:52.732Z 0 3f26c0e5a91d9c50fea3d0ac 3f26c0e5a91d9c50fea3d0ac 3f26c0e5a91d9c50fea3d0ac
4982025-01-21T15:50:52.732Z
4992025-01-21T15:50:52.732Z TAGS 0 1 2 DIFF
5002025-01-21T15:50:52.732Z------ -------------------------------- -------------------------------- -------------------------------- -----
5012025-01-21T15:50:52.732Z 0 861f60d92a2c1bce833c6f2edd77935f 861f60d92a2c1bce833c6f2edd77935f 861f60d92a2c1bce833c6f2edd77935f
5022025-01-21T15:50:52.732Z
5032025-01-21T15:50:52.732ZHASHES 0 1 2 DIFF
5042025-01-21T15:50:52.732Z------ ---------------- ---------------- ---------------- -----
5052025-01-21T15:50:52.732Z
5062025-01-21T15:50:52.735Zdump block test passed
5072025-01-21T15:50:52.735ZInitial upstairs tests have completed, stopping all downstairs
5082025-01-21T15:50:57.802ZCreating 4 larger downstairs regions
5092025-01-21T15:50:57.919ZStarting 4 downstairs
5102025-01-21T15:51:02.927Zdsc restarted at PID: 1251
5112025-01-21T15:51:03.163ZNow do the replace-reconcile test
5122025-01-21T15:51:03.221ZUsing 8840 for the replacement port
5132025-01-21T15:53:54.396ZCompleted test: replace-reconcile
5142025-01-21T15:53:54.399ZNow do the replace-before-active test
5152025-01-21T15:57:01.175ZCompleted test: replace-before-active
5162025-01-21T15:57:01.175ZAll tests have completed, stopping all downstairs
5172025-01-21T15:57:01.235Z
5182025-01-21T15:57:01.235ZAll Tests have passed
5192025-01-21T15:57:01.239Z9:52 Test duration
5202025-01-21T15:57:01.239Z
5212025-01-21T15:57:01.239Zreal 9:51.982766435
5222025-01-21T15:57:01.239Zuser 6:26.994816476
5232025-01-21T15:57:01.239Zsys 12.972271411
5242025-01-21T15:57:01.239Ztrap 0.216529381
5252025-01-21T15:57:01.239Ztflt 0.020173137
5262025-01-21T15:57:01.239Zdflt 0.017433537
5272025-01-21T15:57:01.239Zkflt 0.001404644
5282025-01-21T15:57:01.239Zlock 8:29:12.050756731
5292025-01-21T15:57:01.239Zslp 33:53.953545151
5302025-01-21T15:57:01.239Zlat 24.111150561
5312025-01-21T15:57:01.239Zstop 0.134833328
5322025-01-21T15:57:01.239Z+ echo 'test-up-encrypted ends'
5332025-01-21T15:57:01.239Ztest-up-encrypted ends
5342025-01-21T15:57:06.240Zprocess exited: duration 600250 ms, exit code 0
5352025-01-21T15:57:06.241Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
5362025-01-21T15:58:06.291Zexec warning: : stdout descriptor may be held open by a background process; giving up!
5372025-01-21T15:58:06.291Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
5382025-01-21T15:58:06.303Zfound 14 output files
5392025-01-21T15:58:06.303Zuploading: /tmp/test_up-build/dsc-out.txt (39499 bytes)
5402025-01-21T15:58:07.315Zuploaded: /tmp/test_up-build/dsc-out.txt
5412025-01-21T15:58:07.315Zuploading: /tmp/test_up-build/test_up_out.txt (7331771 bytes)
5422025-01-21T15:58:08.405Zuploaded: /tmp/test_up-build/test_up_out.txt
5432025-01-21T15:58:08.408Zuploading: /tmp/test_up-build/dsc/downstairs-8810.txt (2509 bytes)
5442025-01-21T15:58:09.414Zuploaded: /tmp/test_up-build/dsc/downstairs-8810.txt
5452025-01-21T15:58:09.417Zuploading: /tmp/test_up-build/dsc/downstairs-8820.txt (144653 bytes)
5462025-01-21T15:58:10.436Zuploaded: /tmp/test_up-build/dsc/downstairs-8820.txt
5472025-01-21T15:58:10.438Zuploading: /tmp/test_up-build/dsc/downstairs-8830.txt (251071 bytes)
5482025-01-21T15:58:11.462Zuploaded: /tmp/test_up-build/dsc/downstairs-8830.txt
5492025-01-21T15:58:11.465Zuploading: /tmp/test_up-build/dsc/downstairs-8840.txt (139444 bytes)
5502025-01-21T15:58:12.482Zuploaded: /tmp/test_up-build/dsc/downstairs-8840.txt
5512025-01-21T15:58:12.485Zuploading: /tmp/debug/df.txt (1270 bytes)
5522025-01-21T15:58:13.490Zuploaded: /tmp/debug/df.txt
5532025-01-21T15:58:13.493Zuploading: /tmp/debug/dtrace.txt (473399 bytes)
5542025-01-21T15:58:13.525Zupload warning: file "/tmp/debug/dtrace.txt" changed size mid upload: 473399 -> 560252
5552025-01-21T15:58:14.531Zuploaded: /tmp/debug/dtrace.txt
5562025-01-21T15:58:14.534Zuploading: /tmp/debug/iostat.txt (197436 bytes)
5572025-01-21T15:58:14.550Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 197436 -> 199836
5582025-01-21T15:58:15.556Zuploaded: /tmp/debug/iostat.txt
5592025-01-21T15:58:15.558Zuploading: /tmp/debug/mpstat.txt (479688 bytes)
5602025-01-21T15:58:15.587Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 479688 -> 486249
5612025-01-21T15:58:16.593Zuploaded: /tmp/debug/mpstat.txt
5622025-01-21T15:58:16.596Zuploading: /tmp/debug/paging.txt (86098 bytes)
5632025-01-21T15:58:16.605Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 86098 -> 87406
5642025-01-21T15:58:17.612Zuploaded: /tmp/debug/paging.txt
5652025-01-21T15:58:17.615Zuploading: /tmp/debug/prstat.txt (919353 bytes)
5662025-01-21T15:58:17.656Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 919353 -> 934871
5672025-01-21T15:58:18.663Zuploaded: /tmp/debug/prstat.txt
5682025-01-21T15:58:18.666Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
5692025-01-21T15:58:19.672Zuploaded: /tmp/debug/psrinfo.txt
5702025-01-21T15:58:19.675Zuploading: /tmp/debug/upstairs-info.txt (74603 bytes)
5712025-01-21T15:58:20.688Zuploaded: /tmp/debug/upstairs-info.txt